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_fibersandFiberTrace.pretty_log_fibers.Configurable at run time using the
FIBERTRACE_STACK_DEPTHenvironment 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_fibersandFiberTrace.pretty_log_fibers. There is usually no reason to alter this.Configurable at run time using the
FIBERTRACE_STACK_SKIP_SPAWNenvironment 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_fibersandFiberTrace.pretty_log_fibers. There is usually no reason to alter this.Configurable at run time using the
FIBERTRACE_STACK_SKIP_YIELDenvironment 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.