Skip to content

Comments

Add a warning whenever lost/missed events occur#74

Open
curche wants to merge 5 commits intotarides:mainfrom
curche:warn-lost-events
Open

Add a warning whenever lost/missed events occur#74
curche wants to merge 5 commits intotarides:mainfrom
curche:warn-lost-events

Conversation

@curche
Copy link

@curche curche commented Feb 11, 2026

Brief description

Whenever olly detects any events that couldn't be read before being overwritten in the runtime ring buffer, we print a warning about the same at the end of the run (and refers to the missed events section in readme)

Similar to how hyperfine reports of statistical discrepancies during runs, but this one's simpler and mostly just informative.

Other details

The implementation for now is just using a ref 0 that increments - the value of which doesn't really matter just that its either zero or positive non-zero.
The other alternatives were a) something with effect handlers (but that felt a bit overkill) or b) having a warning only during gc-stats through an updated config (but it seemed like both trace and gc-stats (& future options) could benefit from showing the warning)

I've kept the Printf in lost_events but maybe that could be reconsidered now that the final result gives a warning for lost events - the benefit being that excessive no of lost events will not affect the target executable's output (if any)

Sample new output

To trigger lost events, it was easier to use infer (refer #63)

c\@c : ~/g/runtime_events_tools$ dune exec olly -- gc-stats  "../infer/infer/bin/infer analyze --no-progress-bar --no-report --multicore -j $(getconf _NPROCESSORS_ONLN)"
....
[ring_id=3] Lost 302568 events
[ring_id=4] Lost 141949 events
[ring_id=5] Lost 47645 events
Skipped large procedure (__infer_globals_initializer_ecp_nistz256_precomputed, size:18951) in pulse.

Execution times:
Wall time (s):	130.00
CPU time (s):	1777.23
GC time (s):	669.68
GC overhead (% of CPU time):	37.68%

Per domain stats:
Domain	Wall(s)	GC(s)	GC(%)
0	130.00		28.30	21.77
1	126.48		51.38	40.62
2	127.16		57.20	44.98
3	126.48		50.73	40.11
4	126.47		42.72	33.78
5	126.47		50.86	40.21
6	126.47		50.90	40.24
7	128.89		51.24	39.76
8	126.47		51.00	40.32
9	126.47		32.81	25.94
10	126.47		50.74	40.12
11	126.47		50.50	39.93
12	126.46		50.70	40.09
13	126.46		50.62	40.03

GC latency profile:
#[Mean (ms):	2.27,	Stddev (ms):	74.77]
#[Min (ms):	0.00,	max (ms):	5783.95]

Percentile 	Latency (ms)
25.0000 	0.00
50.0000 	0.01
60.0000 	1.03
70.0000 	1.37
75.0000 	1.61
80.0000 	1.84
85.0000 	2.13
90.0000 	2.65
95.0000 	3.90
96.0000 	4.20
97.0000 	4.63
98.0000 	5.23
99.0000 	7.43
99.9000 	35.78
99.9900 	4840.23
99.9990 	5783.95
99.9999 	5783.95
100.0000 	5783.95

Warning: Results may be inaccurate since some runtime events were lost before they could be read.
Refer to 'Missed events' section in repo README

c\@c: ~/g/runtime_events_tools$ dune exec olly -- trace olly.trace "../infer/infer/bin/infer analyze --no-progress-bar --no-report --multicore -j $(getconf _NPROCESSORS_ONLN)"
....
[ring_id=2] Lost 653481 events
[ring_id=3] Lost 557918 events
Skipped large procedure (__infer_globals_initializer_ecp_nistz256_precomputed, size:18951) in pulse.

Warning: Results may be inaccurate since some runtime events were lost before they could be read.
Refer to 'Missed events' section in repo README

c\@c: ~/g/runtime_events_tools$ 

Previously the runtime callback for whenever lost events occur only
prints out that info into stdin

With this commit, olly keeps note of lost events using a ref so as
to print a warning towards the end of the summary
lost events can also occur during tracing and so it didn't make
sense to refer to just Summary in the warning message.

An alternative idea was to add a new lost_event handler in config
and only keep a counter during gc_stats while defaulting to the
previous behaviour (just printing) while tracing. However, having
a warning felt sensible for both tracing & gc_stats for now and we
can address it in future if required
@curche
Copy link
Author

curche commented Feb 13, 2026

Rebased changes on top of package updates. CI looks ok now

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant