Skip to content

Commit e32cbdb

Browse files
talex5patricoferris
andcommitted
Switch from CTF to custom runtime events
This is a minimal initial version, which mostly keeps the same set of events as before. The new `eio.runtime_events` library defines the events and their types. `lib_eio/core/trace.ml` now uses this instead of using CTF. `examples/trace/main.ml` shows how to subscribe to events. One slight difference is that `current_thread` has gone. It is now up to the reader to remember which thread was active. In a few places this meant recording e.g. reading a promise at the point where the fiber is resumed, not when it is enqueued. `Ctx_unix` is gone. Eio tracing is automatically enabled whenever OCaml tracing is. Co-authored-by: Thomas Leonard <[email protected]> Co-authored-by: Patrick Ferris <[email protected]>
1 parent 9e1872c commit e32cbdb

File tree

27 files changed

+398
-573
lines changed

27 files changed

+398
-573
lines changed

README.md

Lines changed: 58 additions & 19 deletions
Original file line numberDiff line numberDiff line change
@@ -221,35 +221,73 @@ Calling an operation that performs an effect (such as `yield`) can switch to a d
221221

222222
## Tracing
223223

224-
The library can write traces in CTF format, showing when threads (fibers) are created, when they run, and how they interact.
225-
We can run the previous code with tracing enabled (writing to a new `trace.ctf` file) like this:
224+
When OCaml's tracing is turned on, Eio writes events about many actions,
225+
such as creating fibers or resolving promises.
226226

227-
```ocaml
228-
# let () =
229-
Eio_unix.Trace.with_tracing "trace.ctf" @@ fun () ->
230-
Eio_main.run main;;
231-
+x = 1
232-
+y = 1
233-
+x = 2
234-
+y = 2
235-
+x = 3
236-
+y = 3
227+
[examples/trace](./examples/trace/) shows how to consume the events manually:
228+
229+
<!-- $MDX skip -->
230+
```sh
231+
$ dune exec -- ./examples/trace/main.exe
232+
+tracer: starting
233+
30926487700447:ring 0: create fiber 0
234+
30926487702032:ring 0: running fiber 0
235+
30926487705057:ring 0: create switch 1
236+
30926487707264:ring 0: create fiber 2
237+
30926487707512:ring 0: running fiber 2
238+
30926487720213:ring 0: log "tracer: starting"
239+
+server: starting
240+
+client: connecting socket...
241+
+server: got connection from client
242+
+server: read "Hello" from socket
243+
30926487769298:ring 0: running fiber 0
244+
30926487769877:ring 0: create fiber 3
245+
30926487770083:ring 0: running fiber 3
246+
30926487771198:ring 0: create switch 4
247+
30926487807888:ring 0: create switch 5
248+
30926487808329:ring 0: create fiber 6
249+
30926487808555:ring 0: running fiber 6
250+
30926487812219:ring 0: log "server: starting"
251+
30926487818883:ring 0: running fiber 3
252+
30926487819091:ring 0: create fiber 7
253+
30926487819155:ring 0: running fiber 7
254+
30926487822428:ring 0: log "client: connecting socket..."
255+
30926487901604:ring 0: running fiber 3
256+
30926487904947:ring 0: running fiber 0
257+
30926487907318:ring 0: running fiber 6
258+
30926487917202:ring 0: log "server: got connection from client"
259+
30926487929993:ring 0: running fiber 6
260+
30926487941403:ring 0: running fiber 7
261+
30926487948000:ring 0: running fiber 7
262+
30926487971898:ring 0: resolve 7
263+
30926487974810:ring 0: running fiber 6
264+
30926487975215:ring 0: running fiber 6
265+
30926487977869:ring 0: running fiber 6
266+
30926487984514:ring 0: log "server: read \"Hello\" from socket"
267+
30926487990785:ring 0: resolve 6
268+
30926487991752:ring 0: running fiber 3
269+
30926488022310:ring 0: resolve 3
270+
30926497839725:ring 0: running fiber 2
271+
+tracer: stopping
237272
```
238273

239-
The trace can be viewed using [mirage-trace-viewer][].
240-
This should work even while the program is still running.
241-
The file is a ring buffer, so when it gets full, old events will start to be overwritten with new ones.
274+
Note that the output from `traceln` appears in the trace as well as on the console.
275+
276+
There are various third-party tools that can consume this data
277+
(but may currently require patches to support the new system):
278+
279+
- [Meio][] (Monitoring for Eio) provides an interactive console-based UI for exploring running fibers.
280+
- [Olly][] can save Perfetto traces and report statistics.
281+
- [mirage-trace-viewer][] renders the trace visually.
282+
283+
For example, this is how mirage-trace-viewer renders the counting example above:
242284

243285
<p align='center'>
244286
<img src="./doc/trace.svg"/>
245287
</p>
246288

247289
This shows the two counting threads as two horizonal lines.
248290
The white regions indicate when each thread was running.
249-
Note that the output from `traceln` appears in the trace as well as on the console.
250-
251-
The [Meio][] (Monitoring for Eio) project provides an interactive console-based UI for exploring running fibers,
252-
using the new runtime events support in OCaml 5.1.
253291

254292
## Cancellation
255293

@@ -1849,3 +1887,4 @@ Some background about the effects system can be found in:
18491887
[Lambda Capabilities]: https://roscidus.com/blog/blog/2023/04/26/lambda-capabilities/
18501888
[Eio.Process]: https://ocaml-multicore.github.io/eio/eio/Eio/Process/index.html
18511889
[Dev meetings]: https://docs.google.com/document/d/1ZBfbjAkvEkv9ldumpZV5VXrEc_HpPeYjHPW_TiwJe4Q
1890+
[Olly]: https://github.com/tarides/runtime_events_tools

lib_eio/core/debug.ml

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -15,7 +15,7 @@ let default_traceln ?__POS__:pos fmt =
1515
Format.pp_close_box f ();
1616
Format.pp_print_flush f ();
1717
let msg = Buffer.contents b in
18-
Trace.label msg;
18+
Trace.log msg;
1919
let lines = String.split_on_char '\n' msg in
2020
Mutex.lock traceln_mutex;
2121
Fun.protect ~finally:(fun () -> Mutex.unlock traceln_mutex) @@ fun () ->

lib_eio/core/dune

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -1,4 +1,4 @@
11
(library
22
(name eio__core)
33
(public_name eio.core)
4-
(libraries cstruct hmap lwt-dllist fmt optint domain-local-await))
4+
(libraries cstruct hmap lwt-dllist fmt optint domain-local-await eio.runtime_events))

lib_eio/core/fiber.ml

Lines changed: 5 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -19,10 +19,10 @@ let fork ~sw f =
1919
Switch.with_op sw @@ fun () ->
2020
match f () with
2121
| () ->
22-
Trace.resolve (Cancel.Fiber_context.tid new_fiber) ~ex:None
22+
Trace.resolve (Cancel.Fiber_context.tid new_fiber)
2323
| exception ex ->
2424
Switch.fail sw ex; (* The [with_op] ensures this will succeed *)
25-
Trace.resolve (Cancel.Fiber_context.tid new_fiber) ~ex:(Some ex)
25+
Trace.resolve_error (Cancel.Fiber_context.tid new_fiber) ex
2626
) (* else the fiber should report the error to [sw], but [sw] is failed anyway *)
2727

2828
let fork_daemon ~sw f =
@@ -35,13 +35,13 @@ let fork_daemon ~sw f =
3535
match f () with
3636
| `Stop_daemon ->
3737
(* The daemon asked to stop. *)
38-
Trace.resolve (Cancel.Fiber_context.tid new_fiber) ~ex:None
38+
Trace.resolve (Cancel.Fiber_context.tid new_fiber)
3939
| exception Cancel.Cancelled Exit when not (Cancel.is_on sw.cancel) ->
4040
(* The daemon was cancelled because all non-daemon fibers are finished. *)
41-
Trace.resolve (Cancel.Fiber_context.tid new_fiber) ~ex:None
41+
Trace.resolve (Cancel.Fiber_context.tid new_fiber)
4242
| exception ex ->
4343
Switch.fail sw ex; (* The [with_daemon] ensures this will succeed *)
44-
Trace.resolve (Cancel.Fiber_context.tid new_fiber) ~ex:(Some ex)
44+
Trace.resolve_error (Cancel.Fiber_context.tid new_fiber) ex
4545
) (* else the fiber should report the error to [sw], but [sw] is failed anyway *)
4646

4747
let fork_promise ~sw f =

lib_eio/core/promise.ml

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -76,7 +76,7 @@ let resolve t v =
7676
| Resolved _ -> invalid_arg "Can't resolve already-resolved promise"
7777
| Unresolved b as prev ->
7878
if Atomic.compare_and_set t.state prev (Resolved v) then (
79-
Trace.resolve t.id ~ex:None;
79+
Trace.resolve t.id;
8080
Broadcast.resume_all b
8181
) else (
8282
(* Otherwise, the promise was already resolved. Retry (to get the error). *)

lib_eio/core/single_waiter.ml

Lines changed: 14 additions & 11 deletions
Original file line numberDiff line numberDiff line change
@@ -11,14 +11,17 @@ let create () = { wake = ignore }
1111
let wake t v = t.wake v
1212

1313
let await t id =
14-
Suspend.enter @@ fun ctx enqueue ->
15-
Cancel.Fiber_context.set_cancel_fn ctx (fun ex ->
16-
t.wake <- ignore;
17-
enqueue (Error ex)
18-
);
19-
t.wake <- (fun x ->
20-
Cancel.Fiber_context.clear_cancel_fn ctx;
21-
t.wake <- ignore;
22-
Trace.read ~reader:id ctx.tid;
23-
enqueue x
24-
)
14+
let x =
15+
Suspend.enter @@ fun ctx enqueue ->
16+
Cancel.Fiber_context.set_cancel_fn ctx (fun ex ->
17+
t.wake <- ignore;
18+
enqueue (Error ex)
19+
);
20+
t.wake <- (fun x ->
21+
Cancel.Fiber_context.clear_cancel_fn ctx;
22+
t.wake <- ignore;
23+
enqueue x
24+
)
25+
in
26+
Trace.read id;
27+
x

lib_eio/core/switch.ml

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -51,7 +51,7 @@ let combine_exn ex = function
5151
let fail ?(bt=Printexc.get_raw_backtrace ()) t ex =
5252
check_our_domain t;
5353
if t.exs = None then
54-
Trace.resolve t.id ~ex:(Some ex);
54+
Trace.resolve_error t.id ex;
5555
t.exs <- Some (combine_exn (ex, bt) t.exs);
5656
try
5757
Cancel.cancel t.cancel ex

0 commit comments

Comments
 (0)