Skip to content

Commit 2242856

Browse files
committed
Add snapshot test for profile report, remove Raw Metric Summary
- Add insta snapshot test with real prometheus metrics fixture - Remove the "Raw Metric Summary" collapsible section from report output - Extract `report_from_prometheus_text` helper for testability The floating point precision values (e.g. 0.03451024900000001) from JS are already handled by the formatting functions which round appropriately (displayed as "35ms"). The Raw Metric Summary was the only place raw values leaked through, and it's now removed. https://claude.ai/code/session_01VtVRPfBE8KL58Zk44z5V3X
1 parent 9755fb9 commit 2242856

2 files changed

Lines changed: 250 additions & 40 deletions

File tree

packages/cli/src/executor/profile.rs

Lines changed: 164 additions & 40 deletions
Original file line numberDiff line numberDiff line change
@@ -1365,46 +1365,6 @@ fn generate_report(
13651365

13661366
md.push('\n');
13671367

1368-
// ── Raw metric counts (for AI consumption) ──
1369-
md.push_str("## Raw Metric Summary\n\n");
1370-
md.push_str("<details>\n<summary>Full metric values for AI analysis</summary>\n\n");
1371-
md.push_str("```\n");
1372-
md.push_str(&format!("total_events={}\n", total_events));
1373-
md.push_str(&format!(
1374-
"total_batches={}\n",
1375-
perf.storage_write_count
1376-
.map_or("-".to_string(), |v| v.to_string())
1377-
));
1378-
md.push_str(&format!(
1379-
"preload_ms={}\n",
1380-
perf.preload_ms
1381-
.map_or("-".to_string(), |v| format!("{:.0}", v))
1382-
));
1383-
md.push_str(&format!(
1384-
"processing_ms={}\n",
1385-
perf.processing_ms
1386-
.map_or("-".to_string(), |v| format!("{:.0}", v))
1387-
));
1388-
md.push_str(&format!(
1389-
"storage_write_ms={}\n",
1390-
perf.storage_write_ms
1391-
.map_or("-".to_string(), |v| format!("{:.0}", v))
1392-
));
1393-
md.push_str(&format!(
1394-
"memory_mb={}\n",
1395-
perf.resources
1396-
.memory_bytes
1397-
.map_or("-".to_string(), |v| format!("{:.1}", v / 1024.0 / 1024.0))
1398-
));
1399-
md.push_str(&format!(
1400-
"event_loop_lag_ms={}\n",
1401-
perf.resources
1402-
.event_loop_lag
1403-
.map_or("-".to_string(), |v| format!("{:.2}", v * 1000.0))
1404-
));
1405-
md.push_str("```\n\n");
1406-
md.push_str("</details>\n");
1407-
14081368
md
14091369
}
14101370

@@ -1438,6 +1398,13 @@ async fn fetch_metrics(client: &reqwest::Client, base_url: &str) -> Result<Strin
14381398
// Entry point
14391399
// ---------------------------------------------------------------------------
14401400

1401+
/// Parse metrics and generate a markdown report from raw prometheus text.
1402+
/// Extracted for testability.
1403+
fn report_from_prometheus_text(text: &str) -> String {
1404+
let metrics = parse_prometheus_metrics(text);
1405+
generate_report(&metrics, None, None)
1406+
}
1407+
14411408
pub async fn run_profile(args: ProfileArgs) -> Result<()> {
14421409
let base_url = resolve_base_url(&args);
14431410
let client = reqwest::Client::new();
@@ -1476,3 +1443,160 @@ pub async fn run_profile(args: ProfileArgs) -> Result<()> {
14761443

14771444
Ok(())
14781445
}
1446+
1447+
#[cfg(test)]
1448+
mod tests {
1449+
use super::*;
1450+
1451+
#[test]
1452+
fn snapshot_report_from_prometheus_metrics() {
1453+
let input = r#"
1454+
# HELP envio_preload_seconds Cumulative time spent on preloading entities during batch processing.
1455+
# TYPE envio_preload_seconds counter
1456+
envio_preload_seconds 0.066200668
1457+
# HELP envio_processing_seconds Cumulative time spent executing event handlers during batch processing.
1458+
# TYPE envio_processing_seconds counter
1459+
envio_processing_seconds 0.03451024900000001
1460+
# HELP envio_storage_write_seconds Cumulative time spent writing batch data to storage.
1461+
# TYPE envio_storage_write_seconds counter
1462+
envio_storage_write_seconds 0.14491870900000003
1463+
# HELP envio_storage_write_total Total number of batch writes to storage.
1464+
# TYPE envio_storage_write_total counter
1465+
envio_storage_write_total 4
1466+
# HELP envio_progress_ready Whether the chain is fully synced to the head.
1467+
# TYPE envio_progress_ready gauge
1468+
# HELP hyperindex_synced_to_head All chains fully synced
1469+
# TYPE hyperindex_synced_to_head gauge
1470+
hyperindex_synced_to_head 0
1471+
# HELP envio_processing_handler_seconds Cumulative time spent inside individual event handler executions.
1472+
# TYPE envio_processing_handler_seconds counter
1473+
envio_processing_handler_seconds{contract="ERC20",event="Approval"} 0.007507434000000004
1474+
envio_processing_handler_seconds{contract="ERC20",event="Transfer"} 0.018549728
1475+
# HELP envio_processing_handler_total Total number of individual event handler executions.
1476+
# TYPE envio_processing_handler_total counter
1477+
envio_processing_handler_total{contract="ERC20",event="Approval"} 3434
1478+
envio_processing_handler_total{contract="ERC20",event="Transfer"} 6607
1479+
# HELP envio_preload_handler_seconds Wall-clock time spent inside individual preload handler executions.
1480+
# TYPE envio_preload_handler_seconds counter
1481+
envio_preload_handler_seconds{contract="ERC20",event="Approval"} 0.028596248999999997
1482+
envio_preload_handler_seconds{contract="ERC20",event="Transfer"} 0.06534654299999999
1483+
# HELP envio_preload_handler_total Total number of individual preload handler executions.
1484+
# TYPE envio_preload_handler_total counter
1485+
envio_preload_handler_total{contract="ERC20",event="Approval"} 3434
1486+
envio_preload_handler_total{contract="ERC20",event="Transfer"} 6607
1487+
# HELP envio_preload_handler_seconds_total Cumulative time spent inside individual preload handler executions. Can exceed wall-clock time due to parallel execution.
1488+
# TYPE envio_preload_handler_seconds_total counter
1489+
envio_preload_handler_seconds_total{contract="ERC20",event="Approval"} 27.46140452299992
1490+
envio_preload_handler_seconds_total{contract="ERC20",event="Transfer"} 164.58959649099964
1491+
# HELP envio_fetching_block_range_seconds Cumulative time spent fetching block ranges.
1492+
# TYPE envio_fetching_block_range_seconds counter
1493+
envio_fetching_block_range_seconds{chainId="1"} 19.410937083
1494+
# HELP envio_fetching_block_range_parse_seconds Cumulative time spent parsing block range fetch responses.
1495+
# TYPE envio_fetching_block_range_parse_seconds counter
1496+
envio_fetching_block_range_parse_seconds{chainId="1"} 0.137992167
1497+
# HELP envio_fetching_block_range_total Total number of block range fetch operations.
1498+
# TYPE envio_fetching_block_range_total counter
1499+
envio_fetching_block_range_total{chainId="1"} 2
1500+
# HELP envio_fetching_block_range_events_total Cumulative number of events fetched across all block range operations.
1501+
# TYPE envio_fetching_block_range_events_total counter
1502+
envio_fetching_block_range_events_total{chainId="1"} 10041
1503+
# HELP envio_fetching_block_range_size Cumulative number of blocks covered across all block range fetch operations.
1504+
# TYPE envio_fetching_block_range_size counter
1505+
envio_fetching_block_range_size{chainId="1"} 132690
1506+
# HELP envio_indexing_known_height The latest known block number reported by the active indexing source.
1507+
# TYPE envio_indexing_known_height gauge
1508+
envio_indexing_known_height{chainId="1"} 24592713
1509+
# HELP envio_info Information about the indexer
1510+
# TYPE envio_info gauge
1511+
envio_info{version="0.0.1-dev"} 1
1512+
# HELP envio_indexing_addresses The number of addresses indexed on chain.
1513+
# TYPE envio_indexing_addresses gauge
1514+
envio_indexing_addresses{chainId="1"} 1
1515+
# HELP envio_indexing_max_concurrency The maximum number of concurrent queries to the chain data-source.
1516+
# TYPE envio_indexing_max_concurrency gauge
1517+
envio_indexing_max_concurrency{chainId="1"} 10
1518+
# HELP envio_indexing_concurrency The number of executing concurrent queries to the chain data-source.
1519+
# TYPE envio_indexing_concurrency gauge
1520+
envio_indexing_concurrency{chainId="1"} 6
1521+
# HELP envio_indexing_partitions The number of partitions used to split fetching logic.
1522+
# TYPE envio_indexing_partitions gauge
1523+
envio_indexing_partitions{chainId="1"} 1
1524+
# HELP envio_indexing_idle_seconds The time the indexer source syncing has been idle.
1525+
# TYPE envio_indexing_idle_seconds counter
1526+
envio_indexing_idle_seconds{chainId="1"} 0.115673209
1527+
# HELP envio_indexing_source_waiting_seconds The time the indexer has been waiting for new blocks.
1528+
# TYPE envio_indexing_source_waiting_seconds counter
1529+
envio_indexing_source_waiting_seconds{chainId="1"} 1.7183905419999999
1530+
# HELP envio_indexing_source_querying_seconds The time spent performing queries to the chain data-source.
1531+
# TYPE envio_indexing_source_querying_seconds counter
1532+
envio_indexing_source_querying_seconds{chainId="1"} 19.490299541
1533+
# HELP envio_indexing_buffer_size The current number of items in the indexing buffer.
1534+
# TYPE envio_indexing_buffer_size gauge
1535+
envio_indexing_buffer_size{chainId="1"} 0
1536+
# HELP envio_indexing_target_buffer_size The target buffer size per chain for indexing.
1537+
# TYPE envio_indexing_target_buffer_size gauge
1538+
envio_indexing_target_buffer_size 50000
1539+
# HELP envio_indexing_buffer_block The highest block number that has been fully fetched by the indexer.
1540+
# TYPE envio_indexing_buffer_block gauge
1541+
envio_indexing_buffer_block{chainId="1"} 18732689
1542+
# HELP envio_source_request_total The number of requests made to data sources.
1543+
# TYPE envio_source_request_total counter
1544+
envio_source_request_total{source="HyperSync",chainId="1",method="getHeight"} 1
1545+
envio_source_request_total{source="HyperSync",chainId="1",method="getLogs"} 14
1546+
envio_source_request_total{source="HyperSync",chainId="1",method="getBlockHashes"} 2
1547+
# HELP envio_source_request_seconds_total Cumulative time spent on data source requests.
1548+
# TYPE envio_source_request_seconds_total counter
1549+
envio_source_request_seconds_total{source="HyperSync",chainId="1",method="getHeight"} 1.7180131250000001
1550+
# HELP envio_source_known_height The latest known block number reported by the source.
1551+
# TYPE envio_source_known_height gauge
1552+
envio_source_known_height{source="HyperSync",chainId="1"} 24592713
1553+
# HELP envio_reorg_detected_total Total number of reorgs detected
1554+
# TYPE envio_reorg_detected_total counter
1555+
# HELP envio_reorg_threshold Whether indexing is currently within the reorg threshold
1556+
# TYPE envio_reorg_threshold gauge
1557+
envio_reorg_threshold 0
1558+
# HELP envio_rollback_enabled Whether rollback on reorg is enabled
1559+
# TYPE envio_rollback_enabled gauge
1560+
envio_rollback_enabled 1
1561+
# HELP envio_rollback_seconds Rollback on reorg total time.
1562+
# TYPE envio_rollback_seconds counter
1563+
envio_rollback_seconds 0
1564+
# HELP envio_rollback_total Number of successful rollbacks on reorg
1565+
# TYPE envio_rollback_total counter
1566+
envio_rollback_total 0
1567+
# HELP envio_rollback_events Number of events rollbacked on reorg
1568+
# TYPE envio_rollback_events counter
1569+
envio_rollback_events 0
1570+
# HELP envio_processing_max_batch_size The maximum number of items to process in a single batch.
1571+
# TYPE envio_processing_max_batch_size gauge
1572+
envio_processing_max_batch_size 5000
1573+
# HELP envio_progress_block The block number of the latest block processed and stored in the database.
1574+
# TYPE envio_progress_block gauge
1575+
envio_progress_block{chainId="1"} 18732689
1576+
# HELP envio_progress_events The number of events processed and reflected in the database.
1577+
# TYPE envio_progress_events gauge
1578+
envio_progress_events{chainId="1"} 10041
1579+
# HELP envio_progress_latency The latency in milliseconds between the latest processed event creation and the time it was written to storage.
1580+
# TYPE envio_progress_latency gauge
1581+
envio_progress_latency{chainId="1"} 2080747478
1582+
# HELP envio_storage_load_seconds Processing time taken to load data from storage.
1583+
# TYPE envio_storage_load_seconds counter
1584+
envio_storage_load_seconds{operation="Account.get"} 0.026509540999999998
1585+
# HELP envio_storage_load_seconds_total Cumulative time spent loading data from storage during the indexing process.
1586+
# TYPE envio_storage_load_seconds_total counter
1587+
envio_storage_load_seconds_total{operation="Account.get"} 0.026582
1588+
# HELP envio_storage_load_total Cumulative number of successful storage load operations during the indexing process.
1589+
# TYPE envio_storage_load_total counter
1590+
envio_storage_load_total{operation="Account.get"} 4
1591+
# HELP envio_storage_load_where_size Cumulative number of filter conditions used in storage load operations.
1592+
# TYPE envio_storage_load_where_size counter
1593+
envio_storage_load_where_size{operation="Account.get"} 2477
1594+
# HELP envio_storage_load_size Cumulative number of records loaded from storage.
1595+
# TYPE envio_storage_load_size counter
1596+
envio_storage_load_size{operation="Account.get"} 267
1597+
"#;
1598+
1599+
let report = report_from_prometheus_text(input);
1600+
insta::assert_snapshot!(report);
1601+
}
1602+
}
Lines changed: 86 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,86 @@
1+
---
2+
source: packages/cli/src/executor/profile.rs
3+
assertion_line: 1600
4+
expression: report
5+
---
6+
# Envio Indexer Profile
7+
8+
## Overview
9+
10+
**Envio version**: 0.0.1-dev
11+
12+
| Metric | Value |
13+
|---|---|
14+
| Total Events Processed | 10,041 |
15+
| Total Batches | 4 |
16+
| Max Batch Size | 5,000 |
17+
18+
## Processing Pipeline
19+
20+
Cumulative time spent in each processing stage.
21+
22+
| Stage | Time |
23+
|---|---|
24+
| Loaders (preload) | 66ms |
25+
| Handlers (processing) | 35ms |
26+
| DB Writes | 145ms |
27+
| **Total** | **246ms** |
28+
29+
Pipeline split: Loaders 27% | Handlers 14% | DB Writes 59%
30+
31+
## Handler Breakdown
32+
33+
Per-handler timing sorted by total time (handler + preload).
34+
35+
| Handler | Handler Time | Calls | Preload Time | Preload Calls |
36+
|---|---|---|---|---|
37+
| ERC20 Transfer | 19ms | 6,607 | 65ms | 6,607 |
38+
| ERC20 Approval | 8ms | 3,434 | 29ms | 3,434 |
39+
40+
## Chain Progress
41+
42+
| Chain | Block | Events | Latency | Synced |
43+
|---|---|---|---|---|
44+
| 1 | 18,732,689 | 10,041 | 34679m 7s | No |
45+
46+
## Fetching Performance
47+
48+
Per-chain data fetching statistics.
49+
50+
| Chain | Fetch Time | Parse Time | Fetches | Events Fetched | Blocks Covered | Avg Events/Fetch |
51+
|---|---|---|---|---|---|---|
52+
| 1 | 19.4s | 138ms | 2 | 10,041 | 132,690 | 5020 |
53+
54+
## Indexing Status
55+
56+
Per-chain indexing configuration and timing.
57+
58+
| Chain | Known Height | Buffer | Concurrency | Partitions | Addresses | Idle Time | Waiting | Querying |
59+
|---|---|---|---|---|---|---|---|---|
60+
| 1 | 24,592,713 | 0 | 6/10 | 1 | 1 | 116ms | 1.7s | 19.5s |
61+
62+
Target buffer size: 50,000
63+
64+
## Storage Reads (Entity Loads)
65+
66+
Sorted by processing time (descending).
67+
68+
| Operation | Time | Avg/Query | Calls | Batched % | Found % |
69+
|---|---|---|---|---|---|
70+
| Account.get | 27ms | 7ms | 2,477 | 99.8% | 10.8% |
71+
72+
## System Resources
73+
74+
| Resource | Value |
75+
|---|---|
76+
| CPU Usage | - |
77+
| Memory (RSS) | - |
78+
| Heap Usage | - |
79+
| Event Loop Lag | - |
80+
81+
## Insights & Suggestions
82+
83+
- **DB writes are a significant bottleneck**59% of processing time. Consider reducing the number of entity writes or optimizing your schema.
84+
- **Slowest handlers**: `ERC20 Transfer` (84ms) and `ERC20 Approval` (36ms).
85+
- **Chain 1 has slow fetch times** (avg 9.7s per fetch). Consider enabling HyperSync or using field selection to reduce payload size.
86+
- **Storage read `Account.get` has low hit rate** (11%). Many lookups return emptyconsider if all these reads are necessary.

0 commit comments

Comments
 (0)