| name | flight-profiler-trace |
| description | Trace execution time of Python method invocations in a live process with call stack visualization. Use this to see a hierarchical call tree showing which sub-calls are slow and where time is spent within a function. |
flight-profiler-trace
Trace the execution time of a specified method invocation, displaying a call tree with timing. Unlike watch which shows individual invocations, trace reveals the full call hierarchy underneath a function — making it ideal for finding which sub-call is the bottleneck.
Prerequisites: Read the flight-profiler-attach skill first for platform requirements, installation, permissions, and connection details.
When to Use
- You want to find which sub-call inside a function is slow
- You need a hierarchical view of function execution with timing at each level
- You want to filter out fast calls and only see slow ones (via
-i interval threshold)
- You need to understand the call chain depth of a specific function
Usage
flight_profiler <pid> --cmd "trace module [class] method [options]" --no-color
Positional Arguments
module — the module name as it would be imported in the target process. For example, if the target code does from myapp.utils import helper, then module is myapp.utils. PyFlightProfiler locates the module via importlib.import_module. If you're unsure of the module name, run a separate command to resolve it first: flight_profiler <pid> --cmd "module /absolute/path/to/file.py" --no-color, then use the returned module name here.class (optional) — class name, omit if module-level functionmethod — target method name
Options
| Flag | Description | Default |
|---|
-i, --interval <value> | Only display sub-calls costing more than N milliseconds. Calls below this threshold are hidden from the tree. | 0.1 |
-et, --entrance_time <value> | Only display invocations where the entrance (top-level) cost exceeds N milliseconds. Invocations below this threshold are silently skipped. | 0 |
-d, --depth <value> | Limit call tree display depth. -d 2 shows only direct children of the traced method. When set, ignores -i interval. | -1 (unlimited) |
-nm, --nested-method <value> | Trace a nested (inner) function defined inside the target method. Depth is restricted to 1. | none |
-n, --limits <value> | Maximum number of invocations to capture before stopping | 10 |
-f, --filter_expr <value> | Filter expression on (target, *args, **kwargs). Only invocations where the expression is truthy are traced. For class methods, args[0] is self. | none |
Output Format
Each captured invocation produces a block:
────────────────────────────────────────────────────────────
🔍 2026-04-19 11:35:38:953 thread=MainThread tid=8722965056 daemon=False cost=90.003ms
[90.003ms] process_order trace_demo_script.py:6
├─ [5.574ms] validate trace_demo_script.py:13
│ └─ [5.52ms] sleep <built-in>
├─ [31.402ms] compute_price trace_demo_script.py:16
│ ├─ [21.285ms] sleep <built-in>
│ └─ [10.074ms] apply_discount trace_demo_script.py:20
│ └─ [10.049ms] sleep <built-in>
└─ [52.99ms] save_to_db trace_demo_script.py:23
└─ [52.949ms] sleep <built-in>
Title line fields:
| Field | Description |
|---|
🔍 | trace command icon |
| Timestamp | When the entrance method was called |
thread | Thread name that executed the method |
tid | Thread ID |
daemon | Whether the thread is a daemon thread |
cost | Total execution time of the entrance method (milliseconds) |
Call tree fields (each line):
| Field | Description |
|---|
[Nms] | Execution time of that specific call. Color-coded in terminal: >50% of parent = red, >20% = yellow, >5% = green, else faint green |
| Method name | Function name. [await] prefix indicates an async await point |
| Location | filename:lineno for Python methods, <built-in> for C extension methods |
Tree structure: ├─ / └─ show child calls, │ connects sibling levels.
Examples
1. Class method — full call tree
Shows the complete hierarchy with all sub-calls and their timing:
flight_profiler <pid> --cmd "trace __main__ OrderService process_order -n 1" --no-color
🔍 2026-04-19 11:35:38:953 thread=MainThread tid=8722965056 daemon=False cost=90.003ms
[90.003ms] process_order trace_demo_script.py:6
├─ [5.574ms] validate trace_demo_script.py:13
│ └─ [5.52ms] sleep <built-in>
├─ [31.402ms] compute_price trace_demo_script.py:16
│ ├─ [21.285ms] sleep <built-in>
│ └─ [10.074ms] apply_discount trace_demo_script.py:20
│ └─ [10.049ms] sleep <built-in>
└─ [52.99ms] save_to_db trace_demo_script.py:23
└─ [52.949ms] sleep <built-in>
Reading: save_to_db takes 52.99ms (59% of total) — the dominant bottleneck. compute_price takes 31.4ms including its child apply_discount.
2. Module-level function
flight_profiler <pid> --cmd "trace __main__ compute -n 1" --no-color
🔍 2026-04-19 11:35:42:462 thread=MainThread tid=8722965056 daemon=False cost=21.672ms
[21.672ms] compute trace_demo_script.py:43
├─ [10.104ms] sleep <built-in>
├─ [6.298ms] helper trace_demo_script.py:48
│ └─ [6.269ms] sleep <built-in>
└─ [5.217ms] helper trace_demo_script.py:48
└─ [5.184ms] sleep <built-in>
3. Limit depth with -d
-d 2 shows only the entrance method and its direct children — hides deeper calls:
flight_profiler <pid> --cmd "trace __main__ OrderService process_order -d 2 -n 1" --no-color
🔍 2026-04-19 11:35:51:448 thread=MainThread tid=8722965056 daemon=False cost=90.374ms
[90.374ms] process_order trace_demo_script.py:6
├─ [6.282ms] validate trace_demo_script.py:13
├─ [31.704ms] compute_price trace_demo_script.py:16
└─ [52.336ms] save_to_db trace_demo_script.py:23
Useful for getting an overview of the top-level breakdown without noise from deeper calls.
4. Interval threshold with -i
-i 10 hides sub-calls costing less than 10ms. validate (5ms) is hidden:
flight_profiler <pid> --cmd "trace __main__ OrderService process_order -i 10 -n 1" --no-color
🔍 2026-04-19 11:35:52:586 thread=MainThread tid=8722965056 daemon=False cost=92.380ms
[92.38ms] process_order trace_demo_script.py:6
├─ [35.176ms] compute_price trace_demo_script.py:16
│ ├─ [22.783ms] sleep <built-in>
│ └─ [12.343ms] apply_discount trace_demo_script.py:20
│ └─ [12.313ms] sleep <built-in>
└─ [50.889ms] save_to_db trace_demo_script.py:23
└─ [50.844ms] sleep <built-in>
5. Entrance time threshold with -et
-et 50 silently skips entire invocations where total cost < 50ms. Only invocations costing >= 50ms are captured. Unlike -i which filters sub-calls within a tree, -et filters the entire invocation.
flight_profiler <pid> --cmd "trace __main__ OrderService process_order -et 50 -n 1" --no-color
If the method typically takes 90ms, output appears normally. If an invocation only takes 30ms, it is silently dropped and does not count toward -n.
6. Nested method with -nm
Traces an inner function defined inside the target method. Depth is restricted to 1:
flight_profiler <pid> --cmd "trace __main__ OrderService nested_outer -nm inner_work -n 1" --no-color
🔍 2026-04-19 11:36:04:093 thread=MainThread tid=8722965056 daemon=False cost=12.526ms
[12.526ms] inner_work trace_demo_script.py:27
└─ [12.511ms] sleep <built-in>
Note: the spy message shows nested_outer.inner_work, confirming the nested method was found.
7. Deep call chain
Automatically follows the full call chain depth:
flight_profiler <pid> --cmd "trace __main__ OrderService deep_call_a -n 1" --no-color
🔍 2026-04-19 11:36:05:247 thread=MainThread tid=8722965056 daemon=False cost=6.294ms
[6.294ms] deep_call_a trace_demo_script.py:32
└─ [6.291ms] deep_call_b trace_demo_script.py:35
└─ [6.287ms] deep_call_c trace_demo_script.py:38
└─ [6.268ms] sleep <built-in>
8. Filter with -f
Only trace invocations matching the filter expression. For module-level functions, args[0] is the first argument:
flight_profiler <pid> --cmd "trace __main__ compute -f 'args[0]>=1' -n 1" --no-color
🔍 2026-04-19 11:37:42:600 thread=MainThread tid=8722965056 daemon=False cost=24.215ms
[24.215ms] compute trace_demo_script.py:43
├─ [12.534ms] sleep <built-in>
├─ [6.314ms] helper trace_demo_script.py:48
│ └─ [6.286ms] sleep <built-in>
└─ [5.321ms] helper trace_demo_script.py:48
└─ [5.303ms] sleep <built-in>
For class methods, args[0] is self, so use args[1] for the first real argument.
-i / -et / -d Guide
These three options control what appears in the output at different levels:
| Option | What it filters | Effect |
|---|
-i (interval) | Individual sub-calls in the tree | Hides branches where the call cost < N ms. The invocation is still captured, just with fewer branches shown. |
-et (entrance_time) | Entire invocations | Silently skips invocations where the total entrance cost < N ms. Does not count toward -n. |
-d (depth) | Tree depth | Truncates the tree at N levels. When set, -i is ignored. |
Common combinations:
trace __main__ MyClass method -et 100 -i 10 -n 3
trace __main__ MyClass method -d 2 -n 1
trace __main__ MyClass method -i 0 -n 1
Troubleshooting: No Output
If trace produces no output:
- Method not being called — make sure the code path is actually being triggered
- Wrong module name — use
flight_profiler <pid> --cmd "module /path/to/file.py" --no-color to verify
-et too high — invocations below the threshold are silently skipped (try -et 0)-i too high — sub-calls below the threshold are hidden (try -i 0)
Handling Command Output
Tips
- Start with
-d 2 -n 1 for a quick overview, then remove -d to see the full tree
- Use
-i 10 to focus on sub-calls taking > 10ms, lowering as needed to zoom in
- Combine with
watch to first identify a slow function, then trace to find the bottleneck inside it
- Use
-et to skip uninteresting fast invocations when the method is called frequently
Related Commands
- watch — observe individual function calls (args/return/cost), without call tree
- reload — hot-patch a function after editing its source file, without restarting the process. Use trace to inspect call tree timing before/after reload when you need to verify performance improvements that aren't visible from normal program output
- perf — generate flamegraph for broader performance overview via sampling
Source Files
- CLI plugin:
flight_profiler/plugins/trace/cli_plugin_trace.py
- Parser:
flight_profiler/plugins/trace/trace_parser.py
- Server plugin:
flight_profiler/plugins/trace/server_plugin_trace.py
