raboof / ectrace   0.0.1

GitHub

Trace a Scala ExecutionContext

Scala versions: 2.12

ectrace

Wraps a Scala ExecutionContext to collect some statistics.

Experiment/WiP stage

Example

Run the example script at TestMain.sc (with Ammonite).

This example script schedules a number of Futures with a body that sleeps (blocking the thread) for 4 seconds. It produces a timeline.data with the collected timing information:

1484400129982 1484400129982 1484400129982 1484400129982 WrappedExecutionContext.scala:32
1484400129982 1484400129982 1484400129982 1484400129982 WrappedExecutionContext.scala:32
(...)
1484400117982 1484400117982 1484400121980 1484400125981 /home/aengelen/dev/ectrace/example/TestMain.sc:14
1484400117982 1484400117982 1484400121980 1484400125980 /home/aengelen/dev/ectrace/example/TestMain.sc:14
1484400117982 1484400117982 1484400121980 1484400125980 /home/aengelen/dev/ectrace/example/TestMain.sc:14
1484400117982 1484400117982 1484400121980 1484400125980 /home/aengelen/dev/ectrace/example/TestMain.sc:14
1484400117981 1484400117981 1484400117981 1484400121982 /home/aengelen/dev/ectrace/example/TestMain.sc:14
1484400117981 1484400117981 1484400117981 1484400121981 /home/aengelen/dev/ectrace/example/TestMain.sc:14
1484400117981 1484400117981 1484400117981 1484400121981 /home/aengelen/dev/ectrace/example/TestMain.sc:14
1484400117980 1484400117980 1484400117980 1484400121981 /home/aengelen/dev/ectrace/example/TestMain.sc:14
1484400117980 1484400117980 1484400117980 1484400121980 /home/aengelen/dev/ectrace/example/TestMain.sc:14
1484400117980 1484400117980 1484400117980 1484400121980 /home/aengelen/dev/ectrace/example/TestMain.sc:14
1484400117979 1484400117979 1484400117979 1484400121980 /home/aengelen/dev/ectrace/example/TestMain.sc:14
1484400117977 1484400117977 1484400117979 1484400121979 /home/aengelen/dev/ectrace/example/TestMain.sc:14

This can be converted to HAR format:

amm -s ../timeline2har.sc < timeline.data > timeline.har

yielding timeline.har which can be visualized with for example the HAR Viewer:

HAR Viewer screenshot

This shows:

The grey bars show the time the future was actually running. This should typically be short unless for CPU-intensive tasks.

The green bars show the time between the moment the future was created and the moment it was actually started. This shows the time futures are waiting for their input.

The purple bars show the time between the moment the future was triggered and the time it was actually ran. If this is not instant, it is a sign the ExecutionContext has been exhausted.