3 Commits

Author SHA1 Message Date
kodjo ba28fdeef9 Fixed keyboard latency issues 2026-03-29 18:58:51 +02:00
kodjo 9085bcb09a Added Perf details to profiler control 2026-03-26 20:57:39 +01:00
kodjo 3ea551bc1a Fixed wrong full refresh 2026-03-23 22:32:05 +01:00
13 changed files with 484 additions and 152 deletions
+1
View File
@@ -26,6 +26,7 @@ tools.db
**/*.prof
**/*.db
screenshot*
Capture*
# Created by .ignore support plugin (hsz.mobi)
### Python template
+106 -1
View File
@@ -17,9 +17,13 @@
*/
window.HTMX_DEBUG = false;
window.HTMX_DOM_DEBUG = false;
window.HTMX_SETTLE_DEBUG = false;
(function () {
console.log('Debug HTMX: htmx.logAll();');
console.log('Perf HTMX: window.HTMX_DEBUG=true;');
console.log('DOM mutations: window.HTMX_DOM_DEBUG=true;');
console.log('Settle/transition debug: window.HTMX_SETTLE_DEBUG=true;');
})();
(function () {
@@ -38,12 +42,108 @@ window.HTMX_DEBUG = false;
let counter = 0;
const requests = new WeakMap();
function _startDomObserver(requestId, startTime) {
const observer = new MutationObserver(mutations => {
mutations.forEach(m => {
const el = m.target;
const label = el.id ? `#${el.id}` : `<${el.tagName.toLowerCase()} class="${el.className}">`;
const t = (performance.now() - startTime).toFixed(2);
console.debug(`[HTMX DOM] #${requestId} +${t}ms class changed on ${label} → "${el.className}"`);
});
});
observer.observe(document.body, {attributes: true, subtree: true, attributeFilter: ['class']});
return observer;
}
function getInfo(detail) {
const key = detail?.requestConfig ?? detail?.xhr ?? null;
if (!key || !requests.has(key)) return null;
return requests.get(key);
}
// HTMX_SETTLE_DEBUG: trace transitions/animations + computed style on tsm_ after swap
(function () {
['transitionstart', 'transitionend', 'transitioncancel',
'animationstart', 'animationend'].forEach(evtName => {
document.addEventListener(evtName, e => {
if (!window.HTMX_SETTLE_DEBUG) return;
const t = window._perfT0 ? (performance.now() - window._perfT0).toFixed(1) : '?';
const label = e.target.id ? `#${e.target.id}` : `<${e.target.tagName.toLowerCase()}>`;
console.debug(`[SETTLE +${t}ms] ${evtName} on ${label} | property: ${e.propertyName ?? ''} | duration: ${e.elapsedTime ?? ''}s`);
}, true);
});
document.addEventListener('htmx:afterSwap', e => {
if (!window.HTMX_SETTLE_DEBUG) return;
const target = e.detail?.target;
if (!target?.id?.startsWith('tsm_')) return;
const t = window._perfT0 ? (performance.now() - window._perfT0).toFixed(1) : '?';
const cs = getComputedStyle(target);
console.debug(`[SETTLE +${t}ms] tsm_ computed transitionDuration="${cs.transitionDuration}" transition="${cs.transition}"`);
const child = target.firstElementChild;
if (child) {
const cs2 = getComputedStyle(child);
console.debug(`[SETTLE +${t}ms] tsm_>child computed transitionDuration="${cs2.transitionDuration}" transition="${cs2.transition}"`);
}
});
// Patch setTimeout to detect delayed settle timers (main thread blocked by rendering)
const _origST = window.setTimeout;
window.setTimeout = function (fn, delay, ...args) {
const createdAt = window._perfT0 ? (performance.now() - window._perfT0) : null;
return _origST.call(window, function () {
if (window.HTMX_SETTLE_DEBUG && createdAt !== null && delay >= 1) {
const firedAt = performance.now() - window._perfT0;
const late = (firedAt - createdAt - delay).toFixed(1);
console.debug(`[TIMER] delay=${delay}ms | scheduled +${createdAt.toFixed(1)}ms | fired +${firedAt.toFixed(1)}ms | late=${late}ms`);
}
return fn.apply(this, args);
}, delay, ...args);
};
// PerformanceObserver: log all long tasks (>50ms JS blocks) with timing relative to _perfT0
try {
new PerformanceObserver(list => {
if (!window.HTMX_SETTLE_DEBUG || !window._perfT0) return;
list.getEntries().forEach(entry => {
const start = (entry.startTime - window._perfT0).toFixed(1);
const dur = entry.duration.toFixed(1);
console.debug(`[LONG TASK] start +${start}ms | duration ${dur}ms`);
});
}).observe({entryTypes: ['longtask']});
} catch (e) { /* longtask not supported */ }
// After swap: measure time until next rendering frame to detect rendering blockage
document.addEventListener('htmx:afterSwap', e => {
if (!window.HTMX_SETTLE_DEBUG || !window._perfT0) return;
if (!e.detail?.target?.id?.startsWith('tsm_')) return;
const swapAt = performance.now() - window._perfT0;
requestAnimationFrame(() => {
const rafAt = (performance.now() - window._perfT0).toFixed(1);
console.debug(`[RENDER] swap at +${swapAt.toFixed(1)}ms | next rAF at +${rafAt}ms | rendering blocked ${(rafAt - swapAt).toFixed(1)}ms`);
});
});
// Patch requestAnimationFrame to identify which callback causes the long task
const _origRAF = window.requestAnimationFrame;
window.requestAnimationFrame = function (fn) {
const stack = (new Error().stack || '').split('\n')[2]?.trim() || '?';
const scheduledAt = window._perfT0 ? (performance.now() - window._perfT0) : null;
return _origRAF.call(window, function (timestamp) {
const t0 = performance.now();
const result = fn(timestamp);
if (window.HTMX_SETTLE_DEBUG && scheduledAt !== null) {
const cost = (performance.now() - t0).toFixed(1);
const firedAt = (t0 - window._perfT0).toFixed(1);
if (parseFloat(cost) > 5) {
console.debug(`[RAF SLOW] scheduled +${scheduledAt.toFixed(1)}ms | fired +${firedAt}ms | cost ${cost}ms | ${stack}`);
}
}
return result;
});
};
})();
EVENTS.forEach(eventName => {
document.addEventListener(eventName, (e) => {
if (!window.HTMX_DEBUG) return;
@@ -59,7 +159,8 @@ window.HTMX_DEBUG = false;
if (key) {
const id = ++counter;
const now = performance.now();
requests.set(key, {id, start: now, last: now});
const observer = window.HTMX_DOM_DEBUG ? _startDomObserver(id, now) : null;
requests.set(key, {id, start: now, last: now, observer});
prefix = `#${String(id).padStart(3)} + 0.0ms (Δ 0.0ms)`;
} else {
prefix = `# ? + 0.0ms (Δ 0.0ms)`;
@@ -72,6 +173,10 @@ window.HTMX_DEBUG = false;
const step = (now - info.last).toFixed(1);
info.last = now;
prefix = `#${String(info.id).padStart(3)} +${String(total).padStart(7)}ms (Δ${String(step).padStart(7)}ms)`;
if (eventName === 'htmx:afterSettle' || eventName === 'htmx:sendError') {
info.observer?.disconnect();
}
} else {
prefix = `# ? + ?.?ms (Δ ?.?ms)`;
}
+9
View File
@@ -4,6 +4,9 @@
// Set window.KEYBOARD_DEBUG = true in the browser console to enable traces
window.KEYBOARD_DEBUG = false;
(function () {
console.log('Perf Keyboard: window.KEYBOARD_DEBUG=true;');
})();
(function () {
function kbLog(...args) {
@@ -169,6 +172,8 @@ window.KEYBOARD_DEBUG = false;
* @param {KeyboardEvent} event - The keyboard event
*/
function handleKeyboardEvent(event) {
window._perfT0 = performance.now();
kbLog(`[PERF] keyboard_start: 0ms`);
const key = normalizeKey(event.key);
// Add key to current pressed keys
@@ -260,7 +265,9 @@ window.KEYBOARD_DEBUG = false;
// We have matches and NO element has longer sequences possible
// Trigger ALL matches immediately
for (const match of currentMatches) {
kbLog(`[PERF] before_trigger: ${(performance.now() - window._perfT0).toFixed(2)}ms`);
triggerHtmxAction(match.elementId, match.config, match.combinationStr, match.isInside, event);
kbLog(`[PERF] after_trigger: ${(performance.now() - window._perfT0).toFixed(2)}ms`);
}
// Clear history after triggering
@@ -299,6 +306,8 @@ window.KEYBOARD_DEBUG = false;
KeyboardRegistry.snapshotHistory = [];
}
kbLog(`[PERF] keyboard_end: ${(performance.now() - window._perfT0).toFixed(2)}ms`);
// If we found no match at all, clear the history
// This handles invalid sequences like "A C" when only "A B" exists
if (!foundAnyMatch) {
+6 -1
View File
@@ -376,8 +376,13 @@ function triggerHtmxAction(elementId, config, combinationStr, isInside, event) {
}
}
// Use the HTMX target element as source so htmx-request is added there
// instead of <body>, avoiding a full-document style recalculation.
const targetSelector = config['hx-target'];
const sourceElement = targetSelector ? document.querySelector(targetSelector) : element;
htmxOptions.source = sourceElement ?? element;
// Make AJAX call with htmx
//console.debug(`Triggering HTMX action for element ${elementId}: ${method} ${url}`, htmxOptions);
htmx.ajax(method, url, htmxOptions);
}
+35
View File
@@ -230,6 +230,11 @@
flex-direction: column;
}
/* details wrapper: no extra spacing */
.mf-profiler-span-tree-content details {
display: contents;
}
.mf-profiler-span-row {
display: flex;
align-items: center;
@@ -237,6 +242,31 @@
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 {
border-bottom: none;
}
@@ -288,6 +318,11 @@
background: var(--color-primary);
}
.mf-profiler-span-bar.mf-profiler-fast {
background: var(--color-success);
}
.mf-profiler-span-bar.mf-profiler-medium {
background: var(--color-warning);
}
@@ -232,6 +232,7 @@
-ms-overflow-style: none; /* IE/Edge: hide scrollbar */
border: 1px solid var(--color-border);
border-radius: 10px;
contain: layout style paint; /* Isolate from sibling DOM changes (perf: prevents style recalc cascade) */
}
/* Chrome/Safari: hide scrollbar */
+3 -2
View File
@@ -687,9 +687,10 @@ function updateDatagridSelection(datagridId) {
element.style.userSelect = '';
});
// Loop through the children of the selection manager
// Loop through the children of the inner selection manager (#tsmi_)
const tsmi = document.getElementById(`tsmi_${datagridId}`) ?? selectionManager;
let hasFocusedCell = false;
Array.from(selectionManager.children).forEach((selection) => {
Array.from(tsmi.children).forEach((selection) => {
const selectionType = selection.getAttribute('selection-type');
const elementId = selection.getAttribute('element-id');
+42 -19
View File
@@ -34,6 +34,7 @@ from myfasthtml.core.formatting.dsl.parser import DSLParser
from myfasthtml.core.formatting.engine import FormattingEngine
from myfasthtml.core.instances import MultipleInstance, InstancesManager
from myfasthtml.core.optimized_ft import OptimizedDiv
from myfasthtml.core.profiler import profiler
from myfasthtml.core.utils import merge_classes, is_null
from myfasthtml.icons.carbon import row, column, grid
from myfasthtml.icons.fluent import checkbox_unchecked16_regular
@@ -156,21 +157,21 @@ class Commands(BaseCommands):
"Click on the table",
self._owner,
self._owner.handle_on_click
).htmx(target=f"#tsm_{self._id}")
).htmx(target=f"#tsmi_{self._id}")
def on_key_pressed(self):
return Command("OnKeyPressed",
"Key pressed on the table",
self._owner,
self._owner.on_key_pressed
).htmx(target=f"#tsm_{self._id}")
).htmx(target=f"#tsmi_{self._id}")
def on_mouse_selection(self):
return Command("OnMouseSelection",
"Range selection with mouse",
self._owner,
self._owner.on_mouse_selection
).htmx(target=f"#tsm_{self._id}")
).htmx(target=f"#tsmi_{self._id}")
def toggle_columns_manager(self):
return Command("ToggleColumnsManager",
@@ -689,8 +690,8 @@ class DataGrid(MultipleInstance):
else:
logger.debug(f" is_inside=False")
return self.render_partial()
return self.render_partial(inner_mode=True)
def on_mouse_selection(self, combination, is_inside, cell_id_mousedown, cell_id_mouseup):
logger.debug(f"on_mouse_selection {combination=} {is_inside=} {cell_id_mousedown=} {cell_id_mouseup=}")
if (is_inside and
@@ -706,21 +707,22 @@ class DataGrid(MultipleInstance):
self._state.selection.extra_selected.clear()
self._state.selection.extra_selected.append(("range", (min_col, min_row, max_col, max_row)))
return self.render_partial()
return self.render_partial(inner_mode=True)
@profiler.trace_calls()
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=}")
if combination == "esc":
self._update_current_position(None, reset_selection=True)
return self.render_partial("cell", pos=self._state.selection.last_selected)
return self.render_partial("cell", inner_mode=True, pos=self._state.selection.last_selected)
elif (combination == "enter" and
self._settings.enable_edition and
self._state.selection.selected and
self._state.edition.under_edition is None):
return self._enter_edition(self._state.selection.selected)
elif combination in self._ARROW_KEY_DIRECTIONS:
current_pos = (self._state.selection.selected
or self._state.selection.last_selected
@@ -728,8 +730,8 @@ class DataGrid(MultipleInstance):
direction = self._ARROW_KEY_DIRECTIONS[combination]
new_pos = self._navigate(current_pos, direction)
self._update_current_position(new_pos)
return self.render_partial()
return self.render_partial(inner_mode=True)
def on_column_changed(self):
logger.debug("on_column_changed")
@@ -1178,10 +1180,27 @@ class DataGrid(MultipleInstance):
selected.append(extra_sel)
return Div(
*[Div(selection_type=s_type, element_id=f"{elt_id}") for s_type, elt_id in selected],
Div(
*[Div(selection_type=s_type, element_id=f"{elt_id}") for s_type, elt_id in selected],
id=f"tsmi_{self._id}",
),
id=f"tsm_{self._id}",
selection_mode=f"{self._state.selection.selection_mode}",
)
def mk_selection_manager_inner(self):
selected = []
if self._state.selection.selected:
selected.append(("focus", self._get_element_id_from_pos("cell", self._state.selection.selected)))
for extra_sel in self._state.selection.extra_selected:
selected.append(extra_sel)
return Div(
*[Div(selection_type=s_type, element_id=f"{elt_id}") for s_type, elt_id in selected],
id=f"tsmi_{self._id}",
)
def mk_aggregation_cell(self, col_def, row_index: int, footer_conf, oob=False):
"""
@@ -1268,17 +1287,21 @@ class DataGrid(MultipleInstance):
cls="grid",
style="height: 100%; grid-template-rows: auto 1fr;",
tabindex="-1",
**{"hx-on:htmx:after-swap": f"if(event.detail.target.id==='tsm_{self._id}') updateDatagridSelection('{self._id}');"}
**{"hx-on:htmx:after-swap": f"if(event.detail.target.id==='tsm_{self._id}'||event.detail.target.id==='tsmi_{self._id}') updateDatagridSelection('{self._id}');"}
)
def render_partial(self, fragment="cell", **kwargs):
def render_partial(self, fragment="cell", inner_mode=False, **kwargs):
"""
:param fragment: cell | body | table | header
:param inner_mode: When True, returns mk_selection_manager_inner() (outerHTML swap on #tsmi_)
instead of mk_selection_manager() (outerHTML swap on #tsm_).
Use inner_mode=True for navigation commands (arrow keys, click, mouse selection)
to avoid style recalculation on #tsm_ siblings (e.g. the full table).
:param kwargs: Additional parameters for specific fragments (col_id, optimal_width for header)
:return:
"""
res = [self.mk_selection_manager()]
res = [self.mk_selection_manager_inner() if inner_mode else self.mk_selection_manager()]
extra_attr = {
"hx-on::after-settle": f"initDataGrid('{self._id}');",
+94 -73
View File
@@ -1,6 +1,6 @@
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.IconsHelper import IconsHelper
@@ -24,8 +24,13 @@ logger = logging.getLogger("Profiler")
# Span tree renderer — module-level, passed via PropertiesConf.types
# ---------------------------------------------------------------------------
def _mk_span_rows(span, depth: int, total_ms: float) -> list:
"""Recursively build span rows for the tree view.
def _mk_span_rows(span, depth: int, total_ms: float):
"""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:
span: A ProfilingSpan or CumulativeSpan to render.
@@ -33,9 +38,8 @@ def _mk_span_rows(span, depth: int, total_ms: float) -> list:
total_ms: Reference duration used to compute bar widths.
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)]
if isinstance(span, CumulativeSpan):
@@ -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",
cls="mf-profiler-cumulative-badge",
)
row = Div(
return Div(
*indent,
Div(
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",
)
rows.append(row)
else:
pct = (span.duration_ms / total_ms * 100) if total_ms > 0 else 0
duration_cls = _span_duration_cls(span.duration_ms)
name_cls = "mf-profiler-span-name mf-profiler-span-name-root" if depth == 0 else "mf-profiler-span-name"
row = Div(
*indent,
Div(
Span(span.name, cls=name_cls),
Div(Div(cls=f"mf-profiler-span-bar {duration_cls}", style=f"width:{pct:.1f}%"), cls="mf-profiler-span-bar-bg"),
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",
)
rows.append(row)
for child in span.children:
rows.extend(_mk_span_rows(child, depth + 1, total_ms))
pct = (span.duration_ms / total_ms * 100) if total_ms > 0 else 0
duration_cls = _span_duration_cls(span.duration_ms)
name_cls = "mf-profiler-span-name mf-profiler-span-name-root" if depth == 0 else "mf-profiler-span-name"
row_content = (
*indent,
Div(
Span(span.name, cls=name_cls),
Div(Div(cls=f"mf-profiler-span-bar {duration_cls}", style=f"width:{pct:.1f}%"), cls="mf-profiler-span-bar-bg"),
Span(f"{span.duration_ms:.1f} ms", cls=f"mf-profiler-span-ms {duration_cls}"),
cls="mf-profiler-span-body",
),
)
return rows
if not span.children:
return Div(*row_content, cls="mf-profiler-span-row")
return Details(
Summary(*row_content, cls="mf-profiler-span-row"),
*[_mk_span_rows(child, depth + 1, total_ms) for child in span.children],
open=True,
)
def _span_duration_cls(duration_ms: float) -> str:
@@ -98,8 +103,7 @@ def _span_tree_renderer(span: ProfilingSpan, trace: ProfilingTrace):
Returns:
A FT element containing the full span tree.
"""
rows = _mk_span_rows(span, 0, trace.total_duration_ms)
return Div(*rows, cls="mf-profiler-span-tree-content")
return Div(_mk_span_rows(span, 0, trace.total_duration_ms), cls="mf-profiler-span-tree-content")
class Commands(BaseCommands):
@@ -111,7 +115,7 @@ class Commands(BaseCommands):
self._owner,
self._owner.handle_toggle_detail_view,
).htmx(target=f"#{self._id}")
def toggle_enable(self):
return Command(
"ProfilerToggleEnable",
@@ -145,7 +149,7 @@ class Commands(BaseCommands):
self._owner,
self._owner.handle_select_trace,
kwargs={"trace_id": trace_id},
).htmx(target=f"#{self._id}")
).htmx(target=f"#tr_{trace_id}")
class Profiler(SingleInstance):
@@ -186,15 +190,24 @@ class Profiler(SingleInstance):
def handle_select_trace(self, trace_id: str):
"""Select a trace row and re-render to show it highlighted."""
if self._selected_id is not None:
old_trace = next((t for t in profiler.traces if t.trace_id == self._selected_id), None)
else:
old_trace = None
self._selected_id = trace_id
return self
trace = next((t for t in profiler.traces if t.trace_id == trace_id), None)
return (self._mk_trace_item(trace),
self._mk_trace_item(old_trace),
self._panel.set_right(self._mk_right_panel(trace)))
def handle_toggle_detail_view(self):
"""Toggle detail panel between tree and pie view."""
self._detail_view = "pie" if self._detail_view == "tree" else "tree"
logger.debug(f"Profiler detail view set to {self._detail_view}")
return self
def handle_refresh(self):
"""Refresh the trace list without changing selection."""
return self
@@ -245,32 +258,36 @@ class Profiler(SingleInstance):
id=f"tb_{self._id}",
)
def _mk_trace_item(self, trace: ProfilingTrace):
if trace is None:
return None
ts = trace.timestamp.strftime("%H:%M:%S.") + f"{trace.timestamp.microsecond // 1000:03d}"
duration_cls = self._duration_cls(trace.total_duration_ms)
row_cls = "mf-profiler-row mf-profiler-row-selected" if trace.trace_id == self._selected_id else "mf-profiler-row"
return mk.mk(
Div(
Div(
Span(trace.command_name, cls="mf-profiler-cmd"),
Span(trace.command_description, cls="mf-profiler-cmd-description"),
cls="mf-profiler-cmd-cell",
),
Span(f"{trace.total_duration_ms:.1f} ms", cls=f"mf-profiler-duration {duration_cls}"),
Span(ts, cls="mf-profiler-ts"),
cls=row_cls,
id=f"tr_{trace.trace_id}",
),
command=self.commands.select_trace(trace.trace_id),
)
def _mk_trace_list(self):
"""Build the trace list with one clickable row per recorded trace."""
traces = profiler.traces
if not traces:
return Div("No traces recorded.", cls="mf-profiler-empty")
rows = []
for trace in reversed(traces):
ts = trace.timestamp.strftime("%H:%M:%S.") + f"{trace.timestamp.microsecond // 1000:03d}"
duration_cls = self._duration_cls(trace.total_duration_ms)
row_cls = "mf-profiler-row mf-profiler-row-selected" if trace.trace_id == self._selected_id else "mf-profiler-row"
row = mk.mk(
Div(
Div(
Span(trace.command_name, cls="mf-profiler-cmd"),
Span(trace.command_description, cls="mf-profiler-cmd-description"),
cls="mf-profiler-cmd-cell",
),
Span(f"{trace.total_duration_ms:.1f} ms", cls=f"mf-profiler-duration {duration_cls}"),
Span(ts, cls="mf-profiler-ts"),
cls=row_cls,
),
command=self.commands.select_trace(trace.trace_id),
)
rows.append(row)
rows = [self._mk_trace_item(trace) for trace in reversed(traces)]
return Div(
Div(
@@ -286,7 +303,7 @@ class Profiler(SingleInstance):
def _mk_detail_placeholder(self):
"""Placeholder shown in the right panel before a trace is selected."""
return Div("Select a trace to view details.", cls="mf-profiler-empty")
def _mk_detail_header(self, trace: "ProfilingTrace"):
"""Build the detail panel header with title and tree/pie toggle.
@@ -305,12 +322,14 @@ class Profiler(SingleInstance):
tree_cls = "mf-profiler-view-btn mf-profiler-view-btn-active" if self._detail_view == "tree" else "mf-profiler-view-btn"
pie_cls = "mf-profiler-view-btn mf-profiler-view-btn-active" if self._detail_view == "pie" else "mf-profiler-view-btn"
toggle = Div(
mk.icon(text_bullet_list_tree20_filled, command=self.commands.toggle_detail_view(), tooltip="Span tree", cls=tree_cls),
mk.icon(data_pie24_regular, command=self.commands.toggle_detail_view(), tooltip="Pie chart (coming soon)", cls=pie_cls),
mk.icon(text_bullet_list_tree20_filled, command=self.commands.toggle_detail_view(), tooltip="Span tree",
cls=tree_cls),
mk.icon(data_pie24_regular, command=self.commands.toggle_detail_view(), tooltip="Pie chart (coming soon)",
cls=pie_cls),
cls="mf-profiler-view-toggle",
)
return Div(title, toggle, cls="mf-profiler-detail-header")
def _mk_detail_body(self, trace: "ProfilingTrace"):
"""Build the scrollable detail body: metadata, kwargs and span breakdown.
@@ -321,28 +340,28 @@ class Profiler(SingleInstance):
A FT element for the detail body.
"""
from types import SimpleNamespace
meta_props = Properties(
self,
conf=PropertiesConf(
obj=trace,
groups={"Metadata": {
"command": "command_name",
"description": "command_description",
"duration_ms": "total_duration_ms",
"timestamp": "timestamp",
"command": "command_name",
"description": "command_description",
"duration_ms": "total_duration_ms",
"timestamp": "timestamp",
}},
),
_id="-detail-meta",
)
kwargs_obj = SimpleNamespace(**trace.kwargs) if trace.kwargs else SimpleNamespace()
kwargs_props = Properties(
self,
conf=PropertiesConf(obj=kwargs_obj, groups={"kwargs": {"*": ""}}),
_id="-detail-kwargs",
)
span_props = None
if trace.root_span is not None:
span_props = Properties(
@@ -354,13 +373,13 @@ class Profiler(SingleInstance):
),
_id="-detail-spans",
)
if self._detail_view == "pie":
pie_placeholder = Div("Pie chart — coming soon.", cls="mf-profiler-empty")
return Div(meta_props, kwargs_props, pie_placeholder, cls="mf-profiler-detail-body")
return Div(meta_props, kwargs_props, span_props, cls="mf-profiler-detail-body")
def _mk_detail_panel(self, trace: "ProfilingTrace"):
"""Build the full detail panel for a selected trace.
@@ -376,6 +395,14 @@ class Profiler(SingleInstance):
cls="mf-profiler-detail",
)
def _mk_right_panel(self, trace: "ProfilingTrace"):
"""Build the right panel with a trace detail view."""
return (
self._mk_detail_panel(trace)
if trace is not None
else self._mk_detail_placeholder()
)
# ------------------------------------------------------------------
# Render
# ------------------------------------------------------------------
@@ -386,15 +413,9 @@ class Profiler(SingleInstance):
selected_trace = next(
(t for t in profiler.traces if t.trace_id == self._selected_id), None
)
right_panel = (
self._mk_detail_panel(selected_trace)
if selected_trace is not None
else self._mk_detail_placeholder()
)
self._panel.set_main(self._mk_trace_list())
self._panel.set_right(right_panel)
self._panel.set_right(self._mk_right_panel(selected_trace))
return Div(
self._mk_toolbar(),
self._panel,
+1 -1
View File
@@ -65,7 +65,7 @@ class Properties(MultipleInstance):
cls="mf-properties-value",
title=str(value))
def _render_group_content(self, proxy) -> Div:
def _render_group_content(self, proxy):
"""Render a group's content.
When the group contains exactly one property whose type is registered in
+85 -49
View File
@@ -469,62 +469,98 @@ class ProfilingManager:
return decorator(cls)
return decorator
def trace_calls(self, fn):
"""Function decorator — traces all sub-calls via sys.setprofile().
def trace_calls(self, *, include: list[str] = None, max_depth: int = 10):
"""Function decorator — traces sub-calls via sys.setprofile().
Use for exploration when the bottleneck location is unknown.
sys.setprofile() is scoped to this function's execution only;
the global profiler is restored on exit.
Only calls whose top-level module is in ``include`` are recorded.
By default, the top-level package of the decorated function is included.
``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.
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
@functools.wraps(fn)
def wrapper(*args, **kwargs):
if not manager.enabled:
return fn(*args, **kwargs)
call_stack: list[tuple[ProfilingSpan, object]] = []
# Skip the first call event (fn itself — already represented by root_span)
skip_first = [True]
def _profile(frame, event, arg):
if event == 'call':
if skip_first[0]:
skip_first[0] = False
return
span = ProfilingSpan(name=frame.f_code.co_name)
token = manager.push_span(span)
call_stack.append((span, token))
elif event in ('return', 'exception'):
if call_stack:
span, token = call_stack.pop()
manager.pop_span(span, token)
# Build root span BEFORE activating setprofile so that profiler
# 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
def decorator(fn):
_include = list(include) if include else [fn.__module__.split('.')[0]]
@functools.wraps(fn)
def wrapper(*args, **kwargs):
if not manager.enabled:
return fn(*args, **kwargs)
call_stack: list[tuple[ProfilingSpan, object]] = []
# True if a span was pushed for this call, False if it was skipped.
# Maintained in parallel with the raw call stack so that each
# 'return' event is correctly paired with its 'call', regardless of
# whether the call was traced or filtered out.
open_stack: list[bool] = []
# Skip the first call event (fn itself — already represented by root_span)
skip_first = [True]
def _profile(frame, event, arg):
if event == 'call':
if skip_first[0]:
skip_first[0] = False
return
module = frame.f_globals.get('__name__', '').split('.')[0]
should_trace = module in _include and len(call_stack) < max_depth
if should_trace:
span = ProfilingSpan(name=frame.f_code.co_name)
token = manager.push_span(span)
call_stack.append((span, token))
open_stack.append(True)
else:
open_stack.append(False)
elif event in ('return', 'exception'):
if not open_stack:
return
was_open = open_stack.pop()
if was_open and call_stack:
span, token = call_stack.pop()
manager.pop_span(span, token)
# Build root span BEFORE activating setprofile so that profiler
# 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 ---
+4 -3
View File
@@ -81,9 +81,10 @@ class TestProfilerBehaviour:
def test_i_can_select_trace_by_id(self, profiler_control):
"""Test that handle_select_trace stores the given trace_id."""
trace_id = str(uuid4())
profiler_control.handle_select_trace(trace_id)
assert profiler_control._selected_id == trace_id
trace = make_trace()
profiler._traces.appendleft(trace)
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):
"""Test that selection by trace_id remains correct when a new trace is prepended.
+97 -3
View File
@@ -536,7 +536,7 @@ class TestTraceCalls:
def helper_b():
return 2
@p.trace_calls
@p.trace_calls()
def main_func():
helper_a()
helper_b()
@@ -561,7 +561,7 @@ class TestTraceCalls:
"""Test that trace_calls creates no spans when the profiler is disabled at call time."""
p = fresh_profiler
@p.trace_calls
@p.trace_calls()
def main_func():
return 99
@@ -576,7 +576,7 @@ class TestTraceCalls:
"""Test that trace_calls captures the decorated function's arguments in the root span data."""
p = fresh_profiler
@p.trace_calls
@p.trace_calls()
def compute(x, y):
return x + y
@@ -588,6 +588,100 @@ class TestTraceCalls:
assert main_span.data.get("x") == "3"
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