diff --git a/README.md b/README.md index e4b9721..e5bc360 100644 --- a/README.md +++ b/README.md @@ -42,12 +42,15 @@ Define a Component: ## Performance records -ETAF includes an opt-in, application-neutral timing recorder. It recognizes -public Event, Action, mount, flush, focus, Data, Resource, and viewport -operations, then correlates coarse ETAF, Ebox, TP, and SQLite stages when those -packages are loaded. +ETAF provides an independent, opt-in, application-neutral timing recorder. It +consumes public Runtime observer reports without advice or private cross-package +probes. Runtime operations such as Event, Action, mount, flush, and unmount are +recorded automatically; Ebox, TP, Data, Resource, and SQLite provider stages +inside the same operation are correlated by sequence. ```elisp +(require 'etaf-performance) +;; In a buffer with a mounted ETAF Runtime: (etaf-performance-mode 1) ;; Use any mounted ETAF application normally. (etaf-performance-show) @@ -58,30 +61,24 @@ reproducing the operations, press `c` in the panel (or run `M-x etaf-performance-copy-report`) to copy a complete report. Press `w` (or run `M-x etaf-performance-export`) to save the same report as an `.eld` file. The portable report includes the Emacs/display environment, power source, -low-power mode, system load, grouped p50/p95/max, individual operations, GC -deltas, and nested stages. The panel header exposes the same environment -context so a machine-wide slowdown is not mistaken for one package hotspot. +low-power mode, native-JIT state, system load, grouped p50/p95/max, individual +operations, GC deltas, and ordered provider stages. The panel header exposes +the same environment context so a machine-wide slowdown is not mistaken for +one package hotspot. -The `*ETAF Performance*` panel shows operation IDs and parent operations, -generation changes, total latency, GC deltas, and nested stage inclusive/self -time. Records are bounded by `etaf-performance-max-records`; disabling the -mode removes all recorder advice. `etaf-performance-summary` computes -operation p50/p95/max statistics on demand, while -`etaf-performance-operation-stage-summary` ranks one operation's package -categories by exclusive time. - -The default registry deliberately uses coarse package boundaries to keep the -measured application representative. A package or application can add a -temporary detail probe without coupling itself to an example: - -```elisp -(etaf-performance-register-stage - 'my-package-expensive-step 'application 'expensive-step) -``` +The `*ETAF Performance*` panel shows operation IDs, generation changes, total +latency, GC deltas, and each flat provider stage in sequence. Provider stages +may overlap, so they are not presented as exclusive/self time. Records are +bounded by `etaf-performance-max-records`; disabling the mode only detaches the +Runtime observer and never rewrites functions. `etaf-performance-summary` +computes operation p50/p95/max statistics on demand, while +`etaf-performance-operation-stage-summary` groups one operation's flat stages +by provider category. Use `etaf-performance-call-operation` or `etaf-performance-with-operation` to trace an arbitrary operation that has no -built-in public boundary. +built-in public boundary. Both delegate to the same Runtime operation boundary; +they do not create a second timer. ## Executable examples diff --git a/README.zh-CN.md b/README.zh-CN.md index f8255bd..8a323bd 100644 --- a/README.zh-CN.md +++ b/README.zh-CN.md @@ -42,12 +42,14 @@ Component(props, Scope) → View → Renderer → Ebox Node → Emacs buffer ## 性能记录面板 -ETAF 内置了一个按需启用、与具体应用无关的性能记录器。它自动识别公共 -Event、Action、mount、flush、focus、Data、Resource 和 viewport 操作;当 -Ebox、TP、SQLite 等包已加载时,还会把这些包的粗粒度阶段关联到同一个 -operation。 +ETAF 提供一个独立、按需加载、与具体应用无关的性能记录器。它消费 Runtime +公共 observer 报告,不使用 advice 或私有跨包探针。Event、Action、mount、flush +和 unmount 等 Runtime operation 会自动记录;同一 operation 内的 Ebox、TP、Data、 +Resource 和 SQLite 等 provider 阶段按 sequence 关联到同一条记录。 ```elisp +(require 'etaf-performance) +;; 在已挂载 ETAF Runtime 的 buffer 中: (etaf-performance-mode 1) ;; 正常操作任意已挂载的 ETAF 应用。 (etaf-performance-show) @@ -56,28 +58,21 @@ operation。 交互采集时先执行 `M-x etaf-performance-clear`,复现一组操作后,在面板按 `c`(或执行 `M-x etaf-performance-copy-report`)即可把完整报告复制到剪贴板; 按 `w`(或执行 `M-x etaf-performance-export`)可保存为 `.eld` 文件。报告包含 -Emacs/显示环境、电源来源、低功耗模式、系统负载、分组 p50/p95/max、每次 -operation、GC 增量和嵌套阶段;面板 header 也显示同一环境信息,避免把整机降频 -误判成某个包的热点。 +Emacs/显示环境、电源来源、低功耗模式、native JIT 状态、系统负载、分组 +p50/p95/max、每次 operation、GC 增量和有序 provider 阶段;面板 header 也显示 +同一环境信息,避免把整机降频误判成某个包的热点。 -`*ETAF Performance*` 面板会显示 operation ID 与父 operation、generation -变化、总耗时、GC 增量,以及嵌套阶段的 inclusive/self 耗时。记录数量由 -`etaf-performance-max-records` 限制;关闭 mode 会移除全部记录 advice。 +`*ETAF Performance*` 面板会显示 operation ID、generation 变化、总耗时、GC +增量,以及 flat provider 阶段的顺序和各自耗时。provider 阶段可能重叠,因此 +不会伪装成 exclusive/self 时间。记录数量由 `etaf-performance-max-records` +限制;关闭 mode 只会解除当前 Runtime 的 observer,不修改任何函数。 `etaf-performance-summary` 会按需计算 operation 的 p50/p95/max, -`etaf-performance-operation-stage-summary` 则按 exclusive 耗时排列单次 -operation 的包级阶段。 - -默认注册表刻意只记录包级粗边界,避免分析工具明显改变被测应用。任意包或 -应用可以临时增加更细的探针,不需要绑定某个示例: - -```elisp -(etaf-performance-register-stage - 'my-package-expensive-step 'application 'expensive-step) -``` +`etaf-performance-operation-stage-summary` 则按 provider category 汇总单次 +operation 的 flat 阶段。 没有内置公共边界的任意操作,可以使用 `etaf-performance-call-operation` 或 `etaf-performance-with-operation` -包裹。 +包裹;它们直接委托同一个 Runtime operation 边界,不建立第二套计时器。 ## 可执行示例 diff --git a/docs/user-guide.en.md b/docs/user-guide.en.md index b0bd9ea..def94ea 100644 --- a/docs/user-guide.en.md +++ b/docs/user-guide.en.md @@ -612,6 +612,8 @@ Enable the generic recorder around any application workload, then open its ordinary `tabulated-list-mode` panel: ```elisp +(require 'etaf-performance) +;; In a buffer with a mounted ETAF Runtime: (etaf-performance-mode 1) (etaf-performance-show) ``` @@ -620,23 +622,26 @@ Run `M-x etaf-performance-clear` before the measured reproduction. Afterwards, press `c` in the panel, or run `M-x etaf-performance-copy-report`, to copy the environment, summary, operation, GC, and stage data. Press `w`, or run `M-x etaf-performance-export`, to save the same portable report as an `.eld` -file. The report and panel header include power source, low-power mode, and -system load alongside the ordinary Emacs/display environment. +file. The report and panel header include power source, low-power mode, +native-JIT state, and system load alongside the ordinary Emacs/display +environment. -The recorder creates bounded operation records for public interaction, -lifecycle, Data, Resource, and viewport boundaries. Loaded Ebox, TP, and -SQLite functions contribute nested coarse stages without depending on ETAF. -Each stage reports inclusive and exclusive milliseconds; failures and quits -are recorded and then re-signaled unchanged. +The recorder only consumes public Runtime observer reports and installs no +advice. Runtime Event, Action, mount, flush, and unmount boundaries create +bounded operation records. Ebox, TP, Data, Resource, and SQLite may contribute +flat provider stages, ordered by sequence, inside the same operation. Stages +may overlap and are therefore not reported as exclusive/self time; failures and +quits are recorded and then re-signaled unchanged. `etaf-performance-summary` calculates grouped p50/p95/max statistics only when -requested. `etaf-performance-operation-stage-summary` ranks the package -categories of one recorded operation by exclusive time. +requested. `etaf-performance-operation-stage-summary` groups the flat stages +of one recorded operation by provider category. -Use `etaf-performance-register-stage` for a temporary package-specific detail -probe. Use `etaf-performance-with-operation` for application work that does -not enter through a built-in public boundary. Disable the mode when the -capture is complete; all installed advice is removed. +Use `etaf-performance-call-operation` or `etaf-performance-with-operation` for +application work that does not enter through a built-in public boundary. Both +delegate to the same Runtime operation boundary. Disable the mode when the +capture is complete; this only detaches the Runtime observer and does not +rewrite any function. ## 14. Public API map @@ -655,7 +660,7 @@ capture is complete; all installed advice is removed. | Resource | `etaf-resource`, `etaf-resource-result`, `etaf-error-boundary-run` | Own loader state and cleanup | | Official UI | `require 'etaf-ui`, `etaf-button`, `etaf-checkbox`, `etaf-number-input`, `etaf-label`, `etaf-panel`, `etaf-data-grid` | Use ready-made Components | | Playground | `etaf-playground-open`, `etaf-playground-open-ui`, `etaf-playground-close`, `ebox-playground-open`, `ebox-playground-close` | Explore the corresponding layer interactively | -| Performance | `etaf-performance-mode`, `etaf-performance-show`, `etaf-performance-copy-report`, `etaf-performance-export`, `etaf-performance-environment-data`, `etaf-performance-records`, `etaf-performance-summary`, `etaf-performance-operation-stage-summary`, `etaf-performance-with-operation`, `etaf-performance-register-stage` | Attribute generic operation latency across loaded packages and share reports | +| Performance | `etaf-performance-start`, `etaf-performance-stop`, `etaf-performance-mode`, `etaf-performance-show`, `etaf-performance-copy-report`, `etaf-performance-export`, `etaf-performance-environment-data`, `etaf-performance-records`, `etaf-performance-summary`, `etaf-performance-operation-stage-summary`, `etaf-performance-call-operation`, `etaf-performance-with-operation` | Attribute generic operation latency through public observers and share reports | Most applications need only `etaf-view`, `etaf-mount`, `etaf-define-component`, `etaf-ref`, and event callbacks at first. The remaining APIs are additive capabilities, not prerequisites for understanding the core grammar. diff --git a/docs/user-guide.zh.md b/docs/user-guide.zh.md index 8f02def..dac96df 100644 --- a/docs/user-guide.zh.md +++ b/docs/user-guide.zh.md @@ -605,6 +605,8 @@ Loader 错误会保存在 `etaf-resource-error`;cleanup/type 错误保持可 对任意应用负载启用通用记录器,然后打开普通的 `tabulated-list-mode` 面板: ```elisp +(require 'etaf-performance) +;; 在已挂载 ETAF Runtime 的 buffer 中: (etaf-performance-mode 1) (etaf-performance-show) ``` @@ -612,21 +614,23 @@ Loader 错误会保存在 `etaf-resource-error`;cleanup/type 错误保持可 正式复现前执行 `M-x etaf-performance-clear`。复现后在面板按 `c`,或者执行 `M-x etaf-performance-copy-report`,可把环境、汇总、operation、GC 和阶段数据 完整复制到剪贴板;按 `w` 或执行 `M-x etaf-performance-export` 可导出 `.eld` -文件。报告和面板 header 还会显示电源来源、低功耗模式与系统负载。这两种报告 -都可以直接发送给分析者。 +文件。报告和面板 header 还会显示电源来源、低功耗模式、native JIT 状态与系统 +负载。这两种报告都可以直接发送给分析者。 -记录器会为公共交互、lifecycle、Data、Resource 和 viewport 边界创建有界的 -operation 记录。已加载的 Ebox、TP 与 SQLite 可以贡献嵌套的粗粒度阶段, -但不需要反向依赖 ETAF。每个阶段同时报告 inclusive 与 exclusive 毫秒; -error 和 quit 会先被记录,再保持原条件继续抛出。 +记录器只消费 Runtime 的公共 observer 报告,不安装 advice。Runtime 的 Event、 +Action、mount、flush 和 unmount 会创建有界 operation 记录;同一 operation 内, +Ebox、TP、Data、Resource 与 SQLite 可以贡献按 sequence 排列的 flat provider +阶段。阶段可能重叠,因此不声称 exclusive/self 时间;error 和 quit 会先被记录, +再保持原条件继续抛出。 `etaf-performance-summary` 只在请求时计算分组后的 p50/p95/max; -`etaf-performance-operation-stage-summary` 会按 exclusive 时间排列某条记录 -中的包级阶段。 +`etaf-performance-operation-stage-summary` 会按 provider category 汇总某条记录 +中的 flat 阶段。 -使用 `etaf-performance-register-stage` 临时加入包级细节探针。没有经过内置 -公共边界的应用操作可以使用 `etaf-performance-with-operation`。采集结束后 -关闭 mode,所有已安装 advice 都会被移除。 +没有经过内置公共边界的应用操作可以使用 +`etaf-performance-call-operation`/`etaf-performance-with-operation`;它们直接委托 +同一个 Runtime operation 边界。采集结束后关闭 mode,只解除当前 Runtime 的 +observer,不修改任何函数。 ## 14. 公共 API 速查 @@ -645,7 +649,7 @@ error 和 quit 会先被记录,再保持原条件继续抛出。 | Resource | `etaf-resource`、`etaf-resource-result`、`etaf-error-boundary-run` | 管理 loader 状态和 cleanup | | 官方 UI | `require 'etaf-ui`、`etaf-button`、`etaf-checkbox`、`etaf-number-input`、`etaf-label`、`etaf-panel`、`etaf-data-grid` | 使用现成 Component | | Playground | `etaf-playground-open`、`etaf-playground-open-ui`、`etaf-playground-close`、`ebox-playground-open`、`ebox-playground-close` | 探索对应层 | -| 性能分析 | `etaf-performance-mode`、`etaf-performance-show`、`etaf-performance-copy-report`、`etaf-performance-export`、`etaf-performance-environment-data`、`etaf-performance-records`、`etaf-performance-summary`、`etaf-performance-operation-stage-summary`、`etaf-performance-with-operation`、`etaf-performance-register-stage` | 跨已加载包定位通用 operation 的耗时并分享报告 | +| 性能分析 | `etaf-performance-start`、`etaf-performance-stop`、`etaf-performance-mode`、`etaf-performance-show`、`etaf-performance-copy-report`、`etaf-performance-export`、`etaf-performance-environment-data`、`etaf-performance-records`、`etaf-performance-summary`、`etaf-performance-operation-stage-summary`、`etaf-performance-call-operation`、`etaf-performance-with-operation` | 通过公共 observer 定位通用 operation 的耗时并分享报告 | 大多数应用一开始只需要 `etaf-view`、`etaf-mount`、`etaf-define-component`、`etaf-ref` 和事件 callback。其余 API 都是可选能力,不是理解核心语法的前置条件。 diff --git a/etaf-performance.el b/etaf-performance.el index 45ad2aa..936f744 100644 --- a/etaf-performance.el +++ b/etaf-performance.el @@ -1,12 +1,13 @@ -;;; etaf-performance.el --- Cross-package ETAF performance records -*- lexical-binding: t; -*- +;;; etaf-performance.el --- Optional ETAF operation recorder -*- lexical-binding: t; -*- ;; SPDX-License-Identifier: GPL-3.0-or-later ;;; Commentary: -;; This opt-in recorder follows one user-visible ETAF operation through the -;; reactive, data, Ebox, and TP layers. Other packages remain independent: -;; instrumentation is attached here, after those packages are loaded. +;; This optional package records the flat provider reports emitted by one +;; mounted ETAF Runtime. It has no advice registry and owns no timing path: +;; operation boundaries and durations come exclusively from the Runtime +;; observer contract. ;;; Code: @@ -15,9 +16,10 @@ (require 'ring) (require 'seq) (require 'tabulated-list) +(require 'etaf-runtime) (defgroup etaf-performance nil - "Operation and stage timing for ETAF applications." + "Operation timing reports emitted by ETAF runtimes." :group 'etaf) (defcustom etaf-performance-max-records 200 @@ -25,129 +27,33 @@ :type 'integer :group 'etaf-performance) -(defconst etaf-performance-report-format-version 1 +(defconst etaf-performance-report-format-version 2 "Current portable performance report format version.") (cl-defstruct (etaf-performance-stage (:constructor etaf-performance--stage-create)) - "One timed stage inside an ETAF operation. -All duration fields are milliseconds." - id category function detail depth start-time end-time inclusive exclusive - status) + "One flat provider report belonging to an operation." + sequence provider category name duration status metadata) (cl-defstruct (etaf-performance-operation (:constructor etaf-performance--operation-create)) - "One bounded, user-visible ETAF operation record. -ELAPSED is milliseconds; START-TIME and END-TIME are wall-clock seconds." - id parent-id kind label runtime-id buffer-name generation-before generation-after - start-time end-time elapsed status - gc-count-before gc-count-after gc-elapsed-before gc-elapsed-after metadata - stages) + "One completed Runtime operation and its ordered provider reports." + id kind label runtime-id buffer-name generation-before generation-after + elapsed status gc-count gc-elapsed metadata stages) -(cl-defstruct (etaf-performance--stage-frame - (:constructor etaf-performance--stage-frame-create)) - id category function detail depth start-time (child-time 0.0)) +(cl-defstruct (etaf-performance--attachment + (:constructor etaf-performance--attachment-create)) + sink pending-keys) (defvar etaf-performance--record-ring nil) -(defvar etaf-performance--next-operation-id 0) -(defvar etaf-performance--next-stage-id 0) -(defvar etaf-performance--current-operation nil) -(defvar etaf-performance--stage-stack nil) -(defvar etaf-performance--installed-advices nil) -(defvar etaf-performance-mode nil) +(defvar etaf-performance--pending (make-hash-table :test #'equal)) +(defvar etaf-performance--attachments (make-hash-table :test #'eq)) +(defvar-local etaf-performance--mode-runtime nil) -(defconst etaf-performance--operation-functions - '((etaf-dispatch-event event) - (etaf-dispatch action) - (etaf-runtime-mount mount) - (etaf-runtime-flush flush) - (etaf-runtime-unmount unmount) - (etaf-data-load data-load) - (etaf-data-source-load-page data-prepare) - (etaf-data-mutate data-mutate) - (etaf-resource-load resource-load) - (ebox-surface-update-buffer-viewport viewport) - (ebox-rerender-buffer-with-context rerender) - (etaf-focus focus) - (etaf-focus-next focus) - (etaf-focus-previous focus) - (etaf-activate activate) - (etaf-activate-mouse activate)) - "Coarse functions that begin visible operation records.") - -(defvar etaf-performance--stage-functions - '((etaf--runtime-component-overlay runtime owner-overlay) - (etaf--runtime-render-root-turn runtime root-turn) - (etaf--runtime-build-generation runtime generation) - (etaf--runtime-render-dirty-component runtime component-effect) - (etaf--runtime-render-dirty-host-properties runtime host-property-effect) - (etaf--runtime-render-dirty-range runtime range-effect) - (etaf--runtime-render-dirty-inline-range runtime inline-range-effect) - (etaf--runtime-render-dirty-slot-range runtime slot-range-effect) - (etaf-compiler-instantiate compiler blueprint-instantiate) - (etaf-sqlite--call sqlite call) - (etaf-sqlite--transaction sqlite transaction) - (etaf-sqlite--select-items sqlite query) - (etaf-sqlite--mutate sqlite mutate) - (ebox-incremental-consume-candidate ebox candidate) - (ebox-incremental--prepare-logical-candidate ebox candidate-preparation) - (ebox-incremental--candidate-logical-root ebox candidate-root) - (ebox-incremental--candidate-local-index-delta ebox index-delta) - (ebox-incremental--candidate-copy-index-table ebox index-table-copy) - (ebox-incremental--candidate-dirty-set-from-touched ebox dirty-diff) - (ebox-incremental--candidate-map-native-postorder ebox native-postorder) - (ebox-incremental--candidate-range-ref-overlay ebox range-index) - (ebox-incremental--candidate-structural-caches ebox structural-cache) - (ebox-incremental--prepare-declarative-runtime ebox runtime-preparation) - (ebox-incremental--candidate-layout-snapshots ebox snapshot-seed) - (ebox-incremental--candidate-state ebox candidate-state) - (ebox-incremental--surface-commit-input ebox owner-proof) - (ebox-incremental--mixed-owner-proof ebox mixed-owner-proof) - (ebox-incremental--formatting-context-reflow-proof ebox context-proof) - (ebox-incremental--common-runtime-ancestor-id ebox common-ancestor) - (ebox-incremental--formatting-context-reflow-fast-eligible-p - ebox context-eligibility) - (ebox-incremental--cached-layout-snapshot-details ebox snapshot-details) - (ebox-incremental--layout-owner-plan ebox owner-plan) - (ebox-incremental--span-patch-projection-proof ebox span-proof) - (ebox-incremental--allocation-closure-proof ebox allocation-proof) - (ebox-incremental--two-owner-allocation-proof ebox allocation-union-proof) - (ebox-surface--cascade-local-owner-proof-p ebox cascade-proof) - (ebox-incremental--layout-owner-report ebox owner-report) - (ebox-incremental--surface-state-overrides ebox state-overrides) - (ebox-surface-update-buffer-scoped ebox scoped-publication) - (ebox-surface--project ebox projection) - (ebox-surface--projection-start ebox projection-start) - (ebox-surface--style-state-table ebox style-state-copy) - (ebox-tree-subject-index ebox selector-subject-index) - (ebox-surface--project-native-stable-node-table ebox native-object-reuse) - (ebox-surface--mixed-owner-output ebox mixed-owner-output) - (ebox-surface--rendered-fragments ebox fragments) - (ebox-surface--render-candidate ebox candidate-render) - (ebox-surface--surface-plan ebox surface-plan) - (ebox-surface--native-patch-result ebox native-patch-result) - (ebox-native-commit-render ebox native-commit) - (ebox-native-commit-context-axes-stable-p ebox native-axes-proof) - (ebox-native-commit--apply-fragment-style-delta - ebox fragment-style-delta) - (ebox-native-reflow--compile-layout-package compiler layout-ir) - (ebox-native-reflow--compile-retained-layout-package - compiler retained-layout-ir) - (ebox-native-reflow--materialize-layout-tape ebox tape-decode) - (ebox-surface--native-owned-ranges ebox native-ownership) - (ebox-surface--owned-ranges ebox ownership-ranges) - (ebox-commit ebox commit) - (ebox-render-to-buffer ebox render-to-buffer) - (tp-surface-update-scoped tp scoped-update) - (tp-object-reuse-subtree tp object-subtree-reuse) - (tp--prepare-surface tp prepare) - (tp-commit-batch-result-create tp batch-result) - (tp--prepare-commit-batch tp prepare-batch) - (tp--commit-batch-retained-mount-state tp mount-proof) - (tp--retain-candidate-mount-state tp retain-mounts) - (tp--validate-retained-batch-precommit tp retained-precommit) - (tp--publish-one-surface tp publication)) - "Cross-package coarse stages installed only while recording is enabled.") +(defconst etaf-performance--report-context-keys + '(:format-version :operation-id :sequence :runtime-id :buffer-name + :provider :stage :status :duration-ms) + "Flat report keys represented by typed recorder fields.") (defun etaf-performance-records () "Return a newest-first copy of completed performance records." @@ -162,47 +68,60 @@ ELAPSED is milliseconds; START-TIME and END-TIME are wall-clock seconds." (rank (max 1 (ceiling (* percentile (length ordered)))))) (nth (1- rank) ordered)))) -;;;###autoload -(defun etaf-performance-operation-stage-summary (operation) - "Return stage-category timing summaries for OPERATION. +(defun etaf-performance--provider-category (provider) + "Return the public recorder category for PROVIDER." + (if (eq provider 'etaf) 'runtime provider)) -Each result plist contains `:category', `:count', `:inclusive-ms', and -`:exclusive-ms'. Results are sorted by decreasing exclusive time. Inclusive -totals may overlap because they preserve nested span semantics; exclusive -totals partition the recorded work." +(defun etaf-performance--report-metadata (report) + "Return REPORT fields not represented by typed recorder fields." + (let (metadata) + (while report + (let ((key (pop report)) + (value (pop report))) + (unless (memq key etaf-performance--report-context-keys) + (setq metadata (append metadata (list key (copy-tree value))))))) + metadata)) + +(defun etaf-performance--stage-from-report (report) + "Create one flat recorder stage from provider REPORT." + (let ((provider (plist-get report :provider))) + (etaf-performance--stage-create + :sequence (plist-get report :sequence) + :provider provider + :category (etaf-performance--provider-category provider) + :name (plist-get report :stage) + :duration (plist-get report :duration-ms) + :status (plist-get report :status) + :metadata (etaf-performance--report-metadata report)))) + +(defun etaf-performance-operation-stage-summary (operation) + "Summarize flat provider stages in OPERATION by category. + +Each result contains `:category', `:count', and `:duration-ms'. Provider +durations may overlap and are therefore never presented as exclusive time." (unless (etaf-performance-operation-p operation) (signal 'wrong-type-argument (list 'etaf-performance-operation-p operation))) (let ((table (make-hash-table :test #'eq)) result) (dolist (stage (etaf-performance-operation-stages operation)) (let* ((category (etaf-performance-stage-category stage)) - (value (or (gethash category table) (vector 0 0.0 0.0)))) - (aset value 0 (1+ (aref value 0))) - (aset value 1 (+ (aref value 1) - (etaf-performance-stage-inclusive stage))) - (aset value 2 (+ (aref value 2) - (etaf-performance-stage-exclusive stage))) - (puthash category value table))) + (entry (or (gethash category table) (cons 0 0.0)))) + (setcar entry (1+ (car entry))) + (setcdr entry (+ (cdr entry) + (etaf-performance-stage-duration stage))) + (puthash category entry table))) (maphash - (lambda (category value) - (push (list :category category :count (aref value 0) - :inclusive-ms (aref value 1) - :exclusive-ms (aref value 2)) + (lambda (category entry) + (push (list :category category :count (car entry) + :duration-ms (cdr entry)) result)) table) - (sort result - (lambda (left right) - (> (plist-get left :exclusive-ms) - (plist-get right :exclusive-ms)))))) + (sort result (lambda (left right) + (> (plist-get left :duration-ms) + (plist-get right :duration-ms)))))) -;;;###autoload (defun etaf-performance-summary (&optional records) - "Summarize completed RECORDS by operation kind and label. - -RECORDS defaults to `etaf-performance-records'. Each result plist contains -`:kind', `:label', `:count', `:min-ms', `:p50-ms', `:p95-ms', `:max-ms', and -`:mean-ms'. Summary calculation happens on demand, never in the measured hot -path." + "Summarize completed RECORDS by operation kind and label." (let ((groups (make-hash-table :test #'equal)) result) (dolist (operation (or records (etaf-performance-records))) (let ((key (cons (etaf-performance-operation-kind operation) @@ -222,52 +141,207 @@ path." :mean-ms (/ (apply #'+ samples) (float (length samples)))) result)) groups) - (sort result - (lambda (left right) - (> (plist-get left :p95-ms) (plist-get right :p95-ms)))))) + (sort result (lambda (left right) + (> (plist-get left :p95-ms) + (plist-get right :p95-ms)))))) + +(defun etaf-performance--retain (operation) + "Retain completed OPERATION under the configured bound." + (let ((limit (max 0 etaf-performance-max-records))) + (if (zerop limit) + (setq etaf-performance--record-ring nil) + (unless (and etaf-performance--record-ring + (= (ring-size etaf-performance--record-ring) limit)) + (let ((existing (etaf-performance-records))) + (setq etaf-performance--record-ring (make-ring limit)) + (dolist (record (reverse (seq-take existing limit))) + (ring-insert etaf-performance--record-ring record)))) + (ring-insert etaf-performance--record-ring operation)))) + +(defun etaf-performance--final-report-p (report) + "Return non-nil when REPORT closes one Runtime operation." + (and (eq (plist-get report :provider) 'etaf) + (eq (plist-get report :stage) 'runtime-operation))) + +(defun etaf-performance--operation-from-reports (reports) + "Create one completed operation from ordered flat REPORTS." + (let* ((ordered + (sort reports + (lambda (left right) + (< (plist-get left :sequence) + (plist-get right :sequence))))) + (final (car (last ordered)))) + (etaf-performance--operation-create + :id (plist-get final :operation-id) + :kind (plist-get final :kind) + :label (plist-get final :label) + :runtime-id (plist-get final :runtime-id) + :buffer-name (plist-get final :buffer-name) + :generation-before (plist-get final :generation-before) + :generation-after (plist-get final :generation-after) + :elapsed (plist-get final :duration-ms) + :status (plist-get final :status) + :gc-count (or (plist-get final :gc-count) 0) + :gc-elapsed (or (plist-get final :gc-duration-ms) 0.0) + :metadata (etaf-performance--report-metadata final) + :stages (mapcar #'etaf-performance--stage-from-report ordered)))) + +(defun etaf-performance--pending-key (report) + "Return the Runtime and operation correlation key for REPORT." + (cons (plist-get report :runtime-id) + (plist-get report :operation-id))) + +(defun etaf-performance--capture (runtime report) + "Capture one flat REPORT emitted by RUNTIME." + (let* ((attachment (gethash runtime etaf-performance--attachments)) + (key (etaf-performance--pending-key report)) + (reports (cons (copy-tree report) + (gethash key etaf-performance--pending)))) + (when attachment + (cl-pushnew key (etaf-performance--attachment-pending-keys attachment) + :test #'equal)) + (if (etaf-performance--final-report-p report) + (progn + (remhash key etaf-performance--pending) + (when attachment + (setf (etaf-performance--attachment-pending-keys attachment) + (delete key + (etaf-performance--attachment-pending-keys + attachment)))) + (etaf-performance--retain + (etaf-performance--operation-from-reports reports)) + (when (eq (plist-get report :kind) 'unmount) + (remhash runtime etaf-performance--attachments))) + (puthash key reports etaf-performance--pending))) + nil) + +(defun etaf-performance--discard-pending (attachment) + "Discard unfinished records owned by ATTACHMENT." + (dolist (key (etaf-performance--attachment-pending-keys attachment)) + (remhash key etaf-performance--pending)) + (setf (etaf-performance--attachment-pending-keys attachment) nil)) + +;;;###autoload +(defun etaf-performance-start (runtime) + "Attach the recorder to mounted RUNTIME and return RUNTIME. + +Attachment is idempotent for this recorder. A Runtime already owned by a + different observer is rejected rather than replaced." + (setq runtime (etaf-runtime-require-mounted runtime)) + (let* ((attachment (gethash runtime etaf-performance--attachments)) + (owned-sink (and attachment + (etaf-performance--attachment-sink attachment)))) + (cond + (owned-sink + (unless (etaf-runtime-compare-and-set-observer + runtime owned-sink owned-sink) + (error "ETAF recorder no longer owns the Runtime observer")) + runtime) + (t + (when attachment + (remhash runtime etaf-performance--attachments)) + (let* ((sink (lambda (report) + (etaf-performance--capture runtime report))) + (new (etaf-performance--attachment-create + :sink sink :pending-keys nil))) + (unless (etaf-runtime-compare-and-set-observer runtime nil sink) + (error "ETAF runtime already has a different observer")) + (puthash runtime new etaf-performance--attachments) + runtime))))) + +;;;###autoload +(defun etaf-performance-stop (runtime) + "Detach this recorder from RUNTIME and return RUNTIME. + +If another observer replaced the recorder sink, leave that observer intact." + (unless (etaf-runtime-p runtime) + (signal 'wrong-type-argument (list 'etaf-runtime-p runtime))) + (when-let* ((attachment + (gethash runtime etaf-performance--attachments))) + (let ((sink (etaf-performance--attachment-sink attachment))) + (condition-case nil + (etaf-runtime-compare-and-set-observer runtime sink nil) + (etaf-runtime-error nil))) + (etaf-performance--discard-pending attachment) + (remhash runtime etaf-performance--attachments)) + runtime) + +;;;###autoload +(defun etaf-performance-call-operation (runtime kind label function) + "Call FUNCTION as KIND and LABEL through RUNTIME's operation boundary." + (etaf-runtime-call-operation runtime kind label function)) + +(cl-defmacro etaf-performance-with-operation + ((runtime kind label) &rest body) + "Evaluate BODY through RUNTIME's canonical operation boundary." + (declare (indent 1) (debug ((form form form) body))) + `(etaf-performance-call-operation + ,runtime ,kind ,label (lambda () ,@body))) + +;;;###autoload +(define-minor-mode etaf-performance-mode + "Record operations for the Runtime mounted in the current buffer." + :init-value nil + :lighter " ETAF-Perf" + (if etaf-performance-mode + (let ((runtime (etaf-runtime-for-buffer (current-buffer)))) + (unless runtime + (setq etaf-performance-mode nil) + (user-error "Current buffer has no mounted ETAF runtime")) + (condition-case condition + (progn + (etaf-performance-start runtime) + (setq etaf-performance--mode-runtime runtime)) + (error + (setq etaf-performance-mode nil) + (signal (car condition) (cdr condition))))) + (when etaf-performance--mode-runtime + (etaf-performance-stop etaf-performance--mode-runtime) + (setq etaf-performance--mode-runtime nil)))) + +;;;###autoload +(defun etaf-performance-clear () + "Clear completed and unfinished performance records." + (interactive) + (setq etaf-performance--record-ring nil) + (clrhash etaf-performance--pending) + (when-let* ((panel (get-buffer "*ETAF Performance*"))) + (with-current-buffer panel + (when (derived-mode-p 'etaf-performance-panel-mode) + (tabulated-list-revert)))) + nil) (defun etaf-performance--stage-report-data (stage) - "Return portable report data for performance STAGE." - (list :id (etaf-performance-stage-id stage) + "Return portable report data for STAGE." + (list :sequence (etaf-performance-stage-sequence stage) + :provider (etaf-performance-stage-provider stage) :category (etaf-performance-stage-category stage) - :function (etaf-performance-stage-function stage) - :detail (etaf-performance-stage-detail stage) - :depth (etaf-performance-stage-depth stage) - :inclusive-ms (etaf-performance-stage-inclusive stage) - :exclusive-ms (etaf-performance-stage-exclusive stage) - :status (etaf-performance-stage-status stage))) + :stage (etaf-performance-stage-name stage) + :duration-ms (etaf-performance-stage-duration stage) + :status (etaf-performance-stage-status stage) + :metadata (copy-tree (etaf-performance-stage-metadata stage)))) (defun etaf-performance--operation-report-data (operation) - "Return portable report data for performance OPERATION." - (list - :id (etaf-performance-operation-id operation) - :parent-id (etaf-performance-operation-parent-id operation) - :kind (etaf-performance-operation-kind operation) - :label (etaf-performance-operation-label operation) - :runtime-id (etaf-performance-operation-runtime-id operation) - :buffer-name (etaf-performance-operation-buffer-name operation) - :generation-before - (etaf-performance-operation-generation-before operation) - :generation-after - (etaf-performance-operation-generation-after operation) - :started-at - (format-time-string "%Y-%m-%dT%H:%M:%S%z" - (seconds-to-time - (etaf-performance-operation-start-time operation))) - :elapsed-ms (etaf-performance-operation-elapsed operation) - :status (etaf-performance-operation-status operation) - :gc-count-delta - (- (etaf-performance-operation-gc-count-after operation) - (etaf-performance-operation-gc-count-before operation)) - :gc-elapsed-ms - (* 1000.0 - (- (etaf-performance-operation-gc-elapsed-after operation) - (etaf-performance-operation-gc-elapsed-before operation))) - :metadata (copy-tree (etaf-performance-operation-metadata operation)) - :stage-summary (etaf-performance-operation-stage-summary operation) - :stages - (mapcar #'etaf-performance--stage-report-data - (etaf-performance-operation-stages operation)))) + "Return portable report data for OPERATION." + (list :id (etaf-performance-operation-id operation) + :kind (etaf-performance-operation-kind operation) + :label (etaf-performance-operation-label operation) + :runtime-id (etaf-performance-operation-runtime-id operation) + :buffer-name (etaf-performance-operation-buffer-name operation) + :generation-before + (etaf-performance-operation-generation-before operation) + :generation-after + (etaf-performance-operation-generation-after operation) + :elapsed-ms (etaf-performance-operation-elapsed operation) + :status (etaf-performance-operation-status operation) + :gc-count (etaf-performance-operation-gc-count operation) + :gc-duration-ms (etaf-performance-operation-gc-elapsed operation) + :metadata (copy-tree (etaf-performance-operation-metadata operation)) + :stage-summary + (etaf-performance-operation-stage-summary operation) + :stages + (mapcar #'etaf-performance--stage-report-data + (etaf-performance-operation-stages operation)))) (defun etaf-performance--parse-darwin-power-state (battery-output custom-output) @@ -324,25 +398,23 @@ BATTERY-OUTPUT identifies the active source; CUSTOM-OUTPUT contains settings." (list (window-body-width nil t) (window-body-height nil t)) :gc-cons-threshold gc-cons-threshold :gc-cons-percentage gc-cons-percentage + :native-comp-jit-compilation + (and (boundp 'native-comp-jit-compilation) + native-comp-jit-compilation) :load-average (load-average t) :power-state (etaf-performance--power-state))) ;;;###autoload (defun etaf-performance-report-data (&optional records) - "Return a portable report for completed performance RECORDS. - -RECORDS defaults to `etaf-performance-records'. Operations are returned in -capture order, oldest first. The report contains only plain Lisp data so it -can be copied, saved, and read in another Emacs process." + "Return a portable report for completed performance RECORDS." (let ((records (or records (etaf-performance-records)))) - (list - :format-version etaf-performance-report-format-version - :generated-at (format-time-string "%Y-%m-%dT%H:%M:%S%z") - :environment (etaf-performance-environment-data) - :summary (etaf-performance-summary records) - :operations - (mapcar #'etaf-performance--operation-report-data - (reverse (copy-sequence records)))))) + (list :format-version etaf-performance-report-format-version + :generated-at (format-time-string "%Y-%m-%dT%H:%M:%S%z") + :environment (etaf-performance-environment-data) + :summary (etaf-performance-summary records) + :operations + (mapcar #'etaf-performance--operation-report-data + (reverse (copy-sequence records)))))) ;;;###autoload (defun etaf-performance-report-string (&optional records) @@ -365,8 +437,8 @@ can be copied, saved, and read in another Emacs process." (defun etaf-performance-export (file) "Export all retained performance records to FILE. -When called interactively, suggest a timestamped `.eld' file in -`default-directory'. Refuse to overwrite an existing file." +When called interactively, suggest a timestamped `.eld' file. Refuse to +overwrite an existing file." (interactive (list (read-file-name @@ -375,478 +447,50 @@ When called interactively, suggest a timestamped `.eld' file in (format "etaf-performance-%s.eld" (format-time-string "%Y%m%d-%H%M%S")) default-directory)))) - (let* ((record-count (length (etaf-performance-records))) - (report (etaf-performance-report-string))) + (let ((report (etaf-performance-report-string))) (write-region report nil file nil 'silent nil 'excl) (message "Exported %d ETAF performance operations to %s" - record-count (abbreviate-file-name file)) + (length (etaf-performance-records)) + (abbreviate-file-name file)) file)) -(defun etaf-performance-clear () - "Clear all completed performance records." - (interactive) - ;; Keep correlation IDs monotonic even if an active operation clears history. - (setq etaf-performance--record-ring nil) - (when-let* ((panel (get-buffer "*ETAF Performance*"))) - (with-current-buffer panel - (when (derived-mode-p 'etaf-performance-panel-mode) - (tabulated-list-revert)))) - nil) - -(defun etaf-performance--now () - "Return a wall-clock timestamp as floating-point seconds." - (float-time)) - -(defun etaf-performance--runtime-p (value) - "Return non-nil when VALUE is an ETAF Runtime." - (and (fboundp 'etaf-runtime-p) (etaf-runtime-p value))) - -(defun etaf-performance--runtime-for-buffer (buffer) - "Return the Runtime mounted in BUFFER, without signaling." - (and buffer (fboundp 'etaf-runtime-for-buffer) - (ignore-errors (etaf-runtime-for-buffer buffer)))) - -(defun etaf-performance--runtime-from-call (function arguments result after) - "Resolve Runtime for FUNCTION call using ARGUMENTS, RESULT, and AFTER." - (let ((first (car arguments))) - (cond - ((eq function 'etaf-runtime-mount) - (when after (etaf-performance--runtime-for-buffer result))) - ((etaf-performance--runtime-p first) first) - ((memq function '(etaf-runtime-flush etaf-runtime-unmount - etaf-focus etaf-focus-next etaf-focus-previous - etaf-activate)) - (or (and first (etaf-performance--runtime-for-buffer first)) - (and (boundp 'etaf--current-runtime) etaf--current-runtime) - (etaf-performance--runtime-for-buffer (current-buffer)))) - ((eq function 'etaf-activate-mouse) - (and (boundp 'etaf--current-runtime) etaf--current-runtime)) - ((eq function 'etaf-dispatch) - (if (etaf-performance--runtime-p first) - first - (and (boundp 'etaf--current-runtime) etaf--current-runtime))) - ((memq function '(ebox-surface-update-buffer-viewport - ebox-rerender-buffer-with-context)) - (etaf-performance--runtime-for-buffer first)) - (t - (and (boundp 'etaf--current-runtime) etaf--current-runtime))))) - -(defun etaf-performance--buffer (runtime function arguments result after) - "Resolve operation buffer from RUNTIME and call metadata. -FUNCTION received ARGUMENTS and produced RESULT when AFTER is non-nil." - (cond - ((and runtime (fboundp 'etaf-runtime-buffer)) - (ignore-errors (etaf-runtime-buffer runtime))) - ((eq function 'etaf-runtime-mount) - (let ((value (if after result (car arguments)))) - (cond ((bufferp value) value) - ((stringp value) (get-buffer value))))) - ((memq function '(ebox-surface-update-buffer-viewport - ebox-rerender-buffer-with-context)) - (get-buffer (car arguments))) - (t nil))) - -(defun etaf-performance--generation (runtime) - "Return RUNTIME's committed generation, or nil." - (and runtime (fboundp 'etaf-runtime-generation) - (ignore-errors (etaf-runtime-generation runtime)))) - -(defun etaf-performance--runtime-id (runtime) - "Return RUNTIME's stable scalar mount identity, or nil." - (and runtime (fboundp 'etaf-runtime-mount-epoch) - (ignore-errors (etaf-runtime-mount-epoch runtime)))) - -(defun etaf-performance--buffer-name (buffer) - "Return BUFFER's name snapshot, or nil." - (cond ((bufferp buffer) (buffer-name buffer)) - ((stringp buffer) buffer) - (t nil))) - -(defun etaf-performance--label (function arguments) - "Return a concise label for FUNCTION called with ARGUMENTS." - (pcase function - ('etaf-dispatch-event - (format "%s %S" (nth 2 arguments) (nth 1 arguments))) - ('etaf-dispatch - (format "%S" (if (etaf-performance--runtime-p (car arguments)) - (nth 1 arguments) - (car arguments)))) - ('etaf-runtime-mount (format "%s" (car arguments))) - ('etaf-runtime-flush "manual flush") - ('etaf-runtime-unmount "unmount") - ('etaf-data-load "data load") - ('etaf-data-source-load-page - (format "data prepare page %s/%s" - (or (nth 2 arguments) 1) (or (nth 3 arguments) 20))) - ('etaf-data-mutate (format "data %S" (nth 1 arguments))) - ('etaf-resource-load "resource load/reload") - ('ebox-surface-update-buffer-viewport - (format "viewport %sx%s" (nth 1 arguments) (or (nth 2 arguments) "-"))) - ('ebox-rerender-buffer-with-context - (format "rerender %sx%s" (nth 1 arguments) (or (nth 2 arguments) "-"))) - ('etaf-focus (format "focus %S" (nth 1 arguments))) - ('etaf-focus-next "next") - ('etaf-focus-previous "previous") - ('etaf-activate-mouse "mouse") - ('etaf-activate "keyboard") - (_ (symbol-name function)))) - -(defun etaf-performance--retain (operation) - "Retain completed OPERATION under the configured bound." - (let ((limit (max 0 etaf-performance-max-records))) - (if (zerop limit) - (setq etaf-performance--record-ring nil) - (unless (and etaf-performance--record-ring - (= (ring-size etaf-performance--record-ring) limit)) - (let ((existing (etaf-performance-records))) - (setq etaf-performance--record-ring (make-ring limit)) - (dolist (record (reverse (seq-take existing limit))) - (ring-insert etaf-performance--record-ring record)))) - (ring-insert etaf-performance--record-ring operation)))) - -(defun etaf-performance--call-operation - (original function kind arguments &optional label runtime buffer) - "Call ORIGINAL as operation FUNCTION of KIND with ARGUMENTS. -Optional LABEL, RUNTIME, and BUFFER override inferred metadata." - (if (not etaf-performance-mode) - (apply original arguments) - (let* ((runtime-before - (or runtime - (etaf-performance--runtime-from-call - function arguments nil nil))) - (buffer-before - (or buffer - (etaf-performance--buffer - runtime-before function arguments nil nil))) - (start (etaf-performance--now)) - (gc-count-before gcs-done) - (gc-elapsed-before gc-elapsed) - (operation - (etaf-performance--operation-create - :id (cl-incf etaf-performance--next-operation-id) - :parent-id (and etaf-performance--current-operation - (etaf-performance-operation-id - etaf-performance--current-operation)) - :kind kind :label (or label - (etaf-performance--label - function arguments)) - :runtime-id (etaf-performance--runtime-id runtime-before) - :buffer-name (etaf-performance--buffer-name buffer-before) - :generation-before - (etaf-performance--generation runtime-before) - :start-time start :gc-count-before gc-count-before - :gc-elapsed-before gc-elapsed-before)) - (etaf-performance--current-operation operation) - (etaf-performance--stage-stack nil) - (completed nil) - (quit-p nil) - result) - (unwind-protect - (condition-case condition - (prog1 (setq result (apply original arguments)) - (setq completed t)) - (quit - (setq quit-p t) - (signal (car condition) (cdr condition)))) - (let* ((end (etaf-performance--now)) - (runtime-after - (or (etaf-performance--runtime-from-call - function arguments result t) - runtime-before)) - (buffer-after - (or (etaf-performance--buffer - runtime-after function arguments result t) - buffer-before))) - (setf (etaf-performance-operation-runtime-id operation) - (etaf-performance--runtime-id runtime-after) - (etaf-performance-operation-buffer-name operation) - (etaf-performance--buffer-name buffer-after) - (etaf-performance-operation-generation-after operation) - (etaf-performance--generation runtime-after) - (etaf-performance-operation-end-time operation) end - (etaf-performance-operation-elapsed operation) - (* 1000.0 (- end start)) - (etaf-performance-operation-status operation) - (cond (completed 'success) (quit-p 'quit) (t 'error)) - (etaf-performance-operation-gc-count-after operation) gcs-done - (etaf-performance-operation-gc-elapsed-after operation) - gc-elapsed - (etaf-performance-operation-stages operation) - (sort (etaf-performance-operation-stages operation) - (lambda (left right) - (< (etaf-performance-stage-id left) - (etaf-performance-stage-id right))))) - (etaf-performance--retain operation))) - result))) - -;;;###autoload -(defun etaf-performance-call-operation - (kind label function &optional runtime buffer) - "Call FUNCTION as a recorded operation and return its exact result. -KIND and LABEL identify the operation. Optional RUNTIME and BUFFER attach -framework metadata without constraining FUNCTION's implementation. FUNCTION -should close over any arguments it needs. Errors and quits are re-signaled." - (unless (functionp function) - (signal 'wrong-type-argument (list 'functionp function))) - (etaf-performance--call-operation - function 'etaf-performance-call-operation kind nil label runtime buffer)) - -(cl-defmacro etaf-performance-with-operation - ((kind label &optional runtime buffer) &rest body) - "Evaluate BODY as a recorded operation and return its exact result. -KIND, LABEL, optional RUNTIME, and optional BUFFER are evaluated once." - (declare (indent 1) (debug ((form form &optional form form) body))) - `(etaf-performance-call-operation - ,kind ,label (lambda () ,@body) ,runtime ,buffer)) - -(defun etaf-performance--make-operation-advice (function kind) - "Return an around advice closure for operation FUNCTION and KIND." - (lambda (original &rest arguments) - (etaf-performance--call-operation original function kind arguments))) - -(defun etaf-performance--call-stage - (original function category detail arguments) - "Call ORIGINAL as stage FUNCTION in CATEGORY with DETAIL and ARGUMENTS." - (if (not etaf-performance--current-operation) - (apply original arguments) - (let* ((start (etaf-performance--now)) - (frame - (etaf-performance--stage-frame-create - :id (cl-incf etaf-performance--next-stage-id) - :category category :function function :detail detail - :depth (length etaf-performance--stage-stack) - :start-time start)) - (parent (car etaf-performance--stage-stack)) - (etaf-performance--stage-stack - (cons frame etaf-performance--stage-stack)) - (completed nil) - (quit-p nil) - result) - (unwind-protect - (condition-case condition - (prog1 (setq result (apply original arguments)) - (setq completed t)) - (quit - (setq quit-p t) - (signal (car condition) (cdr condition)))) - (let* ((end (etaf-performance--now)) - (inclusive (* 1000.0 (- end start))) - (exclusive - (max 0.0 (- inclusive - (etaf-performance--stage-frame-child-time frame))))) - (when parent - (cl-incf (etaf-performance--stage-frame-child-time parent) - inclusive)) - (when completed - (etaf-performance--capture-stage-result - etaf-performance--current-operation function result)) - (push - (etaf-performance--stage-create - :id (etaf-performance--stage-frame-id frame) - :category category :function function :detail detail - :depth (etaf-performance--stage-frame-depth frame) - :start-time start :end-time end :inclusive inclusive - :exclusive exclusive - :status (cond (completed 'success) (quit-p 'quit) (t 'error))) - (etaf-performance-operation-stages - etaf-performance--current-operation)))) - result))) - -(defun etaf-performance--compact-ebox-report (report) - "Return stable scalar diagnostics from public Ebox REPORT." - (when (listp report) - (list :strategy (plist-get report :strategy) - :projection-kind (plist-get report :projection-kind) - :dirty-count (plist-get report :dirty-count) - :owner-count (length (plist-get report :owner-ids)) - :patch-count (plist-get report :patch-count) - :tp-scope-count (plist-get report :tp-scope-count) - :tp-text-operations (plist-get report :tp-text-operations) - :tp-property-operations (plist-get report :tp-property-operations) - :tp-full-root (and (plist-get report :tp-full-root) t) - :tp-scope-fallback (and (plist-get report :tp-scope-fallback) t) - :native-frame-kind (plist-get report :native-frame-kind) - :timing (copy-tree (plist-get report :timing))))) - -(defun etaf-performance--capture-stage-result (operation function result) - "Attach public FUNCTION RESULT diagnostics to OPERATION." - (when (eq function 'ebox-commit) - (setf (etaf-performance-operation-metadata operation) - (plist-put (etaf-performance-operation-metadata operation) - :ebox - (etaf-performance--compact-ebox-report result))))) - -(defun etaf-performance--make-stage-advice (function category detail) - "Return an around advice closure for stage FUNCTION CATEGORY and DETAIL." - (lambda (original &rest arguments) - (etaf-performance--call-stage - original function category detail arguments))) - -(defun etaf-performance--install-one (function advice) - "Install ADVICE around FUNCTION once and remember it." - (let ((installed - (cl-find function etaf-performance--installed-advices :key #'car))) - (cond - ((and installed (advice-member-p (cdr installed) function)) nil) - (installed - ;; Reloading a package replaces its advised symbol-function. Reattach - ;; the exact tracked closure so disable/unregister can still remove it. - (advice-add function :around (cdr installed))) - (t - (advice-add function :around advice) - (push (cons function advice) etaf-performance--installed-advices))))) - -(defun etaf-performance--uninstall-function (function) - "Remove recorder advice installed on FUNCTION." - (when-let* ((entry (assq function etaf-performance--installed-advices))) - (advice-remove function (cdr entry)) - (setq etaf-performance--installed-advices - (delq entry etaf-performance--installed-advices)))) - -;;;###autoload -(defun etaf-performance-register-stage (function category &optional detail) - "Register FUNCTION as a timed stage in CATEGORY. -DETAIL defaults to FUNCTION. Registration is safe before or after the -package defining FUNCTION is loaded. Return FUNCTION." - (unless (symbolp function) - (signal 'wrong-type-argument (list 'symbolp function))) - (unless (symbolp category) - (signal 'wrong-type-argument (list 'symbolp category))) - (when (assq function etaf-performance--operation-functions) - (error "ETAF performance operation boundary cannot be a stage: %S" - function)) - (let ((detail (or detail function))) - (unless (symbolp detail) - (signal 'wrong-type-argument (list 'symbolp detail))) - (setq etaf-performance--stage-functions - (cons (list function category detail) - (assq-delete-all function - etaf-performance--stage-functions))) - (etaf-performance--uninstall-function function) - (when (and etaf-performance-mode (fboundp function)) - (etaf-performance--install-one - function - (etaf-performance--make-stage-advice function category detail)))) - function) - -;;;###autoload -(defun etaf-performance-unregister-stage (function) - "Unregister timed stage FUNCTION and remove its installed advice." - (when (assq function etaf-performance--operation-functions) - (error "ETAF performance operation boundary is not a registered stage: %S" - function)) - (setq etaf-performance--stage-functions - (assq-delete-all function etaf-performance--stage-functions)) - (etaf-performance--uninstall-function function) - function) - -(defun etaf-performance--install-loaded-advices (&optional _file) - "Install configured advices whose functions are currently loaded." - (when etaf-performance-mode - (dolist (entry etaf-performance--operation-functions) - (when (fboundp (car entry)) - (etaf-performance--install-one - (car entry) - (etaf-performance--make-operation-advice - (car entry) (nth 1 entry))))) - (dolist (entry etaf-performance--stage-functions) - (when (fboundp (car entry)) - (etaf-performance--install-one - (car entry) - (etaf-performance--make-stage-advice - (car entry) (nth 1 entry) (nth 2 entry))))))) - -(defun etaf-performance--uninstall-advices () - "Remove every operation and stage advice installed by this recorder." - (dolist (entry etaf-performance--installed-advices) - (advice-remove (car entry) (cdr entry))) - (setq etaf-performance--installed-advices nil)) - -;;;###autoload -(define-minor-mode etaf-performance-mode - "Globally record ETAF operations and cross-package performance stages." - :global t - :init-value nil - :lighter " ETAF-Perf" - (if etaf-performance-mode - (progn - (add-hook 'after-load-functions - #'etaf-performance--install-loaded-advices) - (etaf-performance--install-loaded-advices)) - (remove-hook 'after-load-functions - #'etaf-performance--install-loaded-advices) - (etaf-performance--uninstall-advices))) - (defun etaf-performance--format-object (value) "Format VALUE compactly for the performance table." - (cond ((bufferp value) (buffer-name value)) - ((null value) "-") - (t (format "%s" value)))) - -(defun etaf-performance--format-report (operation) - "Return compact public backend metadata for OPERATION." - (if-let* ((report (plist-get (etaf-performance-operation-metadata operation) - :ebox))) - (format "%s/%s d:%s o:%s tp:%s/%s/%s%s" - (or (plist-get report :strategy) "-") - (or (plist-get report :projection-kind) "-") - (or (plist-get report :dirty-count) 0) - (or (plist-get report :owner-count) 0) - (or (plist-get report :tp-scope-count) 0) - (or (plist-get report :tp-text-operations) 0) - (or (plist-get report :tp-property-operations) 0) - (if (or (plist-get report :tp-full-root) - (plist-get report :tp-scope-fallback)) - " fallback" - "")) - "-")) + (if (null value) "-" (format "%s" value))) (defun etaf-performance--tabulated-entries () - "Return tabulated entries for retained operations and their stages." + "Return tabulated entries for retained operations and flat stages." (let (entries) (dolist (operation (reverse (etaf-performance-records))) (let ((id (etaf-performance-operation-id operation))) (push (list (cons 'operation id) - (vector - (number-to-string id) - (etaf-performance--format-object - (etaf-performance-operation-parent-id operation)) - (symbol-name (etaf-performance-operation-kind operation)) - (or (etaf-performance-operation-label operation) "") - "operation" "-" "0" - (format "%.3f" (etaf-performance-operation-elapsed operation)) - "-" (symbol-name (etaf-performance-operation-status operation)) - (etaf-performance--format-object - (etaf-performance-operation-buffer-name operation)) - (format "%s→%s" - (etaf-performance--format-object - (etaf-performance-operation-generation-before operation)) - (etaf-performance--format-object - (etaf-performance-operation-generation-after operation))) - (etaf-performance--format-report operation) - (format "%d/%.3fms" - (- (etaf-performance-operation-gc-count-after operation) - (etaf-performance-operation-gc-count-before operation)) - (* 1000.0 - (- (etaf-performance-operation-gc-elapsed-after operation) - (etaf-performance-operation-gc-elapsed-before operation)))))) + (vector (number-to-string id) + (symbol-name (etaf-performance-operation-kind operation)) + (or (etaf-performance-operation-label operation) "") + "operation" "-" "-" + (format "%.3f" + (etaf-performance-operation-elapsed operation)) + (symbol-name + (etaf-performance-operation-status operation)) + (etaf-performance--format-object + (etaf-performance-operation-buffer-name operation)))) entries) (dolist (stage (etaf-performance-operation-stages operation)) (push - (list (cons id (etaf-performance-stage-id stage)) + (list (cons id (etaf-performance-stage-sequence stage)) (vector - (format "%s.%s" id (etaf-performance-stage-id stage)) - (number-to-string id) "stage" - (concat (make-string (* 2 (etaf-performance-stage-depth stage)) ?\s) - (symbol-name (etaf-performance-stage-detail stage))) + (format "%s.%s" id + (etaf-performance-stage-sequence stage)) + "stage" + (symbol-name (etaf-performance-stage-name stage)) (symbol-name (etaf-performance-stage-category stage)) - (symbol-name (etaf-performance-stage-function stage)) - (number-to-string (etaf-performance-stage-depth stage)) - (format "%.3f" (etaf-performance-stage-inclusive stage)) - (format "%.3f" (etaf-performance-stage-exclusive stage)) + (symbol-name (etaf-performance-stage-provider stage)) + (number-to-string + (etaf-performance-stage-sequence stage)) + (format "%.3f" (etaf-performance-stage-duration stage)) (symbol-name (etaf-performance-stage-status stage)) - "-" "-" "-" "-")) + "-")) entries)))) (nreverse entries))) @@ -862,16 +506,13 @@ package defining FUNCTION is loaded. Return FUNCTION." (or (plist-get power :low-power-mode) 'unknown) (or load 0.0)))) -(define-derived-mode etaf-performance-panel-mode tabulated-list-mode "ETAF-Performance" - "Display ETAF operation and nested stage timing records. - -Press `c' to copy a complete report or `w' to export it to a file." +(define-derived-mode etaf-performance-panel-mode + tabulated-list-mode "ETAF-Performance" + "Display ETAF operations and their flat provider reports." (setq tabulated-list-format - [("ID" 9 t) ("Parent" 7 t) ("Type" 10 t) ("Label / Detail" 24 t) - ("Category" 12 t) ("Function" 34 t) ("Depth" 6 t) - ("Inclusive ms" 13 t) ("Exclusive ms" 13 t) ("Status" 8 t) - ("Buffer" 18 t) ("Generation" 12 t) ("Backend report" 40 t) - ("GC delta" 14 t)]) + [("ID" 9 t) ("Type" 10 t) ("Operation / Stage" 26 t) + ("Category" 12 t) ("Provider" 12 t) ("Sequence" 9 t) + ("Duration ms" 13 t) ("Status" 8 t) ("Buffer" 20 t)]) (setq tabulated-list-padding 2 tabulated-list-entries #'etaf-performance--tabulated-entries header-line-format (etaf-performance--panel-environment-line)) diff --git a/tests/etaf-performance-tests.el b/tests/etaf-performance-tests.el index a50663a..f8ef20c 100644 --- a/tests/etaf-performance-tests.el +++ b/tests/etaf-performance-tests.el @@ -6,445 +6,299 @@ (require 'ert) (require 'etaf) +(defconst etaf-performance-test--facade-loaded-recorder-p + (featurep 'etaf-performance) + "Whether loading the ETAF facade eagerly loaded the optional recorder.") +(require 'etaf-performance) + +(ert-deftest etaf-performance-is-not-an-etaf-facade-dependency () + "The optional recorder must be loaded explicitly." + (should-not etaf-performance-test--facade-loaded-recorder-p)) (defmacro etaf-performance-test--isolated (&rest body) - "Run BODY with isolated performance recorder state." + "Run BODY with isolated recorder state." (declare (indent 0) (debug t)) - `(unwind-protect - (progn - (etaf-performance-mode -1) - (etaf-performance-clear) - ,@body) - (etaf-performance-mode -1) - (etaf-performance-clear))) + `(let ((etaf-performance--record-ring nil) + (etaf-performance--pending (make-hash-table :test #'equal)) + (etaf-performance--attachments (make-hash-table :test #'eq))) + ,@body)) -(ert-deftest etaf-performance-records-success-result-and-error () - "Recording preserves successful results and original error data." - (etaf-performance-test--isolated - (etaf-performance-mode 1) - (should (equal 42 - (etaf-performance--call-operation - (lambda () 42) 'test-success 'test nil))) - (let ((condition - (condition-case error-data - (etaf-performance--call-operation - (lambda () - (etaf-performance--call-stage - (lambda () - (signal 'args-out-of-range '(source 1 2))) - 'failing-stage 'test 'failure nil)) - 'test-error 'test nil) - (args-out-of-range error-data)))) - (should (equal condition '(args-out-of-range source 1 2)))) - (let ((records (etaf-performance-records))) - (should (= 2 (length records))) - (should (eq 'error - (etaf-performance-operation-status (car records)))) - (should (eq 'error - (etaf-performance-stage-status - (car (etaf-performance-operation-stages - (car records)))))) - (should (eq 'success - (etaf-performance-operation-status (cadr records))))))) +(cl-defmacro etaf-performance-test--with-runtime + ((runtime buffer-name) &rest body) + "Mount RUNTIME in BUFFER-NAME, evaluate BODY, then clean up." + (declare (indent 1) (debug ((symbolp symbolp) body))) + `(let ((,buffer-name (generate-new-buffer-name " *etaf-performance-test*")) + ,runtime) + (unwind-protect + (progn + (etaf-mount ,buffer-name (etaf-view (box "Performance"))) + (setq ,runtime (etaf-runtime-for-buffer ,buffer-name)) + ,@body) + (when ,runtime + (etaf-performance-stop ,runtime) + (when (etaf-runtime-mounted-p ,runtime) + (etaf-unmount ,runtime))) + (when-let* ((buffer (get-buffer ,buffer-name))) + (kill-buffer buffer))))) -(ert-deftest etaf-performance-records-preserve-quit () - "Recording marks and re-signals a quit without changing its data." +(ert-deftest etaf-performance-start-stop-own-exact-runtime-sink () + "Attach idempotently and remove only this recorder's exact sink." (etaf-performance-test--isolated - (etaf-performance-mode 1) - (let ((condition - (condition-case quit-data - (etaf-performance--call-operation - (lambda () (signal 'quit '(performance-test))) - 'test-quit 'test nil) - (quit quit-data)))) - (should (equal condition '(quit performance-test))) - (should (eq 'quit - (etaf-performance-operation-status - (car (etaf-performance-records)))))))) + (etaf-performance-test--with-runtime (runtime buffer-name) + (should (eq runtime (etaf-performance-start runtime))) + (let* ((attachment + (gethash runtime etaf-performance--attachments)) + (sink (etaf-performance--attachment-sink attachment))) + (should (functionp sink)) + (should (etaf-runtime-compare-and-set-observer runtime sink sink)) + (should (eq runtime (etaf-performance-start runtime))) + (should (eq runtime (etaf-performance-stop runtime))) + (should (etaf-runtime-compare-and-set-observer runtime nil nil)))))) -(ert-deftest etaf-performance-public-operation-wrapper-is-generic () - "The public operation API records arbitrary code and preserves its result." +(ert-deftest etaf-performance-start-rejects-foreign-observer () + "Never replace an observer owned by another consumer." (etaf-performance-test--isolated - (etaf-performance-mode 1) - (should - (equal '(generic result) - (etaf-performance-with-operation ('command "generic fixture") - '(generic result)))) - (let ((operation (car (etaf-performance-records)))) - (should (eq 'command - (etaf-performance-operation-kind operation))) - (should (equal "generic fixture" - (etaf-performance-operation-label operation)))))) + (etaf-performance-test--with-runtime (runtime buffer-name) + (let ((foreign #'ignore)) + (etaf-runtime-set-observer runtime foreign) + (should-error (etaf-performance-start runtime)) + (should (etaf-runtime-compare-and-set-observer + runtime foreign foreign)) + (etaf-runtime-set-observer runtime nil))))) -(ert-deftest etaf-performance-stage-registration-is-load-order-safe () - "Third-party stages may register before their function is defined." +(ert-deftest etaf-performance-stop-preserves-replacement-observer () + "A later foreign replacement is not detached by recorder stop." (etaf-performance-test--isolated - (let ((function (make-symbol "etaf-performance-generic-stage"))) + (etaf-performance-test--with-runtime (runtime buffer-name) + (etaf-performance-start runtime) + (let ((foreign #'ignore)) + (etaf-runtime-set-observer runtime foreign) + (etaf-performance-stop runtime) + (should (etaf-runtime-compare-and-set-observer + runtime foreign foreign)) + (etaf-runtime-set-observer runtime nil))))) + +(ert-deftest etaf-performance-mode-is-current-buffer-convenience () + "The local mode attaches only the Runtime in its current buffer." + (etaf-performance-test--isolated + (etaf-performance-test--with-runtime (runtime buffer-name) + (with-current-buffer buffer-name + (etaf-performance-mode 1) + (should etaf-performance-mode) + (should (eq runtime etaf-performance--mode-runtime)) + (let* ((attachment + (gethash runtime etaf-performance--attachments)) + (sink (etaf-performance--attachment-sink attachment))) + (should (functionp sink)) + (should (etaf-runtime-compare-and-set-observer + runtime sink sink))) + (etaf-performance-mode -1) + (should-not etaf-performance-mode) + (should (etaf-runtime-compare-and-set-observer runtime nil nil)))))) + +(ert-deftest etaf-performance-mode-rejects-non-runtime-buffer () + "The buffer-local convenience requires a mounted Runtime." + (with-temp-buffer + (should-error (etaf-performance-mode 1)) + (should-not etaf-performance-mode))) + +(ert-deftest etaf-performance-unmount-records-and-releases-attachment () + "Record unmount before the Runtime detaches this recorder." + (etaf-performance-test--isolated + (let ((buffer-name (generate-new-buffer-name " *etaf-performance-unmount*")) + runtime) (unwind-protect (progn - (etaf-performance-register-stage function 'extension 'prepare) - (etaf-performance-mode 1) - (should-not (assq function etaf-performance--installed-advices)) - (fset function (lambda () 'extension-result)) - (etaf-performance--install-loaded-advices) - (should (assq function etaf-performance--installed-advices)) - (should (eq 'extension-result - (etaf-performance-call-operation - 'extension "registered stage" - (lambda () (funcall function))))) - (let ((stage - (car (etaf-performance-operation-stages - (car (etaf-performance-records)))))) - (should (eq function - (etaf-performance-stage-function stage))) - (should (eq 'extension - (etaf-performance-stage-category stage))))) - (etaf-performance-unregister-stage function) - (when (fboundp function) - (fmakunbound function)))))) - -(ert-deftest etaf-performance-default-registry-keeps-per-node-probes-opt-in () - "High-frequency per-node probes must not distort default operation timing." - (dolist (function '(ebox-incremental--candidate-local-changed-keys - ebox-tree-node-local-source-signature)) - (should-not (assq function etaf-performance--stage-functions)))) - -(ert-deftest etaf-performance-stage-advice-survives-package-reload () - "Reattach the tracked stage closure after its function is redefined." - (etaf-performance-test--isolated - (let ((function (make-symbol "etaf-performance-reloaded-stage"))) - (unwind-protect - (progn - (fset function (lambda () 'first)) - (etaf-performance-register-stage function 'extension 'reload) - (etaf-performance-mode 1) - (let ((entry (assq function - etaf-performance--installed-advices))) - (should (advice-member-p (cdr entry) function)) - (fset function (lambda () 'second)) - (should-not (advice-member-p (cdr entry) function)) - (etaf-performance--install-loaded-advices) - (should (advice-member-p (cdr entry) function))) - (etaf-performance-clear) - (should (eq 'second - (etaf-performance-call-operation - 'reload "package reload" - (lambda () (funcall function))))) - (should (= 1 - (length - (etaf-performance-operation-stages - (car (etaf-performance-records))))))) - (etaf-performance-unregister-stage function) - (when (fboundp function) (fmakunbound function)))))) - -(ert-deftest etaf-performance-stage-registration-rejects-operation-collision () - "A detail stage must not replace a public operation boundary advice." - (etaf-performance-test--isolated - (etaf-performance-mode 1) - (let* ((function 'etaf-data-load) - (entry (assq function etaf-performance--installed-advices))) - (should entry) - (should-error - (etaf-performance-register-stage function 'data 'nested-load)) - (should-error (etaf-performance-unregister-stage function)) - (should (eq entry (assq function etaf-performance--installed-advices))) - (should (advice-member-p (cdr entry) function))))) - -(ert-deftest etaf-performance-public-data-resource-and-viewport-boundaries () - "Public cross-package operations are boundaries, never duplicate stages." - (etaf-performance-test--isolated - (let ((functions '(etaf-data-load etaf-data-source-load-page - etaf-data-mutate etaf-resource-load - ebox-surface-update-buffer-viewport - ebox-rerender-buffer-with-context))) - (dolist (function functions) - (should (assq function etaf-performance--operation-functions)) - (should-not (assq function etaf-performance--stage-functions))) - (etaf-performance-mode 1) - (dolist (function functions) - (when (fboundp function) - (should (assq function etaf-performance--installed-advices)))) - (let* ((source (etaf-data-memory-source - '((:id 1 :name "one")) :id-key :id)) - (controller (etaf-data-controller source)) - (resource (etaf-resource (lambda () 'loaded) :immediate nil))) - (unwind-protect - (progn - (etaf-data-load controller) - (etaf-data-source-load-page source nil 1 20) - (etaf-data-mutate controller 'insert '(:id 2 :name "two")) - (etaf-resource-load resource) - (let ((kinds - (mapcar #'etaf-performance-operation-kind - (etaf-performance-records)))) - (should (memq 'data-load kinds)) - (should (memq 'data-prepare kinds)) - (should (memq 'data-mutate kinds)) - (should (memq 'resource-load kinds)))) - (etaf-data-stop controller) - (etaf-resource-dispose resource)))))) - -(ert-deftest etaf-performance-records-nested-stage-exclusive-time () - "Nested stages retain depth and subtract child inclusive time." - (etaf-performance-test--isolated - (etaf-performance-mode 1) - (etaf-performance--call-operation - (lambda () - (etaf-performance--call-stage - (lambda () - (sleep-for 0.002) - (etaf-performance--call-stage - (lambda () (sleep-for 0.002) 'inner-result) - 'inner-stage 'inner 'work nil) - (sleep-for 0.002)) - 'outer-stage 'outer 'work nil)) - 'nested-operation 'test nil) - (let* ((operation (car (etaf-performance-records))) - (stages (etaf-performance-operation-stages operation)) - (outer (car stages)) - (inner (cadr stages))) - (should (= 2 (length stages))) - (should (= 0 (etaf-performance-stage-depth outer))) - (should (= 1 (etaf-performance-stage-depth inner))) - (should (>= (etaf-performance-stage-inclusive outer) - (etaf-performance-stage-inclusive inner))) - (should (< (abs (- (etaf-performance-stage-exclusive outer) - (- (etaf-performance-stage-inclusive outer) - (etaf-performance-stage-inclusive inner)))) - 0.001))))) - -(ert-deftest etaf-performance-records-are-bounded () - "Only the configured number of newest operations is retained." - (etaf-performance-test--isolated - (let ((etaf-performance-max-records 2)) - (etaf-performance-mode 1) - (dotimes (index 4) - (etaf-performance--call-operation - (lambda () index) 'bounded 'test nil)) - (let* ((records (etaf-performance-records)) - (ids (mapcar #'etaf-performance-operation-id records))) - (should (= 2 (length records))) - (should (= 1 (- (car ids) (cadr ids)))))))) - -(ert-deftest etaf-performance-clear-keeps-correlation-ids-monotonic () - "Clearing history inside an operation must not reuse its ID." - (etaf-performance-test--isolated - (etaf-performance-mode 1) - (etaf-performance-call-operation - 'outer "clear inside" (lambda () (etaf-performance-clear))) - (etaf-performance-call-operation 'next "after clear" #'ignore) - (let ((ids (mapcar #'etaf-performance-operation-id - (etaf-performance-records)))) - (should (= 2 (length (delete-dups (copy-sequence ids))))) - (should (= 1 (- (car ids) (cadr ids))))))) - -(ert-deftest etaf-performance-summaries-aggregate-off-the-hot-path () - "Summarize operation percentiles and non-overlapping category self time." - (etaf-performance-test--isolated - (etaf-performance-mode 1) - (dolist (delay '(0.001 0.002 0.003)) - (etaf-performance-call-operation - 'summary "generic" - (lambda () - (etaf-performance--call-stage - (lambda () (sleep-for delay)) 'summary-stage 'application 'work nil)))) - (let* ((records (etaf-performance-records)) - (summary (car (etaf-performance-summary records))) - (stage-summary - (car (etaf-performance-operation-stage-summary (car records))))) - (should (= 3 (plist-get summary :count))) - (should (<= (plist-get summary :min-ms) - (plist-get summary :p50-ms) - (plist-get summary :p95-ms) - (plist-get summary :max-ms))) - (should (eq 'application (plist-get stage-summary :category))) - (should (= 1 (plist-get stage-summary :count))) - (should (<= (plist-get stage-summary :exclusive-ms) - (plist-get stage-summary :inclusive-ms)))))) - -(ert-deftest etaf-performance-records-real-event-and-runtime-stages () - "A real mounted event creates an event operation and runtime stages." - (etaf-performance-test--isolated - (let ((buffer-name " *etaf-performance-event-test*") - (calls 0) - runtime-holder) - (unwind-protect - (progn - (etaf-performance-mode 1) - (etaf-mount - buffer-name - (etaf-view - (text :ref 'button - :on-press (lambda () - (cl-incf calls) - (etaf-runtime-flush runtime-holder)) - "Press"))) - (etaf-performance-clear) - (let ((runtime (etaf-runtime-for-buffer buffer-name))) - (setq runtime-holder runtime) - (etaf-dispatch-event runtime 'button 'press) - (should (= calls 1)) - (let ((operation - (cl-find 'event (etaf-performance-records) - :key #'etaf-performance-operation-kind))) - (should (eq 'event - (etaf-performance-operation-kind operation))) - (should (= (etaf-runtime-mount-epoch runtime) - (etaf-performance-operation-runtime-id operation))) - (should (equal buffer-name - (etaf-performance-operation-buffer-name - operation))) - (should (numberp - (etaf-performance-operation-generation-before - operation))) - (should - (cl-some - (lambda (record) - (cl-some - (lambda (stage) - (memq (etaf-performance-stage-category stage) - '(runtime reactive ebox tp))) - (etaf-performance-operation-stages record))) - (etaf-performance-records)))))) - (when-let* ((runtime (etaf-runtime-for-buffer buffer-name))) - (etaf-unmount runtime)) + (etaf-mount buffer-name (etaf-view (box "Unmount"))) + (setq runtime (etaf-runtime-for-buffer buffer-name)) + (etaf-performance-start runtime) + (etaf-unmount runtime) + (should-not (gethash runtime etaf-performance--attachments)) + (let ((operation (car (etaf-performance-records)))) + (should (eq 'unmount + (etaf-performance-operation-kind operation))) + (should (eq 'success + (etaf-performance-operation-status operation)))) + (should (eq runtime (etaf-performance-stop runtime)))) (when-let* ((buffer (get-buffer buffer-name))) (kill-buffer buffer)))))) -(ert-deftest etaf-performance-panel-has-operation-and-stage-entries () - "The tabulated panel expands one operation into its stage rows." +(ert-deftest etaf-performance-groups-flat-reports-in-sequence-order () + "One ETAF final report retains one ordered, categorized operation." (etaf-performance-test--isolated - (etaf-performance-mode 1) - (etaf-performance--call-operation - (lambda () - (etaf-performance--call-stage - (lambda () 'ok) 'panel-stage 'panel 'detail nil)) - 'panel-operation 'test nil) - (let ((entries (etaf-performance--tabulated-entries))) - (should (= 2 (length entries))) - (should (equal "operation" (aref (cadr (car entries)) 4))) - (should (equal "stage" (aref (cadr (cadr entries)) 2)))) - (with-temp-buffer - (etaf-performance-panel-mode) - (tabulated-list-print t) - (should (string-match-p "panel-operation" (buffer-string))) - (should (string-match-p "panel-stage" (buffer-string)))))) + (etaf-performance-test--with-runtime (runtime buffer-name) + (etaf-performance-start runtime) + (should + (equal + 'result + (etaf-performance-call-operation + runtime 'command "flat fixture" + (lambda () + (etaf-observer-emit + '(:provider data :stage load :duration-ms 2.0 :rows 4)) + (etaf-observer-emit + '(:provider ebox :stage commit :duration-ms 3.0 :patches 2)) + 'result)))) + (let* ((records (etaf-performance-records)) + (operation (car records)) + (stages (etaf-performance-operation-stages operation))) + (should (= 1 (length records))) + (should (eq 'command (etaf-performance-operation-kind operation))) + (should (equal "flat fixture" + (etaf-performance-operation-label operation))) + (should (equal '(1 2 3) + (mapcar #'etaf-performance-stage-sequence stages))) + (should (equal '(data ebox etaf) + (mapcar #'etaf-performance-stage-provider stages))) + (should (equal '(data ebox runtime) + (mapcar #'etaf-performance-stage-category stages))) + (should (eq 'runtime-operation + (etaf-performance-stage-name (car (last stages))))) + (should (= 4 (plist-get + (etaf-performance-stage-metadata (car stages)) + :rows))))))) -(ert-deftest etaf-performance-report-is-portable-and-copyable () - "The shareable report contains environment, operation, and stage data." +(ert-deftest etaf-performance-operation-wrapper-preserves-errors () + "The public wrapper delegates result, timing, and failure to Runtime." (etaf-performance-test--isolated - (etaf-performance-mode 1) - (etaf-performance-call-operation - 'report "copy fixture" - (lambda () - (etaf-performance--call-stage - (lambda () 'ok) 'report-stage 'fixture 'work nil))) - (let* ((data (etaf-performance-report-data)) - (operations (plist-get data :operations)) - (operation (car operations)) - (stage (car (plist-get operation :stages))) - (kill-ring nil) - (kill-ring-yank-pointer nil) - (report (etaf-performance-copy-report))) - (should (= etaf-performance-report-format-version - (plist-get data :format-version))) - (should (equal emacs-version - (plist-get (plist-get data :environment) - :emacs-version))) - (should (equal "copy fixture" (plist-get operation :label))) - (should (eq 'report-stage (plist-get stage :function))) - (should (equal report (current-kill 0 t))) - (should (string-match-p "ETAF performance report" report))))) + (etaf-performance-test--with-runtime (runtime buffer-name) + (etaf-performance-start runtime) + (let ((condition + (condition-case data + (etaf-performance-with-operation + (runtime 'command "failure") + (signal 'args-out-of-range '(source 1 2))) + (args-out-of-range data)))) + (should (equal condition '(args-out-of-range source 1 2)))) + (let ((operation (car (etaf-performance-records)))) + (should (eq 'error (etaf-performance-operation-status operation))) + (should (eq 'error + (etaf-performance-stage-status + (car (last + (etaf-performance-operation-stages operation)))))))))) + +(ert-deftest etaf-performance-record-ring-is-bounded () + "Retain only the configured number of newest operations." + (etaf-performance-test--isolated + (let ((etaf-performance-max-records 2)) + (etaf-performance-test--with-runtime (runtime buffer-name) + (etaf-performance-start runtime) + (dotimes (index 4) + (etaf-performance-call-operation + runtime 'bounded (format "operation %d" index) #'ignore)) + (let ((records (etaf-performance-records))) + (should (= 2 (length records))) + (should (> (etaf-performance-operation-id (car records)) + (etaf-performance-operation-id (cadr records))))))))) + +(ert-deftest etaf-performance-summary-uses-flat-duration () + "Summaries expose percentiles and overlapping provider durations honestly." + (etaf-performance-test--isolated + (etaf-performance-test--with-runtime (runtime buffer-name) + (etaf-performance-start runtime) + (dotimes (_ 3) + (etaf-performance-call-operation + runtime 'summary "fixture" + (lambda () + (etaf-observer-emit + '(:provider tp :stage publish :duration-ms 2.5))))) + (let* ((operation (car (etaf-performance-records))) + (summary (car (etaf-performance-summary))) + (stage-summary + (etaf-performance-operation-stage-summary operation)) + (tp-summary + (cl-find 'tp stage-summary :key + (lambda (entry) (plist-get entry :category))))) + (should (= 3 (plist-get summary :count))) + (should (<= (plist-get summary :min-ms) + (plist-get summary :p50-ms) + (plist-get summary :p95-ms) + (plist-get summary :max-ms))) + (should (= 1 (plist-get tp-summary :count))) + (should (= 2.5 (plist-get tp-summary :duration-ms))) + (should-not (plist-member tp-summary :exclusive-ms)))))) + +(ert-deftest etaf-performance-report-panel-copy-and-export-remain-usable () + "Portable reports, the panel, copy, and export consume flat records." + (etaf-performance-test--isolated + (etaf-performance-test--with-runtime (runtime buffer-name) + (etaf-performance-start runtime) + (etaf-performance-call-operation + runtime 'report "portable fixture" + (lambda () + (etaf-observer-emit + '(:provider tp :stage publish :duration-ms 1.25)))) + (let* ((data (etaf-performance-report-data)) + (operation (car (plist-get data :operations))) + (stage (car (plist-get operation :stages))) + (kill-ring nil) + (kill-ring-yank-pointer nil) + (copied (etaf-performance-copy-report)) + (file (make-temp-file "etaf-performance-" nil ".eld"))) + (unwind-protect + (progn + (delete-file file) + (should (= 2 (plist-get data :format-version))) + (should (equal "portable fixture" + (plist-get operation :label))) + (should (eq 'tp (plist-get stage :provider))) + (should (equal copied (current-kill 0 t))) + (should (equal file (etaf-performance-export file))) + (with-temp-buffer + (insert-file-contents file) + (should (string-match-p "portable fixture" + (buffer-string))))) + (when (file-exists-p file) + (delete-file file)))) + (let ((entries (etaf-performance--tabulated-entries))) + (should (= 3 (length entries)))) + (with-temp-buffer + (etaf-performance-panel-mode) + (tabulated-list-print t) + (should (string-match-p "portable fixture" (buffer-string))) + (should (string-match-p "publish" (buffer-string))))))) (ert-deftest etaf-performance-environment-normalizes-darwin-power-state () "Reports distinguish AC, battery low-power, and unknown power states." (should - (equal - '(:source battery :low-power-mode on) - (etaf-performance--parse-darwin-power-state - "Now drawing from 'Battery Power'\n" - "Battery Power:\n lowpowermode 1\nAC Power:\n lowpowermode 0\n"))) + (equal '(:source battery :low-power-mode on) + (etaf-performance--parse-darwin-power-state + "Now drawing from 'Battery Power'\n" + "Battery Power:\n lowpowermode 1\nAC Power:\n lowpowermode 0\n"))) (should - (equal - '(:source ac :low-power-mode off) - (etaf-performance--parse-darwin-power-state - "Now drawing from 'AC Power'\n" - "Battery Power:\n lowpowermode 1\nAC Power:\n lowpowermode 0\n"))) + (equal '(:source ac :low-power-mode off) + (etaf-performance--parse-darwin-power-state + "Now drawing from 'AC Power'\n" + "Battery Power:\n lowpowermode 1\nAC Power:\n lowpowermode 0\n"))) (should - (equal - '(:source unknown :low-power-mode unknown) - (etaf-performance--parse-darwin-power-state "" "")))) + (equal '(:source unknown :low-power-mode unknown) + (etaf-performance--parse-darwin-power-state "" "")))) -(ert-deftest etaf-performance-panel-exposes-power-and-load-context () - "The visible panel explains system-wide latency shifts." - (let ((line - (etaf-performance--panel-environment-line - '(:emacs-version "31.1" - :power-state (:source battery :low-power-mode on) - :load-average (2.5 2.0 1.5))))) - (should (string-match-p "Emacs 31.1" line)) - (should (string-match-p "power battery/low:on" line)) - (should (string-match-p "load 2.50" line)))) +(ert-deftest etaf-performance-environment-reports-native-jit-state () + "Expose background JIT state beside absolute latency records." + (let ((native-comp-jit-compilation t)) + (should (eq t (plist-get (etaf-performance-environment-data) + :native-comp-jit-compilation)))) + (let ((native-comp-jit-compilation nil)) + (should-not (plist-get (etaf-performance-environment-data) + :native-comp-jit-compilation)))) -(ert-deftest etaf-performance-export-writes-readable-report () - "The interactive export payload is a readable plain-data report." - (etaf-performance-test--isolated - (etaf-performance-mode 1) - (etaf-performance-call-operation 'export "file fixture" #'ignore) - (let ((file (concat (make-temp-name - (expand-file-name "etaf-performance-test-" - temporary-file-directory)) - ".eld"))) - (unwind-protect - (progn - (should (equal file (etaf-performance-export file))) - (with-temp-buffer - (insert-file-contents file) - (should (string-match-p "ETAF performance report" - (buffer-string))) - (should (string-match-p "file fixture" (buffer-string))))) - (when (file-exists-p file) - (delete-file file)))))) - -(ert-deftest etaf-performance-captures-public-ebox-report-metadata () - "Attach compact public Ebox report facts to the active operation." - (etaf-performance-test--isolated - (etaf-performance-mode 1) - (etaf-performance--call-operation - (lambda () - (etaf-performance--call-stage - (lambda () - '(:strategy mixed-owner-reflow - :projection-kind mixed-owner-reflow - :dirty-count 8 :owner-ids (1 2 3) :patch-count 3 - :tp-scope-count 3 :tp-text-operations 12 - :tp-property-operations 111 :tp-full-root nil - :tp-scope-fallback nil)) - 'ebox-commit 'ebox 'commit nil)) - 'report-operation 'test nil) - (let* ((operation (car (etaf-performance-records))) - (report (plist-get - (etaf-performance-operation-metadata operation) :ebox))) - (should (eq 'mixed-owner-reflow (plist-get report :strategy))) - (should (= 3 (plist-get report :owner-count))) - (should (= 111 (plist-get report :tp-property-operations))) - (should (string-match-p "mixed-owner-reflow" - (etaf-performance--format-report operation)))))) - -(ert-deftest etaf-performance-mode-uninstalls-all-advices () - "Disabling recording removes operation, stage, and after-load hooks." - (etaf-performance-test--isolated - (etaf-performance-mode 1) - (let ((installed (copy-sequence etaf-performance--installed-advices))) - (should installed) - (dolist (entry installed) - (should (advice-member-p (cdr entry) (car entry)))) - (etaf-performance-mode -1) - (should-not etaf-performance--installed-advices) - (should-not (memq #'etaf-performance--install-loaded-advices - after-load-functions)) - (dolist (entry installed) - (should-not (advice-member-p (cdr entry) (car entry))))))) +(ert-deftest etaf-performance-source-has-no-advice-or-private-provider-registry () + "Recorder source depends only on the public Runtime observation boundary." + (let ((source + (with-temp-buffer + (insert-file-contents + (expand-file-name + "etaf-performance.el" + (file-name-directory (locate-library "etaf-performance")))) + (buffer-string)))) + (dolist (pattern '("advice-add" "advice-remove" "after-load-functions" + "operation-functions" "stage-functions" + "etaf-runtime-mount-epoch" + "etaf-runtime-observer runtime" + "etaf-runtime-mounted-p" + "ebox--" "tp--" "etaf-sqlite--")) + (should-not (string-match-p (regexp-quote pattern) source))))) (provide 'etaf-performance-tests)