gazagnaire.org / ocaml-observe
Logging, runtime tracing, and the obs performance profiler for OCaml
0
Fork 0

Configure Feed

Select the types of activity you want to include in your feed.

observe: spec test for contention span context

An object seen only via Get/Try_get (created before the collector attached,
so its Create/Name was never captured) renders as a bare id in the
contention table with no hint of what it is. runtime_events cannot replay
the missing create, so the row should fall back to the span it was
contended under. The test contends such an object inside a span and asserts
the row names that span; it fails today.

author
Thomas Gazagnaire date (Jun 25, 2026, 7:07 PM -0700) commit b22e7c20 parent dd8dc1e7
+41
+41
test/obs_eio/test_memtrace_eio.ml
··· 208 208 Alcotest.(check int) "immediate" 2 c.immediate; 209 209 Alcotest.(check int) "waited" 1 c.waited 210 210 211 + (* An object seen only via Get/Try_get -- created before the collector attached, 212 + so no Create/Name was captured -- shows as a bare id in the contention table. 213 + runtime_events cannot replay the missing create, so the row falls back to the 214 + span it was contended under, naming where the contention happened. *) 215 + let test_contention_where () = 216 + let m = M.v () in 217 + M.set_wall_clock m ~start:0. ~stop:0.1; 218 + M.eio_event m ~ring:0 ~ts_ns:(ms 0.) (`Fiber 1); 219 + M.eio_event m ~ring:0 ~ts_ns:(ms 0.) (`Enter_span "db.pool.acquire"); 220 + M.eio_event m ~ring:0 ~ts_ns:(ms 1.) (`Try_get 26); 221 + M.eio_event m ~ring:0 ~ts_ns:(ms 1.) (`Suspend_fiber ""); 222 + M.eio_event m ~ring:0 ~ts_ns:(ms 5.) (`Fiber 1); 223 + M.eio_event m ~ring:0 ~ts_ns:(ms 6.) (`Get 26); 224 + M.eio_event m ~ring:0 ~ts_ns:(ms 7.) `Exit_span; 225 + let r = M.report m in 226 + let text = 227 + Observer_model.Memtrace_eio.Render.to_string 228 + Observer_model.Memtrace_eio.Render.default_opts r 229 + in 230 + (* Isolate the Contention block so the span name from the hotspots table above 231 + does not leak into the assertion. *) 232 + let section = 233 + let lines = String.split_on_char '\n' text in 234 + let rec drop = function 235 + | l :: rest when not (contains l "Contention") -> drop rest 236 + | _ :: rest -> rest 237 + | [] -> [] 238 + in 239 + let rec take acc = function 240 + | l :: _ when contains l "Errors / cancellations" -> List.rev acc 241 + | l :: rest -> take (l :: acc) rest 242 + | [] -> List.rev acc 243 + in 244 + String.concat "\n" (take [] (drop lines)) 245 + in 246 + Alcotest.(check bool) "bare-id object present" true (contains section "26"); 247 + Alcotest.(check bool) 248 + "row names where it was contended" true 249 + (contains section "db.pool.acquire") 250 + 211 251 (* 100 blocked Try_get and 20 immediate Get on a named mutex; each blocked 212 252 acquisition suspends for exactly 1ms before the fiber resumes. So waited=100, 213 253 immediate=20, wait_time=100ms, and the contention finding fires with payoff = ··· 1371 1411 Alcotest.test_case "gc" `Quick test_gc; 1372 1412 Alcotest.test_case "gc cycles vs slices" `Quick test_gc_cycles_vs_slices; 1373 1413 Alcotest.test_case "contention" `Quick test_contention; 1414 + Alcotest.test_case "contention where" `Quick test_contention_where; 1374 1415 Alcotest.test_case "contention finding" `Quick test_contention_finding; 1375 1416 Alcotest.test_case "fiber waiting finding" `Quick 1376 1417 test_fiber_waiting_finding;