Compare commits
3 Commits
| Author | SHA1 | Date | |
|---|---|---|---|
| ba28fdeef9 | |||
| 9085bcb09a | |||
| 3ea551bc1a |
@@ -26,6 +26,7 @@ tools.db
|
||||
**/*.prof
|
||||
**/*.db
|
||||
screenshot*
|
||||
Capture*
|
||||
|
||||
# Created by .ignore support plugin (hsz.mobi)
|
||||
### Python template
|
||||
|
||||
@@ -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)`;
|
||||
}
|
||||
|
||||
@@ -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) {
|
||||
|
||||
@@ -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);
|
||||
}
|
||||
|
||||
|
||||
@@ -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 */
|
||||
|
||||
@@ -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');
|
||||
|
||||
|
||||
@@ -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}');",
|
||||
|
||||
@@ -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,
|
||||
|
||||
@@ -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
|
||||
|
||||
@@ -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 ---
|
||||
|
||||
|
||||
@@ -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.
|
||||
|
||||
@@ -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
|
||||
|
||||
Reference in New Issue
Block a user