Added Perf details to profiler control

This commit is contained in:
2026-03-26 20:57:39 +01:00
parent 3ea551bc1a
commit 9085bcb09a
7 changed files with 261 additions and 89 deletions

View File

@@ -230,6 +230,11 @@
flex-direction: column; flex-direction: column;
} }
/* details wrapper: no extra spacing */
.mf-profiler-span-tree-content details {
display: contents;
}
.mf-profiler-span-row { .mf-profiler-span-row {
display: flex; display: flex;
align-items: center; align-items: center;
@@ -237,6 +242,31 @@
border-bottom: 1px solid color-mix(in oklab, var(--color-border) 50%, transparent); border-bottom: 1px solid color-mix(in oklab, var(--color-border) 50%, transparent);
} }
/* summary reuses the same row style — override browser defaults */
summary.mf-profiler-span-row {
list-style: none;
cursor: pointer;
}
summary.mf-profiler-span-row::marker,
summary.mf-profiler-span-row::-webkit-details-marker {
display: none;
}
summary.mf-profiler-span-row::before {
content: '▶';
font-size: 8px;
flex-shrink: 0;
margin-right: 4px;
display: inline-block;
transition: transform 0.15s ease;
color: color-mix(in oklab, var(--color-base-content) 40%, transparent);
}
details[open] > summary.mf-profiler-span-row::before {
transform: rotate(90deg);
}
.mf-profiler-span-row:last-child { .mf-profiler-span-row:last-child {
border-bottom: none; border-bottom: none;
} }
@@ -288,6 +318,11 @@
background: var(--color-primary); background: var(--color-primary);
} }
.mf-profiler-span-bar.mf-profiler-fast {
background: var(--color-success);
}
.mf-profiler-span-bar.mf-profiler-medium { .mf-profiler-span-bar.mf-profiler-medium {
background: var(--color-warning); background: var(--color-warning);
} }

View File

@@ -34,6 +34,7 @@ from myfasthtml.core.formatting.dsl.parser import DSLParser
from myfasthtml.core.formatting.engine import FormattingEngine from myfasthtml.core.formatting.engine import FormattingEngine
from myfasthtml.core.instances import MultipleInstance, InstancesManager from myfasthtml.core.instances import MultipleInstance, InstancesManager
from myfasthtml.core.optimized_ft import OptimizedDiv from myfasthtml.core.optimized_ft import OptimizedDiv
from myfasthtml.core.profiler import profiler
from myfasthtml.core.utils import merge_classes, is_null from myfasthtml.core.utils import merge_classes, is_null
from myfasthtml.icons.carbon import row, column, grid from myfasthtml.icons.carbon import row, column, grid
from myfasthtml.icons.fluent import checkbox_unchecked16_regular from myfasthtml.icons.fluent import checkbox_unchecked16_regular
@@ -709,6 +710,7 @@ class DataGrid(MultipleInstance):
return self.render_partial() return self.render_partial()
@profiler.trace_calls()
def on_key_pressed(self, combination, has_focus, is_inside): def on_key_pressed(self, combination, has_focus, is_inside):
logger.debug(f"on_key_pressed table={self.get_table_name()} {combination=} {has_focus=} {is_inside=}") logger.debug(f"on_key_pressed table={self.get_table_name()} {combination=} {has_focus=} {is_inside=}")
if combination == "esc": if combination == "esc":

View File

@@ -1,6 +1,6 @@
import logging import logging
from fasthtml.components import Div, Span from fasthtml.components import Details, Div, Span, Summary
from myfasthtml.controls.BaseCommands import BaseCommands from myfasthtml.controls.BaseCommands import BaseCommands
from myfasthtml.controls.IconsHelper import IconsHelper from myfasthtml.controls.IconsHelper import IconsHelper
@@ -24,8 +24,13 @@ logger = logging.getLogger("Profiler")
# Span tree renderer — module-level, passed via PropertiesConf.types # Span tree renderer — module-level, passed via PropertiesConf.types
# --------------------------------------------------------------------------- # ---------------------------------------------------------------------------
def _mk_span_rows(span, depth: int, total_ms: float) -> list: def _mk_span_rows(span, depth: int, total_ms: float):
"""Recursively build span rows for the tree view. """Recursively build the span tree.
Spans with children are rendered as a collapsible ``<details>`` element
(expanded by default). Leaf spans and cumulative spans are rendered as
plain ``<div>`` rows. The ``mf-profiler-span-row`` class is applied to
both ``<summary>`` and ``<div>`` so CSS rules are shared.
Args: Args:
span: A ProfilingSpan or CumulativeSpan to render. span: A ProfilingSpan or CumulativeSpan to render.
@@ -33,11 +38,10 @@ def _mk_span_rows(span, depth: int, total_ms: float) -> list:
total_ms: Reference duration used to compute bar widths. total_ms: Reference duration used to compute bar widths.
Returns: Returns:
List of FT elements, one per span row (depth-first order). A single FT element (Details or Div).
""" """
rows = []
indent = [Div(cls="mf-profiler-span-indent") for _ in range(depth)] indent = [Div(cls="mf-profiler-span-indent") for _ in range(depth)]
if isinstance(span, CumulativeSpan): if isinstance(span, CumulativeSpan):
pct = (span.total_ms / total_ms * 100) if total_ms > 0 else 0 pct = (span.total_ms / total_ms * 100) if total_ms > 0 else 0
duration_cls = _span_duration_cls(span.total_ms) duration_cls = _span_duration_cls(span.total_ms)
@@ -45,7 +49,7 @@ def _mk_span_rows(span, depth: int, total_ms: float) -> list:
f"×{span.count} · min {span.min_ms:.2f} · avg {span.avg_ms:.2f} · max {span.max_ms:.2f} ms", f"×{span.count} · min {span.min_ms:.2f} · avg {span.avg_ms:.2f} · max {span.max_ms:.2f} ms",
cls="mf-profiler-cumulative-badge", cls="mf-profiler-cumulative-badge",
) )
row = Div( return Div(
*indent, *indent,
Div( Div(
Span(span.name, cls="mf-profiler-span-name"), Span(span.name, cls="mf-profiler-span-name"),
@@ -56,27 +60,28 @@ def _mk_span_rows(span, depth: int, total_ms: float) -> list:
), ),
cls="mf-profiler-span-row", cls="mf-profiler-span-row",
) )
rows.append(row)
pct = (span.duration_ms / total_ms * 100) if total_ms > 0 else 0
else: duration_cls = _span_duration_cls(span.duration_ms)
pct = (span.duration_ms / total_ms * 100) if total_ms > 0 else 0 name_cls = "mf-profiler-span-name mf-profiler-span-name-root" if depth == 0 else "mf-profiler-span-name"
duration_cls = _span_duration_cls(span.duration_ms) row_content = (
name_cls = "mf-profiler-span-name mf-profiler-span-name-root" if depth == 0 else "mf-profiler-span-name" *indent,
row = Div( Div(
*indent, Span(span.name, cls=name_cls),
Div( Div(Div(cls=f"mf-profiler-span-bar {duration_cls}", style=f"width:{pct:.1f}%"), cls="mf-profiler-span-bar-bg"),
Span(span.name, cls=name_cls), Span(f"{span.duration_ms:.1f} ms", cls=f"mf-profiler-span-ms {duration_cls}"),
Div(Div(cls=f"mf-profiler-span-bar {duration_cls}", style=f"width:{pct:.1f}%"), cls="mf-profiler-span-bar-bg"), cls="mf-profiler-span-body",
Span(f"{span.duration_ms:.1f} ms", cls=f"mf-profiler-span-ms {duration_cls}"), ),
cls="mf-profiler-span-body", )
),
cls="mf-profiler-span-row", if not span.children:
) return Div(*row_content, cls="mf-profiler-span-row")
rows.append(row)
for child in span.children: return Details(
rows.extend(_mk_span_rows(child, depth + 1, total_ms)) Summary(*row_content, cls="mf-profiler-span-row"),
*[_mk_span_rows(child, depth + 1, total_ms) for child in span.children],
return rows open=True,
)
def _span_duration_cls(duration_ms: float) -> str: def _span_duration_cls(duration_ms: float) -> str:
@@ -98,8 +103,7 @@ def _span_tree_renderer(span: ProfilingSpan, trace: ProfilingTrace):
Returns: Returns:
A FT element containing the full span tree. A FT element containing the full span tree.
""" """
rows = _mk_span_rows(span, 0, trace.total_duration_ms) return Div(_mk_span_rows(span, 0, trace.total_duration_ms), cls="mf-profiler-span-tree-content")
return Div(*rows, cls="mf-profiler-span-tree-content")
class Commands(BaseCommands): class Commands(BaseCommands):
@@ -187,12 +191,12 @@ class Profiler(SingleInstance):
def handle_select_trace(self, trace_id: str): def handle_select_trace(self, trace_id: str):
"""Select a trace row and re-render to show it highlighted.""" """Select a trace row and re-render to show it highlighted."""
if self._selected_id is not None: if self._selected_id is not None:
old_trace = next(trace for trace in profiler.traces if trace.trace_id == self._selected_id) old_trace = next((t for t in profiler.traces if t.trace_id == self._selected_id), None)
else: else:
old_trace = None old_trace = None
self._selected_id = trace_id self._selected_id = trace_id
trace = next(trace for trace in profiler.traces if trace.trace_id == trace_id) trace = next((t for t in profiler.traces if t.trace_id == trace_id), None)
return (self._mk_trace_item(trace), return (self._mk_trace_item(trace),
self._mk_trace_item(old_trace), self._mk_trace_item(old_trace),

View File

@@ -65,7 +65,7 @@ class Properties(MultipleInstance):
cls="mf-properties-value", cls="mf-properties-value",
title=str(value)) title=str(value))
def _render_group_content(self, proxy) -> Div: def _render_group_content(self, proxy):
"""Render a group's content. """Render a group's content.
When the group contains exactly one property whose type is registered in When the group contains exactly one property whose type is registered in

View File

@@ -469,62 +469,98 @@ class ProfilingManager:
return decorator(cls) return decorator(cls)
return decorator return decorator
def trace_calls(self, fn): def trace_calls(self, *, include: list[str] = None, max_depth: int = 10):
"""Function decorator — traces all sub-calls via sys.setprofile(). """Function decorator — traces sub-calls via sys.setprofile().
Use for exploration when the bottleneck location is unknown. Only calls whose top-level module is in ``include`` are recorded.
sys.setprofile() is scoped to this function's execution only; By default, the top-level package of the decorated function is included.
the global profiler is restored on exit. ``max_depth`` caps the traced span tree depth as a safety net.
The root span for ``fn`` itself is created before setprofile is sys.setprofile() is scoped to the decorated function's execution only;
the previous profiler is restored on exit.
The root span for the decorated function is created before setprofile is
activated so that profiler internals are not captured as children. activated so that profiler internals are not captured as children.
Args: Args:
fn: The function to instrument. include: Top-level module names to trace (e.g. ``['myapp', 'myfasthtml']``).
Defaults to the top-level package of the decorated function.
max_depth: Maximum depth of the traced span tree. Calls beyond this
depth are ignored. Defaults to 10.
Returns:
A decorator that wraps the function with call tracing.
Example::
@profiler.trace_calls()
def my_handler(self): ...
@profiler.trace_calls(include=['myapp', 'myfasthtml'], max_depth=5)
def my_handler(self): ...
""" """
manager = self manager = self
@functools.wraps(fn) def decorator(fn):
def wrapper(*args, **kwargs): _include = list(include) if include else [fn.__module__.split('.')[0]]
if not manager.enabled:
return fn(*args, **kwargs) @functools.wraps(fn)
def wrapper(*args, **kwargs):
call_stack: list[tuple[ProfilingSpan, object]] = [] if not manager.enabled:
# Skip the first call event (fn itself — already represented by root_span) return fn(*args, **kwargs)
skip_first = [True]
call_stack: list[tuple[ProfilingSpan, object]] = []
def _profile(frame, event, arg): # True if a span was pushed for this call, False if it was skipped.
if event == 'call': # Maintained in parallel with the raw call stack so that each
if skip_first[0]: # 'return' event is correctly paired with its 'call', regardless of
skip_first[0] = False # whether the call was traced or filtered out.
return open_stack: list[bool] = []
span = ProfilingSpan(name=frame.f_code.co_name) # Skip the first call event (fn itself — already represented by root_span)
token = manager.push_span(span) skip_first = [True]
call_stack.append((span, token))
elif event in ('return', 'exception'): def _profile(frame, event, arg):
if call_stack: if event == 'call':
span, token = call_stack.pop() if skip_first[0]:
manager.pop_span(span, token) skip_first[0] = False
return
# Build root span BEFORE activating setprofile so that profiler module = frame.f_globals.get('__name__', '').split('.')[0]
# internals (capture_args, ProfilingSpan.__init__, etc.) are not should_trace = module in _include and len(call_stack) < max_depth
# captured as children. if should_trace:
captured = manager.capture_args(fn, args, kwargs) span = ProfilingSpan(name=frame.f_code.co_name)
root_span = ProfilingSpan(name=fn.__name__) token = manager.push_span(span)
root_span.data.update(captured) call_stack.append((span, token))
root_token = manager.push_span(root_span) open_stack.append(True)
else:
old_profile = sys.getprofile() open_stack.append(False)
sys.setprofile(_profile) elif event in ('return', 'exception'):
try: if not open_stack:
result = fn(*args, **kwargs) return
finally: was_open = open_stack.pop()
sys.setprofile(old_profile) if was_open and call_stack:
manager.pop_span(root_span, root_token) span, token = call_stack.pop()
manager.pop_span(span, token)
return result
# Build root span BEFORE activating setprofile so that profiler
return wrapper # internals (capture_args, ProfilingSpan.__init__, etc.) are not
# captured as children.
captured = manager.capture_args(fn, args, kwargs)
root_span = ProfilingSpan(name=fn.__name__)
root_span.data.update(captured)
root_token = manager.push_span(root_span)
old_profile = sys.getprofile()
sys.setprofile(_profile)
try:
result = fn(*args, **kwargs)
finally:
sys.setprofile(old_profile)
manager.pop_span(root_span, root_token)
return result
return wrapper
return decorator
# --- Overhead measurement --- # --- Overhead measurement ---

View File

@@ -81,9 +81,10 @@ class TestProfilerBehaviour:
def test_i_can_select_trace_by_id(self, profiler_control): def test_i_can_select_trace_by_id(self, profiler_control):
"""Test that handle_select_trace stores the given trace_id.""" """Test that handle_select_trace stores the given trace_id."""
trace_id = str(uuid4()) trace = make_trace()
profiler_control.handle_select_trace(trace_id) profiler._traces.appendleft(trace)
assert profiler_control._selected_id == trace_id profiler_control.handle_select_trace(trace.trace_id)
assert profiler_control._selected_id == trace.trace_id
def test_i_can_select_trace_stable_when_new_trace_added(self, profiler_control): def test_i_can_select_trace_stable_when_new_trace_added(self, profiler_control):
"""Test that selection by trace_id remains correct when a new trace is prepended. """Test that selection by trace_id remains correct when a new trace is prepended.

View File

@@ -536,7 +536,7 @@ class TestTraceCalls:
def helper_b(): def helper_b():
return 2 return 2
@p.trace_calls @p.trace_calls()
def main_func(): def main_func():
helper_a() helper_a()
helper_b() helper_b()
@@ -561,7 +561,7 @@ class TestTraceCalls:
"""Test that trace_calls creates no spans when the profiler is disabled at call time.""" """Test that trace_calls creates no spans when the profiler is disabled at call time."""
p = fresh_profiler p = fresh_profiler
@p.trace_calls @p.trace_calls()
def main_func(): def main_func():
return 99 return 99
@@ -576,7 +576,7 @@ class TestTraceCalls:
"""Test that trace_calls captures the decorated function's arguments in the root span data.""" """Test that trace_calls captures the decorated function's arguments in the root span data."""
p = fresh_profiler p = fresh_profiler
@p.trace_calls @p.trace_calls()
def compute(x, y): def compute(x, y):
return x + y return x + y
@@ -588,6 +588,100 @@ class TestTraceCalls:
assert main_span.data.get("x") == "3" assert main_span.data.get("x") == "3"
assert main_span.data.get("y") == "7" assert main_span.data.get("y") == "7"
def test_i_can_use_trace_calls_with_include_filter(self, fresh_profiler):
"""Test that only calls from included modules are traced."""
import types
p = fresh_profiler
# Simulate a function in a foreign module by overriding __globals__
foreign_mod = types.ModuleType("foreignlib")
foreign_mod.__name__ = "foreignlib"
def _foreign_impl():
return 99
foreign_func = types.FunctionType(
_foreign_impl.__code__,
vars(foreign_mod),
"foreign_func",
)
@p.trace_calls()
def main_func():
foreign_func()
return 42
with p.span("root") as root:
main_func()
main_span = root.children[0]
assert main_span.name == "main_func"
child_names = [c.name for c in main_span.children]
assert "foreign_func" not in child_names, "foreign module must be excluded by default"
def test_i_can_use_trace_calls_with_custom_include(self, fresh_profiler):
"""Test that explicitly listed modules are included even when not the default."""
import types
p = fresh_profiler
extra_mod = types.ModuleType("extralib")
extra_mod.__name__ = "extralib"
def _extra_impl():
return 0
extra_func = types.FunctionType(
_extra_impl.__code__,
vars(extra_mod),
"extra_func",
)
current_top = __name__.split('.')[0]
@p.trace_calls(include=[current_top, "extralib"])
def main_func():
extra_func()
return 42
with p.span("root") as root:
main_func()
main_span = root.children[0]
assert len(main_span.children) == 1, "explicitly included module must be traced"
def test_i_can_use_trace_calls_with_max_depth(self, fresh_profiler):
"""Test that spans beyond max_depth are not recorded."""
p = fresh_profiler
def level3():
return 0
def level2():
level3()
return 1
def level1():
level2()
return 2
@p.trace_calls(max_depth=2)
def main_func():
level1()
return 42
with p.span("root") as root:
main_func()
main_span = root.children[0]
assert main_span.name == "main_func"
assert len(main_span.children) == 1
level1_span = main_span.children[0]
assert level1_span.name == "level1"
assert len(level1_span.children) == 1
level2_span = level1_span.children[0]
assert level2_span.name == "level2"
assert len(level2_span.children) == 0, "level3 must be excluded by max_depth=2"
# --------------------------------------------------------------------------- # ---------------------------------------------------------------------------
# TestProfilingManager — enable/disable, clear, overhead # TestProfilingManager — enable/disable, clear, overhead