module PerfTools::FiberTrace
Overview
In-memory tracking of all existing fibers in the running program.
Defined in:
perf_tools/fiber_trace.crConstant Summary
-
STACK_DEPTH =
ENV["FIBERTRACE_STACK_DEPTH"]?.try(&.to_i) || 5
-
The maximum number of stack frames shown for
FiberTrace.log_fibers
andFiberTrace.pretty_log_fibers
.Configurable at run time using the
FIBERTRACE_STACK_DEPTH
environment variable. -
STACK_SKIP_SPAWN =
ENV["FIBERTRACE_STACK_SKIP_SPAWN"]?.try(&.to_i) || 4
-
The number of stack frames to skip from the fiber creation call stacks for
FiberTrace.log_fibers
andFiberTrace.pretty_log_fibers
. There is usually no reason to alter this.Configurable at run time using the
FIBERTRACE_STACK_SKIP_SPAWN
environment variable. -
STACK_SKIP_YIELD =
ENV["FIBERTRACE_STACK_SKIP_YIELD"]?.try(&.to_i) || 5
-
The number of stack frames to skip from the fiber yield call stacks for
FiberTrace.log_fibers
andFiberTrace.pretty_log_fibers
. There is usually no reason to alter this.Configurable at run time using the
FIBERTRACE_STACK_SKIP_YIELD
environment variable.
Class Method Summary
-
.log_fibers(io : IO) : Nil
Logs all existing fibers, plus the call stacks at their creation and last yield, to the given io.
-
.pretty_log_fibers(io : IO) : Nil
Logs all existing fibers, aggregated by the call stacks at their creation and last yield, to the given io as a Markdown table.
Class Method Detail
Logs all existing fibers, plus the call stacks at their creation and last yield, to the given io.
The behavior of this method can be controlled by the STACK_DEPTH
,
STACK_SKIP_SPAWN
, and STACK_SKIP_YIELD
constants.
The first line contains the number of fibers. For each fiber, the first line is the fiber's name (may be empty), and the second line is the number of frames on the fiber's creation stack, followed by the stack itself, one line per frame. After that, the yield stack follows, except that it may contain 0 frames. Example output:
require "perf_tools/fiber_trace"
spawn { sleep }
sleep 1
PerfTools::FiberTrace.log_fibers(STDOUT)
3
Fiber Clean Loop
4
/opt/homebrew/Cellar/crystal/1.9.2/share/crystal/src/kernel.cr:558:1 in '__crystal_main'
/opt/homebrew/Cellar/crystal/1.9.2/share/crystal/src/crystal/main.cr:129:5 in 'main_user_code'
/opt/homebrew/Cellar/crystal/1.9.2/share/crystal/src/crystal/main.cr:115:7 in 'main'
/opt/homebrew/Cellar/crystal/1.9.2/share/crystal/src/crystal/main.cr:141:3 in 'main'
5
/opt/homebrew/Cellar/crystal/1.9.2/share/crystal/src/crystal/scheduler.cr:174:5 in 'sleep'
/opt/homebrew/Cellar/crystal/1.9.2/share/crystal/src/crystal/scheduler.cr:58:5 in 'sleep'
/opt/homebrew/Cellar/crystal/1.9.2/share/crystal/src/concurrent.cr:14:3 in 'sleep'
/opt/homebrew/Cellar/crystal/1.9.2/share/crystal/src/kernel.cr:558:1 in '->'
src/perf_tools/fiber_trace.cr:184:3 in 'run'
Signal Loop
5
/opt/homebrew/Cellar/crystal/1.9.2/share/crystal/src/crystal/system/unix/signal.cr:60:5 in 'start_loop'
/opt/homebrew/Cellar/crystal/1.9.2/share/crystal/src/crystal/system/unix/signal.cr:163:5 in 'setup_default_handlers'
/opt/homebrew/Cellar/crystal/1.9.2/share/crystal/src/kernel.cr:558:1 in '__crystal_main'
/opt/homebrew/Cellar/crystal/1.9.2/share/crystal/src/crystal/main.cr:129:5 in 'main_user_code'
/opt/homebrew/Cellar/crystal/1.9.2/share/crystal/src/crystal/main.cr:115:7 in 'main'
5
/opt/homebrew/Cellar/crystal/1.9.2/share/crystal/src/crystal/scheduler.cr:50:5 in 'reschedule'
/opt/homebrew/Cellar/crystal/1.9.2/share/crystal/src/io/evented.cr:128:5 in 'wait_readable'
/opt/homebrew/Cellar/crystal/1.9.2/share/crystal/src/io/evented.cr:119:3 in 'wait_readable'
/opt/homebrew/Cellar/crystal/1.9.2/share/crystal/src/io/evented.cr:59:9 in 'unbuffered_read'
/opt/homebrew/Cellar/crystal/1.9.2/share/crystal/src/io/buffered.cr:261:5 in 'fill_buffer'
4
test.cr:4:1 in '__crystal_main'
/opt/homebrew/Cellar/crystal/1.9.2/share/crystal/src/crystal/main.cr:129:5 in 'main_user_code'
/opt/homebrew/Cellar/crystal/1.9.2/share/crystal/src/crystal/main.cr:115:7 in 'main'
/opt/homebrew/Cellar/crystal/1.9.2/share/crystal/src/crystal/main.cr:141:3 in 'main'
5
/opt/homebrew/Cellar/crystal/1.9.2/share/crystal/src/crystal/scheduler.cr:50:5 in 'reschedule'
/opt/homebrew/Cellar/crystal/1.9.2/share/crystal/src/concurrent.cr:29:3 in 'sleep'
test.cr:3:9 in '->'
src/perf_tools/fiber_trace.cr:184:3 in 'run'
/opt/homebrew/Cellar/crystal/1.9.2/share/crystal/src/fiber.cr:98:34 in '->'
NOTE The main fiber of each thread is not shown.
Logs all existing fibers, aggregated by the call stacks at their creation and last yield, to the given io as a Markdown table.
The behavior of this method can be controlled by the STACK_DEPTH
,
STACK_SKIP_SPAWN
, and STACK_SKIP_YIELD
constants.
Example output:
require "perf_tools/fiber_trace"
spawn { sleep }
sleep 1
PerfTools::FiberTrace.pretty_log_fibers(STDOUT)
| Count | Fibers | Spawn stack | Yield stack |
|------:|:-------|:------------|:------------|
| 1 | ` Fiber Clean Loop ` | ` /opt/homebrew/Cellar/crystal/1.9.2/share/crystal/src/kernel.cr:558:1 in '__crystal_main' `<br>` /opt/homebrew/Cellar/crystal/1.9.2/share/crystal/src/crystal/main.cr:129:5 in 'main_user_code' `<br>` /opt/homebrew/Cellar/crystal/1.9.2/share/crystal/src/crystal/main.cr:115:7 in 'main' `<br>` /opt/homebrew/Cellar/crystal/1.9.2/share/crystal/src/crystal/main.cr:141:3 in 'main' ` | ` /opt/homebrew/Cellar/crystal/1.9.2/share/crystal/src/crystal/scheduler.cr:174:5 in 'sleep' `<br>` /opt/homebrew/Cellar/crystal/1.9.2/share/crystal/src/crystal/scheduler.cr:58:5 in 'sleep' `<br>` /opt/homebrew/Cellar/crystal/1.9.2/share/crystal/src/concurrent.cr:14:3 in 'sleep' `<br>` /opt/homebrew/Cellar/crystal/1.9.2/share/crystal/src/kernel.cr:558:1 in '->' `<br>` /Users/quinton/crystal/perf-tools/src/perf_tools/fiber_trace.cr:172:3 in 'run' ` |
| 1 | | ` test.cr:4:1 in '__crystal_main' `<br>` /opt/homebrew/Cellar/crystal/1.9.2/share/crystal/src/crystal/main.cr:129:5 in 'main_user_code' `<br>` /opt/homebrew/Cellar/crystal/1.9.2/share/crystal/src/crystal/main.cr:115:7 in 'main' `<br>` /opt/homebrew/Cellar/crystal/1.9.2/share/crystal/src/crystal/main.cr:141:3 in 'main' ` | ` /opt/homebrew/Cellar/crystal/1.9.2/share/crystal/src/crystal/scheduler.cr:50:5 in 'reschedule' `<br>` /opt/homebrew/Cellar/crystal/1.9.2/share/crystal/src/concurrent.cr:29:3 in 'sleep' `<br>` test.cr:3:9 in '->' `<br>` /Users/quinton/crystal/perf-tools/src/perf_tools/fiber_trace.cr:172:3 in 'run' `<br>` /opt/homebrew/Cellar/crystal/1.9.2/share/crystal/src/fiber.cr:98:34 in '->' ` |
| 1 | ` Signal Loop ` | ` /opt/homebrew/Cellar/crystal/1.9.2/share/crystal/src/crystal/system/unix/signal.cr:60:5 in 'start_loop' `<br>` /opt/homebrew/Cellar/crystal/1.9.2/share/crystal/src/crystal/system/unix/signal.cr:163:5 in 'setup_default_handlers' `<br>` /opt/homebrew/Cellar/crystal/1.9.2/share/crystal/src/kernel.cr:558:1 in '__crystal_main' `<br>` /opt/homebrew/Cellar/crystal/1.9.2/share/crystal/src/crystal/main.cr:129:5 in 'main_user_code' `<br>` /opt/homebrew/Cellar/crystal/1.9.2/share/crystal/src/crystal/main.cr:115:7 in 'main' ` | ` /opt/homebrew/Cellar/crystal/1.9.2/share/crystal/src/crystal/scheduler.cr:50:5 in 'reschedule' `<br>` /opt/homebrew/Cellar/crystal/1.9.2/share/crystal/src/io/evented.cr:128:5 in 'wait_readable' `<br>` /opt/homebrew/Cellar/crystal/1.9.2/share/crystal/src/io/evented.cr:119:3 in 'wait_readable' `<br>` /opt/homebrew/Cellar/crystal/1.9.2/share/crystal/src/io/evented.cr:59:9 in 'unbuffered_read' `<br>` /opt/homebrew/Cellar/crystal/1.9.2/share/crystal/src/io/buffered.cr:261:5 in 'fill_buffer' ` |
NOTE The main fiber of each thread is not shown.