Skip to content

Commit 796b3ba

Browse files
committed
Merge main: reconcile overlapping cache-maintenance and upload-drain fixes
PR #37 independently fixed the upload-queue drain and added event-driven cache maintenance on the polling thread. Keep main's _tick_maintenance system and drop this branch's main-loop _maybe_cleanup_caches duplicate; take main's stop_worker(True, timeout=30) drain. https://claude.ai/code/session_01S9qNz7CTGBd4dLLDFVVQky
2 parents b5dd576 + 3ca07b8 commit 796b3ba

8 files changed

Lines changed: 496 additions & 153 deletions

File tree

.github/workflows/unit-tests.yml

Lines changed: 31 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,31 @@
1+
name: Unit Tests
2+
3+
# Runs the pure-Python unit tests (FlagMapper, PathResolver, utils). These have
4+
# no bcc/kernel dependency, so unlike the BPF compile job they run on any
5+
# runner without privileges.
6+
7+
on:
8+
push:
9+
paths:
10+
- 'src/**'
11+
- 'tests/**'
12+
- '.github/workflows/unit-tests.yml'
13+
pull_request:
14+
paths:
15+
- 'src/**'
16+
- 'tests/**'
17+
- '.github/workflows/unit-tests.yml'
18+
workflow_dispatch:
19+
20+
jobs:
21+
unit-tests:
22+
runs-on: ubuntu-latest
23+
steps:
24+
- uses: actions/checkout@v4
25+
26+
- uses: actions/setup-python@v5
27+
with:
28+
python-version: '3.11'
29+
30+
- name: Run unit tests
31+
run: python3 -m unittest discover -s tests -v

src/tracer/IOTracer.py

Lines changed: 60 additions & 33 deletions
Original file line numberDiff line numberDiff line change
@@ -141,7 +141,15 @@ def __init__(
141141
self.path_resolver = PathResolver()
142142
self.mmap_regions = {}
143143
self.cmdline_cache = {} # pid -> cmdline, populated on first successful read
144-
self._last_cache_cleanup = time.time()
144+
145+
# Bounded-cache maintenance. The path resolver and cmdline caches are
146+
# only evicted on PROCESS_EXEC, so over a long-running trace they would
147+
# otherwise grow without bound. Maintenance runs from the perf-callback
148+
# (polling) thread — the only thread that mutates these caches — so it
149+
# never races with event processing.
150+
self._event_count = 0
151+
self._maintenance_interval = 50000 # events between cache sweeps
152+
self._cmdline_cache_max = 100000 # hard cap on cmdline cache entries
145153

146154
if cache_sample_rate > 1:
147155
self.writer.set_cache_sampling(cache_sample_rate)
@@ -192,9 +200,11 @@ def _print_event(self, cpu, data, size):
192200
data: Raw event data pointer
193201
size: Size of the event data
194202
"""
203+
self._tick_maintenance()
204+
195205
event = self.b["events"].event(data)
196206
op_name = self.flag_mapper.op_fs_types.get(event.op, "[unknown]")
197-
207+
198208
try:
199209
filename = event.filename.decode()
200210
if self.anonymous:
@@ -518,6 +528,46 @@ def _read_cmdline_cached(self, pid: int) -> str:
518528
self.cmdline_cache[pid] = result
519529
return result
520530

531+
def _tick_maintenance(self) -> None:
532+
"""
533+
Advance the event counter and run cache maintenance when it is due.
534+
535+
Called from every perf callback that runs on the polling thread and
536+
touches the long-lived caches (``_print_event``, ``_print_event_dual``,
537+
``_print_event_io_uring``) so a workload dominated by any single event
538+
family — e.g. rename/link/symlink (dual) or async io_uring I/O — still
539+
triggers eviction instead of growing the caches unbounded.
540+
"""
541+
self._event_count += 1
542+
if self._event_count % self._maintenance_interval == 0:
543+
self._run_cache_maintenance()
544+
545+
def _run_cache_maintenance(self) -> None:
546+
"""
547+
Bound the long-lived caches so an indefinite trace does not leak memory.
548+
549+
Runs from the perf-callback (polling) thread, which is the only thread
550+
that mutates ``cmdline_cache`` and the path resolver caches, so no
551+
locking is required.
552+
553+
- Delegates to ``PathResolver.cleanup_old_cache`` (otherwise never
554+
called), which prunes stale per-PID entries and caps ``inode_to_path``.
555+
- Caps ``cmdline_cache`` at ``_cmdline_cache_max`` entries. Entries are
556+
deliberately retained past process exit so that CLOSE/EXIT events
557+
buffered after the process is gone can still resolve a cmdline; when
558+
the cap is exceeded we drop the oldest half (dicts preserve insertion
559+
order), keeping the most recently seen PIDs.
560+
"""
561+
try:
562+
self.path_resolver.cleanup_old_cache()
563+
except Exception as e:
564+
if self.verbose:
565+
logger("warning", f"Path resolver cache cleanup failed: {e}")
566+
567+
if len(self.cmdline_cache) > self._cmdline_cache_max:
568+
items = list(self.cmdline_cache.items())
569+
self.cmdline_cache = dict(items[len(items) // 2:])
570+
521571
def _handle_process_exec(self, pid: int) -> None:
522572
"""
523573
Clear the mmap_regions and cmdline caches for a PID on exec.
@@ -529,31 +579,6 @@ def _handle_process_exec(self, pid: int) -> None:
529579
self.mmap_regions.pop(pid, None)
530580
self.cmdline_cache.pop(pid, None)
531581

532-
def _maybe_cleanup_caches(self) -> None:
533-
"""
534-
Periodically bound the userspace caches during long traces.
535-
536-
path_resolver.inode_to_path gains an entry for every opened inode and
537-
cmdline_cache for every observed PID; without pruning an indefinite
538-
trace grows them without bound.
539-
"""
540-
now = time.time()
541-
if now - self._last_cache_cleanup < 60:
542-
return
543-
self._last_cache_cleanup = now
544-
# The polling thread mutates these caches concurrently; cleanup uses
545-
# snapshot-based iteration, but guard regardless — a rare race must
546-
# degrade to a skipped cleanup, not terminate the trace loop.
547-
try:
548-
self.path_resolver.cleanup_old_cache()
549-
# Keep the most recently added entries (insertion order) so
550-
# cmdlines for recently exited PIDs — the reason this cache
551-
# exists — survive; entries for live PIDs are re-read on demand.
552-
if len(self.cmdline_cache) > 20000:
553-
self.cmdline_cache = dict(list(self.cmdline_cache.items())[-5000:])
554-
except Exception as e:
555-
logger("warning", f"Cache cleanup skipped: {e}")
556-
557582
def _handle_process_exit(self, pid: int) -> None:
558583
"""
559584
Clear the mmap_regions cache for a PID on exit.
@@ -577,6 +602,8 @@ def _print_event_dual(self, cpu, data, size):
577602
data: Raw event data pointer
578603
size: Size of the event data
579604
"""
605+
self._tick_maintenance()
606+
580607
event = self.b["events_dual"].event(data)
581608
op_name = self.flag_mapper.op_fs_types.get(event.op, "[unknown]")
582609

@@ -778,6 +805,8 @@ def _print_event_io_uring(self, cpu, data, size):
778805
data: Raw event data pointer
779806
size: Size of the event data
780807
"""
808+
self._tick_maintenance()
809+
781810
e = self.b["io_uring_events"].event(data)
782811
ts = datetime.today()
783812

@@ -1081,7 +1110,6 @@ def trace(self):
10811110
while remaining > 0 and self.running:
10821111
sleep_time = min(0.1, remaining)
10831112
time.sleep(sleep_time)
1084-
self._maybe_cleanup_caches()
10851113

10861114
current = time.time()
10871115
remaining = end_time - current # type: ignore
@@ -1095,7 +1123,6 @@ def trace(self):
10951123
# Run indefinitely until Ctrl+C
10961124
while self.running:
10971125
time.sleep(0.1)
1098-
self._maybe_cleanup_caches()
10991126

11001127
if self.verbose:
11011128
current = time.time()
@@ -1124,10 +1151,10 @@ def trace(self):
11241151
run_with_spinner("Compressing trace output", self.writer.force_flush)
11251152

11261153
if self.automatic_upload:
1127-
# server_mode=True drains the queue before stopping the worker;
1128-
# otherwise the final bundle queued by force_flush above may
1129-
# never be uploaded (the worker stops before picking it up).
1130-
run_with_spinner("Uploading traces", lambda: self.upload_manager.stop_worker(True, timeout=60))
1154+
# Drain the upload queue before stopping the workers — passing
1155+
# False here set the stop event immediately and abandoned any
1156+
# traces still queued for upload.
1157+
run_with_spinner("Uploading traces", lambda: self.upload_manager.stop_worker(True, timeout=30))
11311158
try:
11321159
os.removedirs(self.writer.output_dir)
11331160
except OSError:

src/tracer/PathResolver.py

Lines changed: 9 additions & 8 deletions
Original file line numberDiff line numberDiff line change
@@ -95,14 +95,14 @@ def update_process_files(self, pid: int) -> dict:
9595
files[inode] = target
9696
# Update global inode cache
9797
self.inode_to_path[inode] = target
98-
except:
98+
except OSError:
9999
continue
100-
100+
101101
self.pid_to_files[pid] = files
102102
self.last_update[pid] = current_time
103103
return files
104-
105-
except:
104+
105+
except OSError:
106106
return {}
107107

108108
def resolve_by_fd(self, pid: int, fd: int, inode: int = 0, filename: str = "") -> str:
@@ -225,10 +225,10 @@ def cleanup_old_cache(self):
225225
- Process entries older than cache_timeout * 10 seconds
226226
- Limits inode cache to 5000 most recent entries
227227
228-
Thread-safety: this runs on the main thread while perf-buffer
229-
callbacks mutate these dicts from the polling thread, so iteration
230-
works on list() snapshots (atomic in CPython) and removals tolerate
231-
entries that disappeared concurrently.
228+
Thread-safety: this runs on the polling thread (from the perf-buffer
229+
callbacks via cache maintenance), the same thread that mutates these
230+
dicts. Iteration still works on list() snapshots and removals
231+
tolerate missing entries as defense in depth.
232232
"""
233233
current_time = time.time()
234234

@@ -242,6 +242,7 @@ def cleanup_old_cache(self):
242242
self.pid_to_files.pop(pid, None)
243243
self.last_update.pop(pid, None)
244244

245+
245246
# Optionally limit inode cache size
246247
if len(self.inode_to_path) > 10000:
247248
# Keep only the most recent 5000 entries

0 commit comments

Comments
 (0)