This is an automated email from the ASF dual-hosted git repository. morningman pushed a commit to branch main in repository https://gitbox.apache.org/repos/asf/doris-cli.git
commit 9df2a270062df0fc120b416a18a0e54a54f2f5bd Author: Mingyu Chen (Rayner) <[email protected]> AuthorDate: Sat May 30 10:01:36 2026 +0800 test(e2e): drive the profile suite against real parsed profiles Rework the profile e2e suite to send real SQL with --profile, fetch the real profile over the FE HTTP API, and assert on the PARSED VALUES rather than just the JSON shape: query_id round-trip, real SQL text, positive total_time_ms, SCAN+AGG operators, total_scan_rows ~= loaded rows, exactly 3 non-empty fragments, extracted physical_plan, parsed changed_session_vars (incl. enable_profile), a join operator + >=2 scans, and a real diff. The FE HTTP profile API is now required (it is the only source of profile text): if it is unreachable these tests FAIL instead of silently SKIP. A successful --raw fetch is captured to tests/e2e/fixtures/sample_profile.txt, which activates the offline parser regression test. Also strengthen the sql (real query_id format, exec_time_ms) and tablet (per-tablet/backend fields, partition attribution) assertions, add the expect_parsed/_capture_profile_fixture helpers, and update the README. Co-Authored-By: Claude Opus 4.8 (1M context) <[email protected]> --- tests/e2e/README.md | 44 +- tests/e2e/fixtures/.gitkeep | 6 + tests/e2e/fixtures/sample_profile.txt | 1785 +++++++++++++++++++++++++++++++++ tests/e2e/lib.sh | 28 + tests/e2e/suite_profile.sh | 193 +++- tests/e2e/suite_sql.sh | 12 +- tests/e2e/suite_tablet.sh | 15 +- 7 files changed, 2021 insertions(+), 62 deletions(-) diff --git a/tests/e2e/README.md b/tests/e2e/README.md index 96e065b..bc2f787 100644 --- a/tests/e2e/README.md +++ b/tests/e2e/README.md @@ -51,7 +51,10 @@ Run a subset with `--only "<suites>"`; list them with `--list`. ### `cargo test` (offline, unless `--no-unit`) The crate's in-tree unit tests — primarily the profile-text parsers (`section_parser`, `fragment_parser`, `operator_parser`, `value_parser`). No -cluster needed. +cluster needed. Includes `parses_a_real_captured_profile`, an offline regression +that parses a **real** profile captured by the e2e run (see below) and asserts +the load-bearing invariants. It's a visible no-op until you commit the fixture +`tests/e2e/fixtures/sample_profile.txt` that a cluster run generates. ### `cli` — argument contract (offline) `--version` / `-V`, `--help` (usage + subcommand listing), and the error paths: @@ -86,12 +89,34 @@ stats weren't collected). `UNIQUE` model detection on a second table. `--detail` (per-tablet + per-backend) and `--detail --partition` (narrowed to one partition). Negative: a missing table exits non-zero. -### `profile` — query profiles (needs cluster; HTTP-gated parts auto-SKIP) -`profile list` and `list --active` (arrays); `profile get <id>` summary (works -via the SQL fallback even without HTTP); `get --full`, `get --raw`, and `diff` -(**require the FE HTTP profile API → SKIP if `http_status != connected`**); -`profile history` (**requires `__internal_schema.audit_log` → SKIP if absent**); -and a negative case (unknown query id exits non-zero). +### `profile` — query profiles (needs cluster **+ the FE HTTP profile API**) +This suite is the point of the harness: it sends real SQL with `--profile`, +fetches the **real** profile, and asserts on the **parsed values**, not just the +JSON shape. It runs three profiled queries — a group-by over `events` (twice) and +a hash join `events⨝dim_users` — then checks, against the live profile: + +- `profile list` / `list --active` → arrays carrying the real `SHOW QUERY + PROFILE` fields (MySQL only, always testable). +- `profile get <id>` → the parsed Profile ID equals the id we sent, the parsed + SQL is our query text, `total_time_ms` is a positive parsed number, the + operator tree includes a `SCAN` and an `AGG`, `query_stats.total_scan_rows` + is ≈ the rows we loaded, and the fragment breakdown is well-formed. +- `get --full` → the full `fragments→pipelines→operators` tree with populated + `all_counters`; `get --raw` → the raw text round-trips (and is **captured as + the offline regression fixture**, see below). +- `profile diff` → two real runs of the same query: parsed totals on both sides + and a numeric `time_ratio`. +- the join query → a `JOIN` operator and ≥2 `SCAN` operators are parsed. + +The full profile **text comes only over HTTP** (REST v2 / legacy; the SQL path +yields summary metadata with no operators). So the FE HTTP profile API is a hard +requirement: **if `http_status != connected`, these parse tests FAIL, not SKIP** +— a silent skip behind a green run would hide the entire parser. Two narrower +conditions still SKIP, because they're cluster preconditions and not parser bugs: +a profile **evicted** before we could fetch it (raise `max_query_profile_num`), +and `profile history`, which needs `__internal_schema.audit_log`. Operator→table +attribution auto-SKIPs on pre-4.0 Doris (its operator headers omit `table_name`). +A negative case (unknown query id exits non-zero) rounds it out. ## The seed data @@ -117,8 +142,9 @@ See `./start-testing.sh --help`. Highlights: `--only`, `--no-unit`, `--keep`, - **MySQL/query port** (default 9030) is required for everything. - **FE HTTP port** (default 8030; cloud often **8080**) enables `auth status`'s - HTTP probe and the `profile get --full/--raw` and `profile diff` paths. - Without it those tests SKIP rather than fail. + HTTP probe and is **required by the whole `profile` suite** — it's the only + source of profile text, so without it the profile parse tests **FAIL** (they + used to SKIP). Point `--http-port` at the right port before running `profile`. - **Cloud / storage-compute**: set `DORIS_TEST_INIT_SQL='USE @<compute_group>'` so queries run against a live compute group; otherwise setup fails early with a hint. diff --git a/tests/e2e/fixtures/.gitkeep b/tests/e2e/fixtures/.gitkeep new file mode 100644 index 0000000..52cfbb7 --- /dev/null +++ b/tests/e2e/fixtures/.gitkeep @@ -0,0 +1,6 @@ +# Captured real Doris profiles used as offline parser regression fixtures. +# +# tests/e2e/suite_profile.sh writes sample_profile.txt here on a successful +# `profile get --raw` against a live cluster. Commit the generated file to +# activate the `parses_a_real_captured_profile` test in +# src/parser/profile_parser.rs (it is a no-op until the fixture exists). diff --git a/tests/e2e/fixtures/sample_profile.txt b/tests/e2e/fixtures/sample_profile.txt new file mode 100644 index 0000000..257f176 --- /dev/null +++ b/tests/e2e/fixtures/sample_profile.txt @@ -0,0 +1,1785 @@ +Summary: + - Profile ID: 4076f870101b4f9a-987957a5a6e37838 + - Task Type: QUERY + - Start Time: 2026-05-30 09:57:21 + - End Time: 2026-05-30 09:57:21 + - Total: 42ms + - Task State: OK + - User: admin + - Default Catalog: internal + - Default Db: + - Sql Statement: SELECT event_type, COUNT(*) AS c FROM `doriscli_selftest`.events GROUP BY event_type ORDER BY c DESC + - Distributed Plan: N/A +Execution Summary: + - Workload Group: normal + - Parse SQL Time: 1ms + - Plan Time: 28ms + - Garbage Collect During Plan Time: 0ms + - Nereids Lock Table Time: 0ms + - Nereids Analysis Time: 10ms + - Nereids Rewrite Time: 9ms + - Nereids Fold Const By BE Time: 0ms + - Nereids Collect Table Partition Time: 0ms + - Nereids Pre Rewrite By Mv Time: N/A + - Nereids Optimize Time: N/A + - Nereids Translate Time: 1ms + - Init Scan Node Time: N/A + - Finalize Scan Node Time: N/A + - Get Splits Time: N/A + - Get Partitions Time: N/A + - Get Partition Files Time: N/A + - Create Scan Range Time: N/A + - Nereids Distribute Time: 9ms + - Get Meta Version Time: 8hour41min + - Get Partition Version Time: 21.926ms + - Get Partition Version Count (hasData): 1 + - Get Partition Version Count: 3 + - Get Table Version Time: 9.358ms + - Get Table Version Count: 1 + - Schedule Time: 11ms + - Fragment Assign Time: 1ms + - Fragment Serialize Time: 7ms + - Fragment RPC Phase1 Time: 2ms + - Fragment RPC Phase2 Time: 1ms + - Fragment Compressed Size: 4.26 KB + - Fragment RPC Count: 2 + - Schedule Time Of BE: {"phase1":{"192.0.2.1: 8060":{"RPC Work Time":"2ms","RPC Latency From FE To BE":"-1ms","RPC Work Queue Time":"0ms","RPC Latency From BE To FE":"1ms"}},"phase2":{"192.0.2.1: 8060":{"RPC Work Time":"1ms","RPC Latency From FE To BE":"-1ms","RPC Work Queue Time":"0ms","RPC Latency From BE To FE":"1ms"}}} + - Wait and Fetch Result Time: 2ms + - Fetch Result Time: 1ms + - Write Result Time: 0ms + - Doris Version: selectdb-5.0.0-a1546ca3b28 + - Is Nereids: Yes + - Is Cached: No + - Total Instances Num: 17 + - Instances Num Per BE: 192.0.2.1:8060:17 + - Parallel Fragment Exec Instance Num: 8 + - Trace ID: + - Transaction Commit Time: N/A + - System Message: N/A + - Executed By Frontend: N/A + - Splits Assignment Weight: N/A + +ChangedSessionVariables: +[ + { + "VarName": "enable_profile", + "CurrentValue": "true", + "DefaultValue": "false" + }, + { + "VarName": "audit_plugin_max_batch_interval_sec", + "CurrentValue": "5", + "DefaultValue": "60" + } +] +MergedProfile: + Fragments: + Fragment 0: + Pipeline 0(instance_num=1): + - WaitWorkerTime: avg 6.30us, max 6.30us, min 6.30us + RESULT_SINK_OPERATOR(id=2147483647): + CommonCounters: + - ExecTime: avg 31.371us, max 31.371us, min 31.371us + - InputRows: sum 4, avg 4, max 4, min 4 + - MemoryUsage: sum 0.00 , avg 0.00 , max 0.00 , min 0.00 + - MemoryUsagePeak: sum 0.00 , avg 0.00 , max 0.00 , min 0.00 + - WaitForDependency[RESULT_SINK_OPERATOR_DEPENDENCY]Time: avg 0ns, max 0ns, min 0ns + CustomCounters: + - WaitForDependencyTime: avg 0ns, max 0ns, min 0ns + EXCHANGE_OPERATOR(id=5): + - PlanInfo + - offset: 0 + CommonCounters: + - BlocksProduced: sum 4, avg 4, max 4, min 4 + - ExecTime: avg 45.962us, max 45.962us, min 45.962us + - MemoryUsage: sum 0.00 , avg 0.00 , max 0.00 , min 0.00 + - MemoryUsagePeak: sum 576.00 B, avg 576.00 B, max 576.00 B, min 576.00 B + - RowsProduced: sum 4, avg 4, max 4, min 4 + CustomCounters: + - WaitForDependencyTime: avg 0ns, max 0ns, min 0ns + - WaitForData0: avg 479.738us, max 479.738us, min 479.738us + Fragment 1: + Pipeline 0(instance_num=8): + - WaitWorkerTime: avg 12.99us, max 31.302us, min 6.540us + DATA_STREAM_SINK_OPERATOR(dest_id=5): + CommonCounters: + - ExecTime: avg 15.307us, max 34.751us, min 10.810us + - InputRows: sum 4, avg 0, max 4, min 0 + - MemoryUsage: sum 0.00 , avg 0.00 , max 0.00 , min 0.00 + - MemoryUsagePeak: sum 0.00 , avg 0.00 , max 0.00 , min 0.00 + - WaitForDependencyTime: avg 0ns, max 0ns, min 0ns + - WaitForRpcBufferQueue: avg 0ns, max 0ns, min 0ns + CustomCounters: + - BlocksProduced: sum 12, avg 1, max 5, min 1 + - OverallThroughput: sum 0.0 /sec, avg 0.0 /sec, max 0.0 /sec, min 0.0 /sec + LOCAL_MERGE_SORT_SOURCE_OPERATOR(nereids_id=157)(id=4): + - PlanInfo + - order by: c DESC + - algorithm: full sort + - local merge sort + - merge by exchange + - offset: 0 + CommonCounters: + - BlocksProduced: sum 4, avg 0, max 4, min 0 + - ExecTime: avg 5.401us, max 34.961us, min 790ns + - MemoryUsage: sum 0.00 , avg 0.00 , max 0.00 , min 0.00 + - MemoryUsagePeak: sum 0.00 , avg 0.00 , max 0.00 , min 0.00 + - RowsProduced: sum 4, avg 0, max 4, min 0 + - WaitForDependency[LOCAL_MERGE_SORT_SOURCE_OPERATOR_DEPENDENCY]Time: avg 412.31us, max 432.16us, min 387.464us + CustomCounters: + Pipeline 1(instance_num=8): + - WaitWorkerTime: avg 11.46us, max 26.751us, min 5.880us + SORT_SINK_OPERATOR(nereids_id=157)(id=4): + CommonCounters: + - ExecTime: avg 15.614us, max 22.931us, min 10.631us + - InputRows: sum 4, avg 0, max 1, min 0 + - MemoryUsage: sum 71.00 B, avg 8.00 B, max 20.00 B, min 0.00 + - MemoryUsagePeak: sum 71.00 B, avg 8.00 B, max 20.00 B, min 0.00 + - WaitForDependency[SORT_SINK_OPERATOR_DEPENDENCY]Time: avg 0ns, max 0ns, min 0ns + CustomCounters: + - MemoryUsageSortBlocks: sum 71.00 B, avg 8.00 B, max 20.00 B, min 0.00 + LOCAL_EXCHANGE_OPERATOR(PASSTHROUGH)(id=-3): + CommonCounters: + - BlocksProduced: sum 4, avg 0, max 1, min 0 + - ExecTime: avg 1.657us, max 3.540us, min 290ns + - MemoryUsage: sum 0.00 , avg 0.00 , max 0.00 , min 0.00 + - MemoryUsagePeak: sum 16.50 KB, avg 2.06 KB, max 4.13 KB, min 0.00 + - RowsProduced: sum 4, avg 0, max 1, min 0 + - WaitForDependency[LOCAL_EXCHANGE_OPERATOR_DEPENDENCY]Time: avg 387.775us, max 411.485us, min 368.924us + CustomCounters: + - GetBlockFailedTime: sum 2, avg 0, max 1, min 0 + Pipeline 2(instance_num=8): + - WaitWorkerTime: avg 12.845us, max 32.292us, min 5.601us + LOCAL_EXCHANGE_SINK_OPERATOR(PASSTHROUGH)(id=-3): + CommonCounters: + - ExecTime: avg 4.193us, max 13.210us, min 980ns + - InputRows: sum 4, avg 0, max 1, min 0 + - MemoryUsage: sum 24.75 KB, avg 3.09 KB, max 8.25 KB, min 0.00 + - MemoryUsagePeak: sum 24.75 KB, avg 3.09 KB, max 8.25 KB, min 0.00 + - WaitForDependency[LOCAL_EXCHANGE_SINK_DEPENDENCY]Time: avg 0ns, max 0ns, min 0ns + CustomCounters: + AGGREGATION_OPERATOR(nereids_id=153)(id=3): + - PlanInfo + - output: count(partial_count(*))[#9] + - group by: event_type + - sortByGroupKey:false + - cardinality=4 + CommonCounters: + - BlocksProduced: sum 4, avg 0, max 1, min 0 + - ExecTime: avg 8.743us, max 11.930us, min 6.11us + - MemoryUsage: sum 0.00 , avg 0.00 , max 0.00 , min 0.00 + - MemoryUsagePeak: sum 0.00 , avg 0.00 , max 0.00 , min 0.00 + - RowsProduced: sum 4, avg 0, max 1, min 0 + - WaitForDependency[AGGREGATION_OPERATOR_DEPENDENCY]Time: avg 380.573us, max 399.965us, min 358.833us + CustomCounters: + - HashTableInputCount: sum 0, avg 0, max 0, min 0 + - HashTableSize: sum 0, avg 0, max 0, min 0 + - MemoryUsageHashTable: sum 0.00 , avg 0.00 , max 0.00 , min 0.00 + Pipeline 3(instance_num=8): + - WaitWorkerTime: avg 26.733us, max 51.462us, min 4.520us + AGGREGATION_SINK_OPERATOR(nereids_id=153)(id=3): + CommonCounters: + - ExecTime: avg 23.287us, max 37.504us, min 15.380us + - InputRows: sum 32, avg 4, max 8, min 0 + - MemoryUsage: sum 1.67 MB, avg 213.14 KB, max 426.28 KB, min 0.00 + - MemoryUsagePeak: sum 1.67 MB, avg 213.14 KB, max 426.28 KB, min 0.00 + - WaitForDependency[AGGREGATION_SINK_OPERATOR_DEPENDENCY]Time: avg 0ns, max 0ns, min 0ns + CustomCounters: + - MemoryUsageHashTable: sum 89.13 KB, avg 11.14 KB, max 22.28 KB, min 0.00 + - MemoryUsageSerializeKeyArena: sum 1.58 MB, avg 202.00 KB, max 404.00 KB, min 0.00 + EXCHANGE_OPERATOR(id=2): + - PlanInfo + - offset: 0 + CommonCounters: + - BlocksProduced: sum 32, avg 4, max 8, min 0 + - ExecTime: avg 11.579us, max 15.710us, min 6.230us + - MemoryUsage: sum 0.00 , avg 0.00 , max 0.00 , min 0.00 + - MemoryUsagePeak: sum 4.88 KB, avg 624.00 B, max 1.31 KB, min 0.00 + - RowsProduced: sum 32, avg 4, max 8, min 0 + CustomCounters: + - WaitForDependencyTime: avg 0ns, max 0ns, min 0ns + - WaitForData0: avg 318.963us, max 358.13us, min 283.180us + Fragment 2: + Pipeline 0(instance_num=8): + - WaitWorkerTime: avg 11.490us, max 16.41us, min 4.910us + DATA_STREAM_SINK_OPERATOR(dest_id=2): + CommonCounters: + - ExecTime: avg 57.914us, max 80.144us, min 46.52us + - InputRows: sum 32, avg 4, max 4, min 4 + - MemoryUsage: sum 0.00 , avg 0.00 , max 0.00 , min 0.00 + - MemoryUsagePeak: sum 6.00 KB, avg 768.00 B, max 768.00 B, min 768.00 B + - WaitForDependencyTime: avg 0ns, max 0ns, min 0ns + - WaitForRpcBufferQueue: avg 0ns, max 0ns, min 0ns + CustomCounters: + - BlocksProduced: sum 64, avg 8, max 8, min 8 + - OverallThroughput: sum 0.0 /sec, avg 0.0 /sec, max 0.0 /sec, min 0.0 /sec + STREAMING_AGGREGATION_OPERATOR(nereids_id=145)(id=1): + - PlanInfo + - STREAMING + - output: partial_count(*)[#7] + - group by: event_type + - sortByGroupKey:false + - cardinality=4 + CommonCounters: + - BlocksProduced: sum 8, avg 1, max 1, min 1 + - ExecTime: avg 43.182us, max 56.321us, min 36.101us + - MemoryUsage: sum 3.33 MB, avg 426.28 KB, max 426.28 KB, min 426.28 KB + - MemoryUsagePeak: sum 3.33 MB, avg 426.28 KB, max 426.28 KB, min 426.28 KB + - RowsProduced: sum 32, avg 4, max 4, min 4 + CustomCounters: + - MemoryUsageHashTable: sum 178.25 KB, avg 22.28 KB, max 22.28 KB, min 22.28 KB + - MemoryUsageSerializeKeyArena: sum 3.16 MB, avg 404.00 KB, max 404.00 KB, min 404.00 KB + - MemoryUsageSerializeKeyArenaPeak: sum 3.16 MB, avg 404.00 KB, max 404.00 KB, min 404.00 KB + OLAP_SCAN_OPERATOR(nereids_id=137. table_name=events(events))(id=0): + CommonCounters: + - BlocksProduced: sum 8, avg 1, max 1, min 1 + - ExecTime: avg 250.905us, max 311.72us, min 214.858us + - MemoryUsage: sum 40.00 KB, avg 5.00 KB, max 6.00 KB, min 4.00 KB + - MemoryUsagePeak: sum 40.00 KB, avg 5.00 KB, max 6.00 KB, min 4.00 KB + - RowsProduced: sum 2.0K (2000), avg 250, max 266, min 234 + - WaitForDependency[OLAP_SCAN_OPERATOR_DEPENDENCY]Time: avg 103.377us, max 138.716us, min 57.382us + CustomCounters: + - RuntimeFilterInfo: sum , avg , max , min + - ScanBytes: sum 8.40 KB, avg 1.05 KB, max 1.12 KB, min 1023.00 B + - ScanRows: sum 2.0K (2000), avg 250, max 266, min 234 + +DetailProfile(4076f870101b4f9a-987957a5a6e37838): + Fragments: + Fragment 0: + FragmentLevelProfile:(host=TNetworkAddress(hostname:192.0.2.1, port:9050)): + Pipeline 0(host=TNetworkAddress(hostname:192.0.2.1, port:9050)): + PipelineTask(index=0): + - TaskState: FINALIZED + - BlockedByDependency: + - WakeUpEarly: 0 + - WaitWorkerTime: 6.30us + RESULT_SINK_OPERATOR(id=2147483647): + CommonCounters: + - ExecTime: 31.371us + - InputRows: 4 + - MemoryUsage: 0.00 + - MemoryUsagePeak: 0.00 + - WaitForDependency[RESULT_SINK_OPERATOR_DEPENDENCY]Time: 0ns + CustomCounters: + - WaitForDependencyTime: 0ns + EXCHANGE_OPERATOR(id=5): + CommonCounters: + - BlocksProduced: 4 + - ExecTime: 45.962us + - MemoryUsage: 0.00 + - MemoryUsagePeak: 576.00 B + - RowsProduced: 4 + CustomCounters: + - InstanceID: 4076f870101b4f9a-987957a5a6e37849 + - WaitForDependencyTime: 0ns + - WaitForData0: 479.738us + Fragment 1: + FragmentLevelProfile:(host=TNetworkAddress(hostname:192.0.2.1, port:9050)): + Pipeline 0(host=TNetworkAddress(hostname:192.0.2.1, port:9050)): + PipelineTask(index=0): + - TaskState: FINALIZED + - BlockedByDependency: + - WakeUpEarly: 0 + - WaitWorkerTime: 10.241us + DATA_STREAM_SINK_OPERATOR(dest_id=5): + CommonCounters: + - ExecTime: 34.751us + - InputRows: 4 + - MemoryUsage: 0.00 + - MemoryUsagePeak: 0.00 + - WaitForDependencyTime: 0ns + - WaitForRpcBufferQueue: 0ns + CustomCounters: + - BlocksProduced: 5 + - OverallThroughput: 0.0 /sec + LOCAL_MERGE_SORT_SOURCE_OPERATOR(nereids_id=157)(id=4): + CommonCounters: + - BlocksProduced: 4 + - ExecTime: 34.961us + - MemoryUsage: 0.00 + - MemoryUsagePeak: 0.00 + - RowsProduced: 4 + - WaitForDependency[LOCAL_MERGE_SORT_SOURCE_OPERATOR_DEPENDENCY]Time: 421.395us + CustomCounters: + PipelineTask(index=4): + - TaskState: FINALIZED + - BlockedByDependency: + - WakeUpEarly: 0 + - WaitWorkerTime: 7.930us + DATA_STREAM_SINK_OPERATOR(dest_id=5): + CommonCounters: + - ExecTime: 13.850us + - InputRows: 0 + - MemoryUsage: 0.00 + - MemoryUsagePeak: 0.00 + - WaitForDependencyTime: 0ns + - WaitForRpcBufferQueue: 0ns + CustomCounters: + - BlocksProduced: 1 + - OverallThroughput: 0.0 /sec + LOCAL_MERGE_SORT_SOURCE_OPERATOR(nereids_id=157)(id=4): + CommonCounters: + - BlocksProduced: 0 + - ExecTime: 1.20us + - MemoryUsage: 0.00 + - MemoryUsagePeak: 0.00 + - RowsProduced: 0 + - WaitForDependency[LOCAL_MERGE_SORT_SOURCE_OPERATOR_DEPENDENCY]Time: 416.995us + CustomCounters: + PipelineTask(index=8): + - TaskState: FINALIZED + - BlockedByDependency: + - WakeUpEarly: 0 + - WaitWorkerTime: 10.150us + DATA_STREAM_SINK_OPERATOR(dest_id=5): + CommonCounters: + - ExecTime: 12.1us + - InputRows: 0 + - MemoryUsage: 0.00 + - MemoryUsagePeak: 0.00 + - WaitForDependencyTime: 0ns + - WaitForRpcBufferQueue: 0ns + CustomCounters: + - BlocksProduced: 1 + - OverallThroughput: 0.0 /sec + LOCAL_MERGE_SORT_SOURCE_OPERATOR(nereids_id=157)(id=4): + CommonCounters: + - BlocksProduced: 0 + - ExecTime: 1.70us + - MemoryUsage: 0.00 + - MemoryUsagePeak: 0.00 + - RowsProduced: 0 + - WaitForDependency[LOCAL_MERGE_SORT_SOURCE_OPERATOR_DEPENDENCY]Time: 387.464us + CustomCounters: + PipelineTask(index=12): + - TaskState: FINALIZED + - BlockedByDependency: + - WakeUpEarly: 0 + - WaitWorkerTime: 10.551us + DATA_STREAM_SINK_OPERATOR(dest_id=5): + CommonCounters: + - ExecTime: 11.60us + - InputRows: 0 + - MemoryUsage: 0.00 + - MemoryUsagePeak: 0.00 + - WaitForDependencyTime: 0ns + - WaitForRpcBufferQueue: 0ns + CustomCounters: + - BlocksProduced: 1 + - OverallThroughput: 0.0 /sec + LOCAL_MERGE_SORT_SOURCE_OPERATOR(nereids_id=157)(id=4): + CommonCounters: + - BlocksProduced: 0 + - ExecTime: 2.490us + - MemoryUsage: 0.00 + - MemoryUsagePeak: 0.00 + - RowsProduced: 0 + - WaitForDependency[LOCAL_MERGE_SORT_SOURCE_OPERATOR_DEPENDENCY]Time: 424.415us + CustomCounters: + PipelineTask(index=16): + - TaskState: FINALIZED + - BlockedByDependency: + - WakeUpEarly: 0 + - WaitWorkerTime: 6.540us + DATA_STREAM_SINK_OPERATOR(dest_id=5): + CommonCounters: + - ExecTime: 10.810us + - InputRows: 0 + - MemoryUsage: 0.00 + - MemoryUsagePeak: 0.00 + - WaitForDependencyTime: 0ns + - WaitForRpcBufferQueue: 0ns + CustomCounters: + - BlocksProduced: 1 + - OverallThroughput: 0.0 /sec + LOCAL_MERGE_SORT_SOURCE_OPERATOR(nereids_id=157)(id=4): + CommonCounters: + - BlocksProduced: 0 + - ExecTime: 790ns + - MemoryUsage: 0.00 + - MemoryUsagePeak: 0.00 + - RowsProduced: 0 + - WaitForDependency[LOCAL_MERGE_SORT_SOURCE_OPERATOR_DEPENDENCY]Time: 417.305us + CustomCounters: + PipelineTask(index=20): + - TaskState: FINALIZED + - BlockedByDependency: + - WakeUpEarly: 0 + - WaitWorkerTime: 10.360us + DATA_STREAM_SINK_OPERATOR(dest_id=5): + CommonCounters: + - ExecTime: 16.300us + - InputRows: 0 + - MemoryUsage: 0.00 + - MemoryUsagePeak: 0.00 + - WaitForDependencyTime: 0ns + - WaitForRpcBufferQueue: 0ns + CustomCounters: + - BlocksProduced: 1 + - OverallThroughput: 0.0 /sec + LOCAL_MERGE_SORT_SOURCE_OPERATOR(nereids_id=157)(id=4): + CommonCounters: + - BlocksProduced: 0 + - ExecTime: 1.190us + - MemoryUsage: 0.00 + - MemoryUsagePeak: 0.00 + - RowsProduced: 0 + - WaitForDependency[LOCAL_MERGE_SORT_SOURCE_OPERATOR_DEPENDENCY]Time: 405.175us + CustomCounters: + PipelineTask(index=24): + - TaskState: FINALIZED + - BlockedByDependency: + - WakeUpEarly: 0 + - WaitWorkerTime: 9.721us + DATA_STREAM_SINK_OPERATOR(dest_id=5): + CommonCounters: + - ExecTime: 12.430us + - InputRows: 0 + - MemoryUsage: 0.00 + - MemoryUsagePeak: 0.00 + - WaitForDependencyTime: 0ns + - WaitForRpcBufferQueue: 0ns + CustomCounters: + - BlocksProduced: 1 + - OverallThroughput: 0.0 /sec + LOCAL_MERGE_SORT_SOURCE_OPERATOR(nereids_id=157)(id=4): + CommonCounters: + - BlocksProduced: 0 + - ExecTime: 840ns + - MemoryUsage: 0.00 + - MemoryUsagePeak: 0.00 + - RowsProduced: 0 + - WaitForDependency[LOCAL_MERGE_SORT_SOURCE_OPERATOR_DEPENDENCY]Time: 432.16us + CustomCounters: + PipelineTask(index=28): + - TaskState: FINALIZED + - BlockedByDependency: + - WakeUpEarly: 0 + - WaitWorkerTime: 31.302us + DATA_STREAM_SINK_OPERATOR(dest_id=5): + CommonCounters: + - ExecTime: 11.260us + - InputRows: 0 + - MemoryUsage: 0.00 + - MemoryUsagePeak: 0.00 + - WaitForDependencyTime: 0ns + - WaitForRpcBufferQueue: 0ns + CustomCounters: + - BlocksProduced: 1 + - OverallThroughput: 0.0 /sec + LOCAL_MERGE_SORT_SOURCE_OPERATOR(nereids_id=157)(id=4): + CommonCounters: + - BlocksProduced: 0 + - ExecTime: 850ns + - MemoryUsage: 0.00 + - MemoryUsagePeak: 0.00 + - RowsProduced: 0 + - WaitForDependency[LOCAL_MERGE_SORT_SOURCE_OPERATOR_DEPENDENCY]Time: 391.484us + CustomCounters: + Pipeline 1(host=TNetworkAddress(hostname:192.0.2.1, port:9050)): + PipelineTask(index=1): + - TaskState: FINALIZED + - BlockedByDependency: + - WakeUpEarly: 0 + - WaitWorkerTime: 6.750us + SORT_SINK_OPERATOR(nereids_id=157)(id=4): + CommonCounters: + - ExecTime: 19.860us + - InputRows: 1 + - MemoryUsage: 17.00 B + - MemoryUsagePeak: 17.00 B + - WaitForDependency[SORT_SINK_OPERATOR_DEPENDENCY]Time: 0ns + CustomCounters: + - TOP-N: false + - SortAlgorithm: FULL_SORT + - MemoryUsageSortBlocks: 17.00 B + LOCAL_EXCHANGE_OPERATOR(PASSTHROUGH)(id=-3): + CommonCounters: + - BlocksProduced: 1 + - ExecTime: 3.540us + - MemoryUsage: 0.00 + - MemoryUsagePeak: 4.13 KB + - RowsProduced: 1 + - WaitForDependency[LOCAL_EXCHANGE_OPERATOR_DEPENDENCY]Time: 408.956us + CustomCounters: + - GetBlockFailedTime: 1 + PipelineTask(index=5): + - TaskState: FINALIZED + - BlockedByDependency: + - WakeUpEarly: 0 + - WaitWorkerTime: 5.970us + SORT_SINK_OPERATOR(nereids_id=157)(id=4): + CommonCounters: + - ExecTime: 12.530us + - InputRows: 0 + - MemoryUsage: 0.00 + - MemoryUsagePeak: 0.00 + - WaitForDependency[SORT_SINK_OPERATOR_DEPENDENCY]Time: 0ns + CustomCounters: + - TOP-N: false + - SortAlgorithm: FULL_SORT + - MemoryUsageSortBlocks: 0.00 + LOCAL_EXCHANGE_OPERATOR(PASSTHROUGH)(id=-3): + CommonCounters: + - BlocksProduced: 0 + - ExecTime: 870ns + - MemoryUsage: 0.00 + - MemoryUsagePeak: 0.00 + - RowsProduced: 0 + - WaitForDependency[LOCAL_EXCHANGE_OPERATOR_DEPENDENCY]Time: 411.485us + CustomCounters: + - GetBlockFailedTime: 0 + PipelineTask(index=9): + - TaskState: FINALIZED + - BlockedByDependency: + - WakeUpEarly: 0 + - WaitWorkerTime: 5.880us + SORT_SINK_OPERATOR(nereids_id=157)(id=4): + CommonCounters: + - ExecTime: 11.211us + - InputRows: 0 + - MemoryUsage: 0.00 + - MemoryUsagePeak: 0.00 + - WaitForDependency[SORT_SINK_OPERATOR_DEPENDENCY]Time: 0ns + CustomCounters: + - TOP-N: false + - SortAlgorithm: FULL_SORT + - MemoryUsageSortBlocks: 0.00 + LOCAL_EXCHANGE_OPERATOR(PASSTHROUGH)(id=-3): + CommonCounters: + - BlocksProduced: 0 + - ExecTime: 680ns + - MemoryUsage: 0.00 + - MemoryUsagePeak: 0.00 + - RowsProduced: 0 + - WaitForDependency[LOCAL_EXCHANGE_OPERATOR_DEPENDENCY]Time: 377.984us + CustomCounters: + - GetBlockFailedTime: 0 + PipelineTask(index=13): + - TaskState: FINALIZED + - BlockedByDependency: + - WakeUpEarly: 0 + - WaitWorkerTime: 16.250us + SORT_SINK_OPERATOR(nereids_id=157)(id=4): + CommonCounters: + - ExecTime: 14.590us + - InputRows: 1 + - MemoryUsage: 20.00 B + - MemoryUsagePeak: 20.00 B + - WaitForDependency[SORT_SINK_OPERATOR_DEPENDENCY]Time: 0ns + CustomCounters: + - TOP-N: false + - SortAlgorithm: FULL_SORT + - MemoryUsageSortBlocks: 20.00 B + LOCAL_EXCHANGE_OPERATOR(PASSTHROUGH)(id=-3): + CommonCounters: + - BlocksProduced: 1 + - ExecTime: 2.930us + - MemoryUsage: 0.00 + - MemoryUsagePeak: 4.13 KB + - RowsProduced: 1 + - WaitForDependency[LOCAL_EXCHANGE_OPERATOR_DEPENDENCY]Time: 396.124us + CustomCounters: + - GetBlockFailedTime: 1 + PipelineTask(index=17): + - TaskState: FINALIZED + - BlockedByDependency: + - WakeUpEarly: 0 + - WaitWorkerTime: 6.281us + SORT_SINK_OPERATOR(nereids_id=157)(id=4): + CommonCounters: + - ExecTime: 10.631us + - InputRows: 0 + - MemoryUsage: 0.00 + - MemoryUsagePeak: 0.00 + - WaitForDependency[SORT_SINK_OPERATOR_DEPENDENCY]Time: 0ns + CustomCounters: + - TOP-N: false + - SortAlgorithm: FULL_SORT + - MemoryUsageSortBlocks: 0.00 + LOCAL_EXCHANGE_OPERATOR(PASSTHROUGH)(id=-3): + CommonCounters: + - BlocksProduced: 0 + - ExecTime: 290ns + - MemoryUsage: 0.00 + - MemoryUsagePeak: 0.00 + - RowsProduced: 0 + - WaitForDependency[LOCAL_EXCHANGE_OPERATOR_DEPENDENCY]Time: 386.814us + CustomCounters: + - GetBlockFailedTime: 0 + PipelineTask(index=21): + - TaskState: FINALIZED + - BlockedByDependency: + - WakeUpEarly: 0 + - WaitWorkerTime: 8.450us + SORT_SINK_OPERATOR(nereids_id=157)(id=4): + CommonCounters: + - ExecTime: 13.730us + - InputRows: 0 + - MemoryUsage: 0.00 + - MemoryUsagePeak: 0.00 + - WaitForDependency[SORT_SINK_OPERATOR_DEPENDENCY]Time: 0ns + CustomCounters: + - TOP-N: false + - SortAlgorithm: FULL_SORT + - MemoryUsageSortBlocks: 0.00 + LOCAL_EXCHANGE_OPERATOR(PASSTHROUGH)(id=-3): + CommonCounters: + - BlocksProduced: 0 + - ExecTime: 870ns + - MemoryUsage: 0.00 + - MemoryUsagePeak: 0.00 + - RowsProduced: 0 + - WaitForDependency[LOCAL_EXCHANGE_OPERATOR_DEPENDENCY]Time: 374.454us + CustomCounters: + - GetBlockFailedTime: 0 + PipelineTask(index=25): + - TaskState: FINALIZED + - BlockedByDependency: + - WakeUpEarly: 0 + - WaitWorkerTime: 12.41us + SORT_SINK_OPERATOR(nereids_id=157)(id=4): + CommonCounters: + - ExecTime: 19.431us + - InputRows: 1 + - MemoryUsage: 16.00 B + - MemoryUsagePeak: 16.00 B + - WaitForDependency[SORT_SINK_OPERATOR_DEPENDENCY]Time: 0ns + CustomCounters: + - TOP-N: false + - SortAlgorithm: FULL_SORT + - MemoryUsageSortBlocks: 16.00 B + LOCAL_EXCHANGE_OPERATOR(PASSTHROUGH)(id=-3): + CommonCounters: + - BlocksProduced: 1 + - ExecTime: 1.850us + - MemoryUsage: 0.00 + - MemoryUsagePeak: 4.13 KB + - RowsProduced: 1 + - WaitForDependency[LOCAL_EXCHANGE_OPERATOR_DEPENDENCY]Time: 377.464us + CustomCounters: + - GetBlockFailedTime: 0 + PipelineTask(index=29): + - TaskState: FINALIZED + - BlockedByDependency: + - WakeUpEarly: 0 + - WaitWorkerTime: 26.751us + SORT_SINK_OPERATOR(nereids_id=157)(id=4): + CommonCounters: + - ExecTime: 22.931us + - InputRows: 1 + - MemoryUsage: 18.00 B + - MemoryUsagePeak: 18.00 B + - WaitForDependency[SORT_SINK_OPERATOR_DEPENDENCY]Time: 0ns + CustomCounters: + - TOP-N: false + - SortAlgorithm: FULL_SORT + - MemoryUsageSortBlocks: 18.00 B + LOCAL_EXCHANGE_OPERATOR(PASSTHROUGH)(id=-3): + CommonCounters: + - BlocksProduced: 1 + - ExecTime: 2.230us + - MemoryUsage: 0.00 + - MemoryUsagePeak: 4.13 KB + - RowsProduced: 1 + - WaitForDependency[LOCAL_EXCHANGE_OPERATOR_DEPENDENCY]Time: 368.924us + CustomCounters: + - GetBlockFailedTime: 0 + Pipeline 2(host=TNetworkAddress(hostname:192.0.2.1, port:9050)): + PipelineTask(index=2): + - TaskState: FINALIZED + - BlockedByDependency: + - WakeUpEarly: 0 + - WaitWorkerTime: 8.770us + LOCAL_EXCHANGE_SINK_OPERATOR(PASSTHROUGH)(id=-3): + CommonCounters: + - ExecTime: 6.320us + - InputRows: 1 + - MemoryUsage: 4.13 KB + - MemoryUsagePeak: 4.13 KB + - WaitForDependency[LOCAL_EXCHANGE_SINK_DEPENDENCY]Time: 0ns + CustomCounters: + - PartitionExprsSize: 0 + AGGREGATION_OPERATOR(nereids_id=153)(id=3): + CommonCounters: + - BlocksProduced: 1 + - ExecTime: 11.930us + - MemoryUsage: 0.00 + - MemoryUsagePeak: 0.00 + - RowsProduced: 1 + - WaitForDependency[AGGREGATION_OPERATOR_DEPENDENCY]Time: 390.194us + CustomCounters: + - HashTableInputCount: 0 + - HashTableSize: 0 + - MemoryUsageHashTable: 0.00 + PipelineTask(index=6): + - TaskState: FINALIZED + - BlockedByDependency: + - WakeUpEarly: 0 + - WaitWorkerTime: 5.601us + LOCAL_EXCHANGE_SINK_OPERATOR(PASSTHROUGH)(id=-3): + CommonCounters: + - ExecTime: 1.400us + - InputRows: 0 + - MemoryUsage: 0.00 + - MemoryUsagePeak: 0.00 + - WaitForDependency[LOCAL_EXCHANGE_SINK_DEPENDENCY]Time: 0ns + CustomCounters: + - PartitionExprsSize: 0 + AGGREGATION_OPERATOR(nereids_id=153)(id=3): + CommonCounters: + - BlocksProduced: 0 + - ExecTime: 10.670us + - MemoryUsage: 0.00 + - MemoryUsagePeak: 0.00 + - RowsProduced: 0 + - WaitForDependency[AGGREGATION_OPERATOR_DEPENDENCY]Time: 391.294us + CustomCounters: + - HashTableInputCount: 0 + - HashTableSize: 0 + - MemoryUsageHashTable: 0.00 + PipelineTask(index=10): + - TaskState: FINALIZED + - BlockedByDependency: + - WakeUpEarly: 0 + - WaitWorkerTime: 6.400us + LOCAL_EXCHANGE_SINK_OPERATOR(PASSTHROUGH)(id=-3): + CommonCounters: + - ExecTime: 1.380us + - InputRows: 0 + - MemoryUsage: 0.00 + - MemoryUsagePeak: 0.00 + - WaitForDependency[LOCAL_EXCHANGE_SINK_DEPENDENCY]Time: 0ns + CustomCounters: + - PartitionExprsSize: 0 + AGGREGATION_OPERATOR(nereids_id=153)(id=3): + CommonCounters: + - BlocksProduced: 0 + - ExecTime: 7.751us + - MemoryUsage: 0.00 + - MemoryUsagePeak: 0.00 + - RowsProduced: 0 + - WaitForDependency[AGGREGATION_OPERATOR_DEPENDENCY]Time: 375.4us + CustomCounters: + - HashTableInputCount: 0 + - HashTableSize: 0 + - MemoryUsageHashTable: 0.00 + PipelineTask(index=14): + - TaskState: FINALIZED + - BlockedByDependency: + - WakeUpEarly: 0 + - WaitWorkerTime: 6.420us + LOCAL_EXCHANGE_SINK_OPERATOR(PASSTHROUGH)(id=-3): + CommonCounters: + - ExecTime: 5.80us + - InputRows: 1 + - MemoryUsage: 8.25 KB + - MemoryUsagePeak: 8.25 KB + - WaitForDependency[LOCAL_EXCHANGE_SINK_DEPENDENCY]Time: 0ns + CustomCounters: + - PartitionExprsSize: 0 + AGGREGATION_OPERATOR(nereids_id=153)(id=3): + CommonCounters: + - BlocksProduced: 1 + - ExecTime: 8.270us + - MemoryUsage: 0.00 + - MemoryUsagePeak: 0.00 + - RowsProduced: 1 + - WaitForDependency[AGGREGATION_OPERATOR_DEPENDENCY]Time: 376.154us + CustomCounters: + - HashTableInputCount: 0 + - HashTableSize: 0 + - MemoryUsageHashTable: 0.00 + PipelineTask(index=18): + - TaskState: FINALIZED + - BlockedByDependency: + - WakeUpEarly: 0 + - WaitWorkerTime: 12.310us + LOCAL_EXCHANGE_SINK_OPERATOR(PASSTHROUGH)(id=-3): + CommonCounters: + - ExecTime: 980ns + - InputRows: 0 + - MemoryUsage: 0.00 + - MemoryUsagePeak: 0.00 + - WaitForDependency[LOCAL_EXCHANGE_SINK_DEPENDENCY]Time: 0ns + CustomCounters: + - PartitionExprsSize: 0 + AGGREGATION_OPERATOR(nereids_id=153)(id=3): + CommonCounters: + - BlocksProduced: 0 + - ExecTime: 6.11us + - MemoryUsage: 0.00 + - MemoryUsagePeak: 0.00 + - RowsProduced: 0 + - WaitForDependency[AGGREGATION_OPERATOR_DEPENDENCY]Time: 399.965us + CustomCounters: + - HashTableInputCount: 0 + - HashTableSize: 0 + - MemoryUsageHashTable: 0.00 + PipelineTask(index=22): + - TaskState: FINALIZED + - BlockedByDependency: + - WakeUpEarly: 0 + - WaitWorkerTime: 17.290us + LOCAL_EXCHANGE_SINK_OPERATOR(PASSTHROUGH)(id=-3): + CommonCounters: + - ExecTime: 1.610us + - InputRows: 0 + - MemoryUsage: 0.00 + - MemoryUsagePeak: 0.00 + - WaitForDependency[LOCAL_EXCHANGE_SINK_DEPENDENCY]Time: 0ns + CustomCounters: + - PartitionExprsSize: 0 + AGGREGATION_OPERATOR(nereids_id=153)(id=3): + CommonCounters: + - BlocksProduced: 0 + - ExecTime: 9.931us + - MemoryUsage: 0.00 + - MemoryUsagePeak: 0.00 + - RowsProduced: 0 + - WaitForDependency[AGGREGATION_OPERATOR_DEPENDENCY]Time: 388.504us + CustomCounters: + - HashTableInputCount: 0 + - HashTableSize: 0 + - MemoryUsageHashTable: 0.00 + PipelineTask(index=26): + - TaskState: FINALIZED + - BlockedByDependency: + - WakeUpEarly: 0 + - WaitWorkerTime: 13.681us + LOCAL_EXCHANGE_SINK_OPERATOR(PASSTHROUGH)(id=-3): + CommonCounters: + - ExecTime: 3.571us + - InputRows: 1 + - MemoryUsage: 4.13 KB + - MemoryUsagePeak: 4.13 KB + - WaitForDependency[LOCAL_EXCHANGE_SINK_DEPENDENCY]Time: 0ns + CustomCounters: + - PartitionExprsSize: 0 + AGGREGATION_OPERATOR(nereids_id=153)(id=3): + CommonCounters: + - BlocksProduced: 1 + - ExecTime: 7.710us + - MemoryUsage: 0.00 + - MemoryUsagePeak: 0.00 + - RowsProduced: 1 + - WaitForDependency[AGGREGATION_OPERATOR_DEPENDENCY]Time: 358.833us + CustomCounters: + - HashTableInputCount: 0 + - HashTableSize: 0 + - MemoryUsageHashTable: 0.00 + PipelineTask(index=30): + - TaskState: FINALIZED + - BlockedByDependency: + - WakeUpEarly: 0 + - WaitWorkerTime: 32.292us + LOCAL_EXCHANGE_SINK_OPERATOR(PASSTHROUGH)(id=-3): + CommonCounters: + - ExecTime: 13.210us + - InputRows: 1 + - MemoryUsage: 8.25 KB + - MemoryUsagePeak: 8.25 KB + - WaitForDependency[LOCAL_EXCHANGE_SINK_DEPENDENCY]Time: 0ns + CustomCounters: + - PartitionExprsSize: 0 + AGGREGATION_OPERATOR(nereids_id=153)(id=3): + CommonCounters: + - BlocksProduced: 1 + - ExecTime: 7.671us + - MemoryUsage: 0.00 + - MemoryUsagePeak: 0.00 + - RowsProduced: 1 + - WaitForDependency[AGGREGATION_OPERATOR_DEPENDENCY]Time: 364.643us + CustomCounters: + - HashTableInputCount: 0 + - HashTableSize: 0 + - MemoryUsageHashTable: 0.00 + Pipeline 3(host=TNetworkAddress(hostname:192.0.2.1, port:9050)): + PipelineTask(index=3): + - TaskState: FINALIZED + - BlockedByDependency: + - WakeUpEarly: 0 + - WaitWorkerTime: 49.32us + AGGREGATION_SINK_OPERATOR(nereids_id=153)(id=3): + CommonCounters: + - ExecTime: 37.504us + - InputRows: 8 + - MemoryUsage: 426.28 KB + - MemoryUsagePeak: 426.28 KB + - WaitForDependency[AGGREGATION_SINK_OPERATOR_DEPENDENCY]Time: 0ns + CustomCounters: + - MemoryUsageHashTable: 22.28 KB + - MemoryUsageSerializeKeyArena: 404.00 KB + EXCHANGE_OPERATOR(id=2): + CommonCounters: + - BlocksProduced: 8 + - ExecTime: 15.710us + - MemoryUsage: 0.00 + - MemoryUsagePeak: 1.31 KB + - RowsProduced: 8 + CustomCounters: + - InstanceID: 4076f870101b4f9a-987957a5a6e37841 + - WaitForDependencyTime: 0ns + - WaitForData0: 283.180us + PipelineTask(index=7): + - TaskState: FINALIZED + - BlockedByDependency: + - WakeUpEarly: 0 + - WaitWorkerTime: 19.650us + AGGREGATION_SINK_OPERATOR(nereids_id=153)(id=3): + CommonCounters: + - ExecTime: 17.972us + - InputRows: 0 + - MemoryUsage: 0.00 + - MemoryUsagePeak: 0.00 + - WaitForDependency[AGGREGATION_SINK_OPERATOR_DEPENDENCY]Time: 0ns + CustomCounters: + - MemoryUsageHashTable: 0.00 + - MemoryUsageSerializeKeyArena: 0.00 + EXCHANGE_OPERATOR(id=2): + CommonCounters: + - BlocksProduced: 0 + - ExecTime: 9.851us + - MemoryUsage: 0.00 + - MemoryUsagePeak: 0.00 + - RowsProduced: 0 + CustomCounters: + - InstanceID: 4076f870101b4f9a-987957a5a6e37842 + - WaitForDependencyTime: 0ns + - WaitForData0: 356.283us + PipelineTask(index=11): + - TaskState: FINALIZED + - BlockedByDependency: + - WakeUpEarly: 0 + - WaitWorkerTime: 4.520us + AGGREGATION_SINK_OPERATOR(nereids_id=153)(id=3): + CommonCounters: + - ExecTime: 15.421us + - InputRows: 0 + - MemoryUsage: 0.00 + - MemoryUsagePeak: 0.00 + - WaitForDependency[AGGREGATION_SINK_OPERATOR_DEPENDENCY]Time: 0ns + CustomCounters: + - MemoryUsageHashTable: 0.00 + - MemoryUsageSerializeKeyArena: 0.00 + EXCHANGE_OPERATOR(id=2): + CommonCounters: + - BlocksProduced: 0 + - ExecTime: 10.461us + - MemoryUsage: 0.00 + - MemoryUsagePeak: 0.00 + - RowsProduced: 0 + CustomCounters: + - InstanceID: 4076f870101b4f9a-987957a5a6e37843 + - WaitForDependencyTime: 0ns + - WaitForData0: 358.13us + PipelineTask(index=15): + - TaskState: FINALIZED + - BlockedByDependency: + - WakeUpEarly: 0 + - WaitWorkerTime: 51.462us + AGGREGATION_SINK_OPERATOR(nereids_id=153)(id=3): + CommonCounters: + - ExecTime: 27.152us + - InputRows: 8 + - MemoryUsage: 426.28 KB + - MemoryUsagePeak: 426.28 KB + - WaitForDependency[AGGREGATION_SINK_OPERATOR_DEPENDENCY]Time: 0ns + CustomCounters: + - MemoryUsageHashTable: 22.28 KB + - MemoryUsageSerializeKeyArena: 404.00 KB + EXCHANGE_OPERATOR(id=2): + CommonCounters: + - BlocksProduced: 8 + - ExecTime: 13.190us + - MemoryUsage: 0.00 + - MemoryUsagePeak: 1.31 KB + - RowsProduced: 8 + CustomCounters: + - InstanceID: 4076f870101b4f9a-987957a5a6e37844 + - WaitForDependencyTime: 0ns + - WaitForData0: 286.21us + PipelineTask(index=19): + - TaskState: FINALIZED + - BlockedByDependency: + - WakeUpEarly: 0 + - WaitWorkerTime: 5.31us + AGGREGATION_SINK_OPERATOR(nereids_id=153)(id=3): + CommonCounters: + - ExecTime: 15.780us + - InputRows: 0 + - MemoryUsage: 0.00 + - MemoryUsagePeak: 0.00 + - WaitForDependency[AGGREGATION_SINK_OPERATOR_DEPENDENCY]Time: 0ns + CustomCounters: + - MemoryUsageHashTable: 0.00 + - MemoryUsageSerializeKeyArena: 0.00 + EXCHANGE_OPERATOR(id=2): + CommonCounters: + - BlocksProduced: 0 + - ExecTime: 10.200us + - MemoryUsage: 0.00 + - MemoryUsagePeak: 0.00 + - RowsProduced: 0 + CustomCounters: + - InstanceID: 4076f870101b4f9a-987957a5a6e37845 + - WaitForDependencyTime: 0ns + - WaitForData0: 335.153us + PipelineTask(index=23): + - TaskState: FINALIZED + - BlockedByDependency: + - WakeUpEarly: 0 + - WaitWorkerTime: 11.430us + AGGREGATION_SINK_OPERATOR(nereids_id=153)(id=3): + CommonCounters: + - ExecTime: 15.380us + - InputRows: 0 + - MemoryUsage: 0.00 + - MemoryUsagePeak: 0.00 + - WaitForDependency[AGGREGATION_SINK_OPERATOR_DEPENDENCY]Time: 0ns + CustomCounters: + - MemoryUsageHashTable: 0.00 + - MemoryUsageSerializeKeyArena: 0.00 + EXCHANGE_OPERATOR(id=2): + CommonCounters: + - BlocksProduced: 0 + - ExecTime: 6.230us + - MemoryUsage: 0.00 + - MemoryUsagePeak: 0.00 + - RowsProduced: 0 + CustomCounters: + - InstanceID: 4076f870101b4f9a-987957a5a6e37846 + - WaitForDependencyTime: 0ns + - WaitForData0: 338.683us + PipelineTask(index=27): + - TaskState: FINALIZED + - BlockedByDependency: + - WakeUpEarly: 0 + - WaitWorkerTime: 43.382us + AGGREGATION_SINK_OPERATOR(nereids_id=153)(id=3): + CommonCounters: + - ExecTime: 29.2us + - InputRows: 8 + - MemoryUsage: 426.28 KB + - MemoryUsagePeak: 426.28 KB + - WaitForDependency[AGGREGATION_SINK_OPERATOR_DEPENDENCY]Time: 0ns + CustomCounters: + - MemoryUsageHashTable: 22.28 KB + - MemoryUsageSerializeKeyArena: 404.00 KB + EXCHANGE_OPERATOR(id=2): + CommonCounters: + - BlocksProduced: 8 + - ExecTime: 13.170us + - MemoryUsage: 0.00 + - MemoryUsagePeak: 1.13 KB + - RowsProduced: 8 + CustomCounters: + - InstanceID: 4076f870101b4f9a-987957a5a6e37847 + - WaitForDependencyTime: 0ns + - WaitForData0: 294.991us + PipelineTask(index=31): + - TaskState: FINALIZED + - BlockedByDependency: + - WakeUpEarly: 0 + - WaitWorkerTime: 29.361us + AGGREGATION_SINK_OPERATOR(nereids_id=153)(id=3): + CommonCounters: + - ExecTime: 28.92us + - InputRows: 8 + - MemoryUsage: 426.28 KB + - MemoryUsagePeak: 426.28 KB + - WaitForDependency[AGGREGATION_SINK_OPERATOR_DEPENDENCY]Time: 0ns + CustomCounters: + - MemoryUsageHashTable: 22.28 KB + - MemoryUsageSerializeKeyArena: 404.00 KB + EXCHANGE_OPERATOR(id=2): + CommonCounters: + - BlocksProduced: 8 + - ExecTime: 13.820us + - MemoryUsage: 0.00 + - MemoryUsagePeak: 1.13 KB + - RowsProduced: 8 + CustomCounters: + - InstanceID: 4076f870101b4f9a-987957a5a6e37848 + - WaitForDependencyTime: 0ns + - WaitForData0: 299.381us + Fragment 2: + FragmentLevelProfile:(host=TNetworkAddress(hostname:192.0.2.1, port:9050)): + Pipeline 0(host=TNetworkAddress(hostname:192.0.2.1, port:9050)): + PipelineTask(index=0): + - TaskState: FINALIZED + - BlockedByDependency: + - WakeUpEarly: 0 + - WaitWorkerTime: 14.41us + DATA_STREAM_SINK_OPERATOR(dest_id=2): + CommonCounters: + - ExecTime: 54.473us + - InputRows: 4 + - MemoryUsage: 0.00 + - MemoryUsagePeak: 768.00 B + - WaitForDependencyTime: 0ns + - WaitForRpcBufferQueue: 0ns + CustomCounters: + - Partitioner: Crc32HashPartitioner(8) + - BlocksProduced: 8 + - OverallThroughput: 0.0 /sec + STREAMING_AGGREGATION_OPERATOR(nereids_id=145)(id=1): + CommonCounters: + - BlocksProduced: 1 + - ExecTime: 37.211us + - MemoryUsage: 426.28 KB + - MemoryUsagePeak: 426.28 KB + - RowsProduced: 4 + CustomCounters: + - MemoryUsageHashTable: 22.28 KB + - MemoryUsageSerializeKeyArena: 404.00 KB + - MemoryUsageSerializeKeyArenaPeak: 404.00 KB + OLAP_SCAN_OPERATOR(nereids_id=137. table_name=events(events))(id=0): + CommonCounters: + - BlocksProduced: 1 + - ExecTime: 294.701us + - MemoryUsage: 6.00 KB + - MemoryUsagePeak: 6.00 KB + - RowsProduced: 266 + - WaitForDependency[OLAP_SCAN_OPERATOR_DEPENDENCY]Time: 134.215us + CustomCounters: + - TopNFilterSourceNodeIds: + - PushDownPredicates: [] + - KeyRanges: ScanKeys: + - TabletIds: [1778469329803] + - RuntimeFilterInfo: + - ScanBytes: 1.12 KB + - ScanRows: 266 + Scanner: + - ReadColumns: [event_type] + - PerScannerRunningTime: [7.740us, ] + - PerScannerRowsRead: [266, ] + - PerScannerWaitTime: [7.371us, ] + - PerScannerProjectionTime: [2.610us, ] + - EOS: True + SegmentIterator: + - FileCache: 0ns + - BytesScannedFromCache: 188.00 B + - BytesScannedFromPeer: 0.00 + - BytesScannedFromRemote: 0.00 + - BytesWriteIntoCache: 0.00 + - CacheGetOrSetTimer: 48.832us + - GetTimer: 1.900us + - InvertedIndexBytesScannedFromCache: 0.00 + - InvertedIndexBytesScannedFromPeer: 0.00 + - InvertedIndexBytesScannedFromRemote: 0.00 + - InvertedIndexIOTimer: 0ns + - InvertedIndexLocalIOUseTimer: 0ns + - InvertedIndexNumLocalIOTotal: 0 + - InvertedIndexNumPeerIOTotal: 0 + - InvertedIndexNumRemoteIOTotal: 0 + - InvertedIndexPeerIOUseTimer: 0ns + - InvertedIndexRemoteIOUseTimer: 0ns + - LocalIOUseTimer: 5.170us + - LockWaitTimer: 43.882us + - NumLocalIOTotal: 2 + - NumPeerIOTotal: 0 + - NumRemoteIOTotal: 0 + - NumSkipCacheIOTotal: 0 + - PeerIOUseTimer: 0ns + - ReadCacheFileDirectlyTimer: 0ns + - RemoteIOUseTimer: 0ns + - SetTimer: 140ns + - WaitOtherDownloaderTimer: 0ns + - WriteCacheIOUseTimer: 0ns + IndexFilter: + PipelineTask(index=1): + - TaskState: FINALIZED + - BlockedByDependency: + - WakeUpEarly: 0 + - WaitWorkerTime: 14.891us + DATA_STREAM_SINK_OPERATOR(dest_id=2): + CommonCounters: + - ExecTime: 46.181us + - InputRows: 4 + - MemoryUsage: 0.00 + - MemoryUsagePeak: 768.00 B + - WaitForDependencyTime: 0ns + - WaitForRpcBufferQueue: 0ns + CustomCounters: + - Partitioner: Crc32HashPartitioner(8) + - BlocksProduced: 8 + - OverallThroughput: 0.0 /sec + STREAMING_AGGREGATION_OPERATOR(nereids_id=145)(id=1): + CommonCounters: + - BlocksProduced: 1 + - ExecTime: 47.791us + - MemoryUsage: 426.28 KB + - MemoryUsagePeak: 426.28 KB + - RowsProduced: 4 + CustomCounters: + - MemoryUsageHashTable: 22.28 KB + - MemoryUsageSerializeKeyArena: 404.00 KB + - MemoryUsageSerializeKeyArenaPeak: 404.00 KB + OLAP_SCAN_OPERATOR(nereids_id=137. table_name=events(events))(id=0): + CommonCounters: + - BlocksProduced: 1 + - ExecTime: 311.72us + - MemoryUsage: 6.00 KB + - MemoryUsagePeak: 6.00 KB + - RowsProduced: 264 + - WaitForDependency[OLAP_SCAN_OPERATOR_DEPENDENCY]Time: 57.382us + CustomCounters: + - TopNFilterSourceNodeIds: + - PushDownPredicates: [] + - KeyRanges: ScanKeys: + - TabletIds: [1778469329805] + - RuntimeFilterInfo: + - ScanBytes: 1.09 KB + - ScanRows: 264 + Scanner: + - ReadColumns: [event_type] + - PerScannerRunningTime: [13.631us, ] + - PerScannerRowsRead: [264, ] + - PerScannerWaitTime: [4.150us, ] + - PerScannerProjectionTime: [11.181us, ] + - EOS: True + SegmentIterator: + - FileCache: 0ns + - BytesScannedFromCache: 186.00 B + - BytesScannedFromPeer: 0.00 + - BytesScannedFromRemote: 0.00 + - BytesWriteIntoCache: 0.00 + - CacheGetOrSetTimer: 3.170us + - GetTimer: 1.980us + - InvertedIndexBytesScannedFromCache: 0.00 + - InvertedIndexBytesScannedFromPeer: 0.00 + - InvertedIndexBytesScannedFromRemote: 0.00 + - InvertedIndexIOTimer: 0ns + - InvertedIndexLocalIOUseTimer: 0ns + - InvertedIndexNumLocalIOTotal: 0 + - InvertedIndexNumPeerIOTotal: 0 + - InvertedIndexNumRemoteIOTotal: 0 + - InvertedIndexPeerIOUseTimer: 0ns + - InvertedIndexRemoteIOUseTimer: 0ns + - LocalIOUseTimer: 3.140us + - LockWaitTimer: 100ns + - NumLocalIOTotal: 2 + - NumPeerIOTotal: 0 + - NumRemoteIOTotal: 0 + - NumSkipCacheIOTotal: 0 + - PeerIOUseTimer: 0ns + - ReadCacheFileDirectlyTimer: 0ns + - RemoteIOUseTimer: 0ns + - SetTimer: 50ns + - WaitOtherDownloaderTimer: 0ns + - WriteCacheIOUseTimer: 0ns + IndexFilter: + PipelineTask(index=2): + - TaskState: FINALIZED + - BlockedByDependency: + - WakeUpEarly: 0 + - WaitWorkerTime: 5.130us + DATA_STREAM_SINK_OPERATOR(dest_id=2): + CommonCounters: + - ExecTime: 80.144us + - InputRows: 4 + - MemoryUsage: 0.00 + - MemoryUsagePeak: 768.00 B + - WaitForDependencyTime: 0ns + - WaitForRpcBufferQueue: 0ns + CustomCounters: + - Partitioner: Crc32HashPartitioner(8) + - BlocksProduced: 8 + - OverallThroughput: 0.0 /sec + STREAMING_AGGREGATION_OPERATOR(nereids_id=145)(id=1): + CommonCounters: + - BlocksProduced: 1 + - ExecTime: 48.152us + - MemoryUsage: 426.28 KB + - MemoryUsagePeak: 426.28 KB + - RowsProduced: 4 + CustomCounters: + - MemoryUsageHashTable: 22.28 KB + - MemoryUsageSerializeKeyArena: 404.00 KB + - MemoryUsageSerializeKeyArenaPeak: 404.00 KB + OLAP_SCAN_OPERATOR(nereids_id=137. table_name=events(events))(id=0): + CommonCounters: + - BlocksProduced: 1 + - ExecTime: 214.858us + - MemoryUsage: 6.00 KB + - MemoryUsagePeak: 6.00 KB + - RowsProduced: 261 + - WaitForDependency[OLAP_SCAN_OPERATOR_DEPENDENCY]Time: 89.854us + CustomCounters: + - TopNFilterSourceNodeIds: + - PushDownPredicates: [] + - KeyRanges: ScanKeys: + - TabletIds: [1778469329807] + - RuntimeFilterInfo: + - ScanBytes: 1.09 KB + - ScanRows: 261 + Scanner: + - ReadColumns: [event_type] + - PerScannerRunningTime: [9.540us, ] + - PerScannerRowsRead: [261, ] + - PerScannerWaitTime: [3.730us, ] + - PerScannerProjectionTime: [4.240us, ] + - EOS: True + SegmentIterator: + - FileCache: 0ns + - BytesScannedFromCache: 186.00 B + - BytesScannedFromPeer: 0.00 + - BytesScannedFromRemote: 0.00 + - BytesWriteIntoCache: 0.00 + - CacheGetOrSetTimer: 4.410us + - GetTimer: 2.210us + - InvertedIndexBytesScannedFromCache: 0.00 + - InvertedIndexBytesScannedFromPeer: 0.00 + - InvertedIndexBytesScannedFromRemote: 0.00 + - InvertedIndexIOTimer: 0ns + - InvertedIndexLocalIOUseTimer: 0ns + - InvertedIndexNumLocalIOTotal: 0 + - InvertedIndexNumPeerIOTotal: 0 + - InvertedIndexNumRemoteIOTotal: 0 + - InvertedIndexPeerIOUseTimer: 0ns + - InvertedIndexRemoteIOUseTimer: 0ns + - LocalIOUseTimer: 5.370us + - LockWaitTimer: 70ns + - NumLocalIOTotal: 2 + - NumPeerIOTotal: 0 + - NumRemoteIOTotal: 0 + - NumSkipCacheIOTotal: 0 + - PeerIOUseTimer: 0ns + - ReadCacheFileDirectlyTimer: 0ns + - RemoteIOUseTimer: 0ns + - SetTimer: 110ns + - WaitOtherDownloaderTimer: 0ns + - WriteCacheIOUseTimer: 0ns + IndexFilter: + PipelineTask(index=3): + - TaskState: FINALIZED + - BlockedByDependency: + - WakeUpEarly: 0 + - WaitWorkerTime: 16.41us + DATA_STREAM_SINK_OPERATOR(dest_id=2): + CommonCounters: + - ExecTime: 46.52us + - InputRows: 4 + - MemoryUsage: 0.00 + - MemoryUsagePeak: 768.00 B + - WaitForDependencyTime: 0ns + - WaitForRpcBufferQueue: 0ns + CustomCounters: + - Partitioner: Crc32HashPartitioner(8) + - BlocksProduced: 8 + - OverallThroughput: 0.0 /sec + STREAMING_AGGREGATION_OPERATOR(nereids_id=145)(id=1): + CommonCounters: + - BlocksProduced: 1 + - ExecTime: 38.392us + - MemoryUsage: 426.28 KB + - MemoryUsagePeak: 426.28 KB + - RowsProduced: 4 + CustomCounters: + - MemoryUsageHashTable: 22.28 KB + - MemoryUsageSerializeKeyArena: 404.00 KB + - MemoryUsageSerializeKeyArenaPeak: 404.00 KB + OLAP_SCAN_OPERATOR(nereids_id=137. table_name=events(events))(id=0): + CommonCounters: + - BlocksProduced: 1 + - ExecTime: 239.108us + - MemoryUsage: 6.00 KB + - MemoryUsagePeak: 6.00 KB + - RowsProduced: 263 + - WaitForDependency[OLAP_SCAN_OPERATOR_DEPENDENCY]Time: 92.344us + CustomCounters: + - TopNFilterSourceNodeIds: + - PushDownPredicates: [] + - KeyRanges: ScanKeys: + - TabletIds: [1778469329809] + - RuntimeFilterInfo: + - ScanBytes: 1.09 KB + - ScanRows: 263 + Scanner: + - ReadColumns: [event_type] + - PerScannerRunningTime: [6.950us, ] + - PerScannerRowsRead: [263, ] + - PerScannerWaitTime: [7.290us, ] + - PerScannerProjectionTime: [2.650us, ] + - EOS: True + SegmentIterator: + - FileCache: 0ns + - BytesScannedFromCache: 186.00 B + - BytesScannedFromPeer: 0.00 + - BytesScannedFromRemote: 0.00 + - BytesWriteIntoCache: 0.00 + - CacheGetOrSetTimer: 4.260us + - GetTimer: 1.950us + - InvertedIndexBytesScannedFromCache: 0.00 + - InvertedIndexBytesScannedFromPeer: 0.00 + - InvertedIndexBytesScannedFromRemote: 0.00 + - InvertedIndexIOTimer: 0ns + - InvertedIndexLocalIOUseTimer: 0ns + - InvertedIndexNumLocalIOTotal: 0 + - InvertedIndexNumPeerIOTotal: 0 + - InvertedIndexNumRemoteIOTotal: 0 + - InvertedIndexPeerIOUseTimer: 0ns + - InvertedIndexRemoteIOUseTimer: 0ns + - LocalIOUseTimer: 5.151us + - LockWaitTimer: 110ns + - NumLocalIOTotal: 2 + - NumPeerIOTotal: 0 + - NumRemoteIOTotal: 0 + - NumSkipCacheIOTotal: 0 + - PeerIOUseTimer: 0ns + - ReadCacheFileDirectlyTimer: 0ns + - RemoteIOUseTimer: 0ns + - SetTimer: 110ns + - WaitOtherDownloaderTimer: 0ns + - WriteCacheIOUseTimer: 0ns + IndexFilter: + PipelineTask(index=4): + - TaskState: FINALIZED + - BlockedByDependency: + - WakeUpEarly: 0 + - WaitWorkerTime: 4.910us + DATA_STREAM_SINK_OPERATOR(dest_id=2): + CommonCounters: + - ExecTime: 67.531us + - InputRows: 4 + - MemoryUsage: 0.00 + - MemoryUsagePeak: 768.00 B + - WaitForDependencyTime: 0ns + - WaitForRpcBufferQueue: 0ns + CustomCounters: + - Partitioner: Crc32HashPartitioner(8) + - BlocksProduced: 8 + - OverallThroughput: 0.0 /sec + STREAMING_AGGREGATION_OPERATOR(nereids_id=145)(id=1): + CommonCounters: + - BlocksProduced: 1 + - ExecTime: 56.321us + - MemoryUsage: 426.28 KB + - MemoryUsagePeak: 426.28 KB + - RowsProduced: 4 + CustomCounters: + - MemoryUsageHashTable: 22.28 KB + - MemoryUsageSerializeKeyArena: 404.00 KB + - MemoryUsageSerializeKeyArenaPeak: 404.00 KB + OLAP_SCAN_OPERATOR(nereids_id=137. table_name=events(events))(id=0): + CommonCounters: + - BlocksProduced: 1 + - ExecTime: 215.830us + - MemoryUsage: 4.00 KB + - MemoryUsagePeak: 4.00 KB + - RowsProduced: 234 + - WaitForDependency[OLAP_SCAN_OPERATOR_DEPENDENCY]Time: 96.234us + CustomCounters: + - TopNFilterSourceNodeIds: + - PushDownPredicates: [] + - KeyRanges: ScanKeys: + - TabletIds: [1778469329811] + - RuntimeFilterInfo: + - ScanBytes: 1023.00 B + - ScanRows: 234 + Scanner: + - ReadColumns: [event_type] + - PerScannerRunningTime: [9.030us, ] + - PerScannerRowsRead: [234, ] + - PerScannerWaitTime: [5.180us, ] + - PerScannerProjectionTime: [3.770us, ] + - EOS: True + SegmentIterator: + - FileCache: 0ns + - BytesScannedFromCache: 179.00 B + - BytesScannedFromPeer: 0.00 + - BytesScannedFromRemote: 0.00 + - BytesWriteIntoCache: 0.00 + - CacheGetOrSetTimer: 3.400us + - GetTimer: 1.740us + - InvertedIndexBytesScannedFromCache: 0.00 + - InvertedIndexBytesScannedFromPeer: 0.00 + - InvertedIndexBytesScannedFromRemote: 0.00 + - InvertedIndexIOTimer: 0ns + - InvertedIndexLocalIOUseTimer: 0ns + - InvertedIndexNumLocalIOTotal: 0 + - InvertedIndexNumPeerIOTotal: 0 + - InvertedIndexNumRemoteIOTotal: 0 + - InvertedIndexPeerIOUseTimer: 0ns + - InvertedIndexRemoteIOUseTimer: 0ns + - LocalIOUseTimer: 5.550us + - LockWaitTimer: 200ns + - NumLocalIOTotal: 2 + - NumPeerIOTotal: 0 + - NumRemoteIOTotal: 0 + - NumSkipCacheIOTotal: 0 + - PeerIOUseTimer: 0ns + - ReadCacheFileDirectlyTimer: 0ns + - RemoteIOUseTimer: 0ns + - SetTimer: 80ns + - WaitOtherDownloaderTimer: 0ns + - WriteCacheIOUseTimer: 0ns + IndexFilter: + PipelineTask(index=5): + - TaskState: FINALIZED + - BlockedByDependency: + - WakeUpEarly: 0 + - WaitWorkerTime: 13.472us + DATA_STREAM_SINK_OPERATOR(dest_id=2): + CommonCounters: + - ExecTime: 60.972us + - InputRows: 4 + - MemoryUsage: 0.00 + - MemoryUsagePeak: 768.00 B + - WaitForDependencyTime: 0ns + - WaitForRpcBufferQueue: 0ns + CustomCounters: + - Partitioner: Crc32HashPartitioner(8) + - BlocksProduced: 8 + - OverallThroughput: 0.0 /sec + STREAMING_AGGREGATION_OPERATOR(nereids_id=145)(id=1): + CommonCounters: + - BlocksProduced: 1 + - ExecTime: 36.101us + - MemoryUsage: 426.28 KB + - MemoryUsagePeak: 426.28 KB + - RowsProduced: 4 + CustomCounters: + - MemoryUsageHashTable: 22.28 KB + - MemoryUsageSerializeKeyArena: 404.00 KB + - MemoryUsageSerializeKeyArenaPeak: 404.00 KB + OLAP_SCAN_OPERATOR(nereids_id=137. table_name=events(events))(id=0): + CommonCounters: + - BlocksProduced: 1 + - ExecTime: 249.958us + - MemoryUsage: 4.00 KB + - MemoryUsagePeak: 4.00 KB + - RowsProduced: 236 + - WaitForDependency[OLAP_SCAN_OPERATOR_DEPENDENCY]Time: 130.54us + CustomCounters: + - TopNFilterSourceNodeIds: + - PushDownPredicates: [] + - KeyRanges: ScanKeys: + - TabletIds: [1778469329813] + - RuntimeFilterInfo: + - ScanBytes: 1023.00 B + - ScanRows: 236 + Scanner: + - ReadColumns: [event_type] + - PerScannerRunningTime: [7.351us, ] + - PerScannerRowsRead: [236, ] + - PerScannerWaitTime: [4.230us, ] + - PerScannerProjectionTime: [2.851us, ] + - EOS: True + SegmentIterator: + - FileCache: 0ns + - BytesScannedFromCache: 179.00 B + - BytesScannedFromPeer: 0.00 + - BytesScannedFromRemote: 0.00 + - BytesWriteIntoCache: 0.00 + - CacheGetOrSetTimer: 41.21us + - GetTimer: 38.891us + - InvertedIndexBytesScannedFromCache: 0.00 + - InvertedIndexBytesScannedFromPeer: 0.00 + - InvertedIndexBytesScannedFromRemote: 0.00 + - InvertedIndexIOTimer: 0ns + - InvertedIndexLocalIOUseTimer: 0ns + - InvertedIndexNumLocalIOTotal: 0 + - InvertedIndexNumPeerIOTotal: 0 + - InvertedIndexNumRemoteIOTotal: 0 + - InvertedIndexPeerIOUseTimer: 0ns + - InvertedIndexRemoteIOUseTimer: 0ns + - LocalIOUseTimer: 5.431us + - LockWaitTimer: 90ns + - NumLocalIOTotal: 2 + - NumPeerIOTotal: 0 + - NumRemoteIOTotal: 0 + - NumSkipCacheIOTotal: 0 + - PeerIOUseTimer: 0ns + - ReadCacheFileDirectlyTimer: 0ns + - RemoteIOUseTimer: 0ns + - SetTimer: 110ns + - WaitOtherDownloaderTimer: 0ns + - WriteCacheIOUseTimer: 0ns + IndexFilter: + PipelineTask(index=6): + - TaskState: FINALIZED + - BlockedByDependency: + - WakeUpEarly: 0 + - WaitWorkerTime: 8.451us + DATA_STREAM_SINK_OPERATOR(dest_id=2): + CommonCounters: + - ExecTime: 50.251us + - InputRows: 4 + - MemoryUsage: 0.00 + - MemoryUsagePeak: 768.00 B + - WaitForDependencyTime: 0ns + - WaitForRpcBufferQueue: 0ns + CustomCounters: + - Partitioner: Crc32HashPartitioner(8) + - BlocksProduced: 8 + - OverallThroughput: 0.0 /sec + STREAMING_AGGREGATION_OPERATOR(nereids_id=145)(id=1): + CommonCounters: + - BlocksProduced: 1 + - ExecTime: 38.162us + - MemoryUsage: 426.28 KB + - MemoryUsagePeak: 426.28 KB + - RowsProduced: 4 + CustomCounters: + - MemoryUsageHashTable: 22.28 KB + - MemoryUsageSerializeKeyArena: 404.00 KB + - MemoryUsageSerializeKeyArenaPeak: 404.00 KB + OLAP_SCAN_OPERATOR(nereids_id=137. table_name=events(events))(id=0): + CommonCounters: + - BlocksProduced: 1 + - ExecTime: 256.340us + - MemoryUsage: 4.00 KB + - MemoryUsagePeak: 4.00 KB + - RowsProduced: 239 + - WaitForDependency[OLAP_SCAN_OPERATOR_DEPENDENCY]Time: 138.716us + CustomCounters: + - TopNFilterSourceNodeIds: + - PushDownPredicates: [] + - KeyRanges: ScanKeys: + - TabletIds: [1778469329815] + - RuntimeFilterInfo: + - ScanBytes: 1023.00 B + - ScanRows: 239 + Scanner: + - ReadColumns: [event_type] + - PerScannerRunningTime: [7.240us, ] + - PerScannerRowsRead: [239, ] + - PerScannerWaitTime: [4.700us, ] + - PerScannerProjectionTime: [2.750us, ] + - EOS: True + SegmentIterator: + - FileCache: 0ns + - BytesScannedFromCache: 179.00 B + - BytesScannedFromPeer: 0.00 + - BytesScannedFromRemote: 0.00 + - BytesWriteIntoCache: 0.00 + - CacheGetOrSetTimer: 55.172us + - GetTimer: 52.572us + - InvertedIndexBytesScannedFromCache: 0.00 + - InvertedIndexBytesScannedFromPeer: 0.00 + - InvertedIndexBytesScannedFromRemote: 0.00 + - InvertedIndexIOTimer: 0ns + - InvertedIndexLocalIOUseTimer: 0ns + - InvertedIndexNumLocalIOTotal: 0 + - InvertedIndexNumPeerIOTotal: 0 + - InvertedIndexNumRemoteIOTotal: 0 + - InvertedIndexPeerIOUseTimer: 0ns + - InvertedIndexRemoteIOUseTimer: 0ns + - LocalIOUseTimer: 3.920us + - LockWaitTimer: 90ns + - NumLocalIOTotal: 2 + - NumPeerIOTotal: 0 + - NumRemoteIOTotal: 0 + - NumSkipCacheIOTotal: 0 + - PeerIOUseTimer: 0ns + - ReadCacheFileDirectlyTimer: 0ns + - RemoteIOUseTimer: 0ns + - SetTimer: 70ns + - WaitOtherDownloaderTimer: 0ns + - WriteCacheIOUseTimer: 0ns + IndexFilter: + PipelineTask(index=7): + - TaskState: FINALIZED + - BlockedByDependency: + - WakeUpEarly: 0 + - WaitWorkerTime: 14.991us + DATA_STREAM_SINK_OPERATOR(dest_id=2): + CommonCounters: + - ExecTime: 57.712us + - InputRows: 4 + - MemoryUsage: 0.00 + - MemoryUsagePeak: 768.00 B + - WaitForDependencyTime: 0ns + - WaitForRpcBufferQueue: 0ns + CustomCounters: + - Partitioner: Crc32HashPartitioner(8) + - BlocksProduced: 8 + - OverallThroughput: 0.0 /sec + STREAMING_AGGREGATION_OPERATOR(nereids_id=145)(id=1): + CommonCounters: + - BlocksProduced: 1 + - ExecTime: 43.330us + - MemoryUsage: 426.28 KB + - MemoryUsagePeak: 426.28 KB + - RowsProduced: 4 + CustomCounters: + - MemoryUsageHashTable: 22.28 KB + - MemoryUsageSerializeKeyArena: 404.00 KB + - MemoryUsageSerializeKeyArenaPeak: 404.00 KB + OLAP_SCAN_OPERATOR(nereids_id=137. table_name=events(events))(id=0): + CommonCounters: + - BlocksProduced: 1 + - ExecTime: 225.379us + - MemoryUsage: 4.00 KB + - MemoryUsagePeak: 4.00 KB + - RowsProduced: 237 + - WaitForDependency[OLAP_SCAN_OPERATOR_DEPENDENCY]Time: 88.224us + CustomCounters: + - TopNFilterSourceNodeIds: + - PushDownPredicates: [] + - KeyRanges: ScanKeys: + - TabletIds: [1778469329817] + - RuntimeFilterInfo: + - ScanBytes: 1023.00 B + - ScanRows: 237 + Scanner: + - ReadColumns: [event_type] + - PerScannerRunningTime: [11.510us, ] + - PerScannerRowsRead: [237, ] + - PerScannerWaitTime: [4.310us, ] + - PerScannerProjectionTime: [3.190us, ] + - EOS: True + SegmentIterator: + - FileCache: 0ns + - BytesScannedFromCache: 179.00 B + - BytesScannedFromPeer: 0.00 + - BytesScannedFromRemote: 0.00 + - BytesWriteIntoCache: 0.00 + - CacheGetOrSetTimer: 6.1us + - GetTimer: 1.790us + - InvertedIndexBytesScannedFromCache: 0.00 + - InvertedIndexBytesScannedFromPeer: 0.00 + - InvertedIndexBytesScannedFromRemote: 0.00 + - InvertedIndexIOTimer: 0ns + - InvertedIndexLocalIOUseTimer: 0ns + - InvertedIndexNumLocalIOTotal: 0 + - InvertedIndexNumPeerIOTotal: 0 + - InvertedIndexNumRemoteIOTotal: 0 + - InvertedIndexPeerIOUseTimer: 0ns + - InvertedIndexRemoteIOUseTimer: 0ns + - LocalIOUseTimer: 4.790us + - LockWaitTimer: 2.120us + - NumLocalIOTotal: 2 + - NumPeerIOTotal: 0 + - NumRemoteIOTotal: 0 + - NumSkipCacheIOTotal: 0 + - PeerIOUseTimer: 0ns + - ReadCacheFileDirectlyTimer: 0ns + - RemoteIOUseTimer: 0ns + - SetTimer: 100ns + - WaitOtherDownloaderTimer: 0ns + - WriteCacheIOUseTimer: 0ns + IndexFilter: + LoadChannels: + +Appendix: + +PhysicalPlan: +PhysicalResultSink[169] ( outputExprs=[event_type#2, c#5] ) + +--PhysicalQuickSort[165]@3 ( stats=4 actualRows=4, orderKeys=[c#5 desc], phase=MERGE_SORT ) + +--PhysicalDistribute[161]@5 ( stats=4 actualRows=4, distributionSpec=DistributionSpecGather ) + +--PhysicalQuickSort[157]@5 ( stats=4 actualRows=4, orderKeys=[c#5 desc], phase=LOCAL_SORT ) + +--PhysicalHashAggregate[153]@2 ( stats=4 actualRows=4, aggPhase=GLOBAL, aggMode=BUFFER_TO_RESULT, maybeUseStreaming=false, groupByExpr=[event_type#2], outputExpr=[event_type#2, count(partial_count(*)#6) AS `c`#5], partitionExpr=Optional.empty, topnFilter=false, topnPushDown=false ) + +--PhysicalDistribute[149]@6 ( stats=4 actualRows=32, distributionSpec=DistributionSpecHash ( orderedShuffledColumns=[2], shuffleType=EXECUTION_BUCKETED, tableId=-1, selectedIndexId=-1, partitionIds=[], equivalenceExprIds=[[2]], exprIdToEquivalenceSet={2=0} ) ) + +--PhysicalHashAggregate[145]@6 ( stats=4 actualRows=32, aggPhase=LOCAL, aggMode=INPUT_TO_BUFFER, maybeUseStreaming=true, groupByExpr=[event_type#2], outputExpr=[event_type#2, partial_count(*) AS `partial_count(*)`#6], partitionExpr=Optional.empty, topnFilter=false, topnPushDown=false ) + +--PhysicalProject[141]@1 ( stats=2,000, projects=[event_type#2] ) + +--PhysicalOlapScan[events]@0 ( stats=2,000 actualRows=2000, operativeSlots=[event_type#2], virtualColumns=[] ) + PhysicalOlapScan[events]@0 ( stats=2,000 actualRows=2000, operativeSlots=[event_type#2], virtualColumns=[] ) + event_date#0 -> ndv=59.0000, min=20240101000000.000000(2024-01-01), max=20240228000000.000000(2024-02-28), count=2000.0000, numNulls=0.0000, avgSizeByte=4.000000, hotValues=(null) + user_id#1 -> ndv=986.0000, min=0.000000(0), max=999.000000(999), count=2000.0000, numNulls=0.0000, avgSizeByte=8.000000, hotValues=(null) + event_type#2 -> ndv=4.0000, min=27985222589677568.000000(click), max=33329931760959488.000000(view), count=2000.0000, numNulls=0.0000, avgSizeByte=5.750000, hotValues=(null) + amount#3 -> ndv=100.0000, min=0.500000(0.50), max=99.500000(99.50), count=2000.0000, numNulls=0.0000, avgSizeByte=8.000000, hotValues=(null) + detail#4 -> ndv=2000.0000, min=28259048195976288.000000(detail_0), max=28259048195976288.000000(detail_999), count=2000.0000, numNulls=0.0000, avgSizeByte=10.445000, hotValues=(null) + diff --git a/tests/e2e/lib.sh b/tests/e2e/lib.sh index 7043a64..634c33a 100644 --- a/tests/e2e/lib.sh +++ b/tests/e2e/lib.sh @@ -137,6 +137,21 @@ expect_json() { record_pass "$name" } +# expect_parsed "<name>" [jq-args...] '<filter>' +# Assert a jq filter against the LAST captured $OUT (from a prior _run_dcli), +# WITHOUT re-running the command. The profile suite fetches one real profile and +# then makes many assertions on it; re-running per assertion would re-hit the FE +# and risk the profile being evicted mid-suite. Extra jq args (e.g. +# `--arg q "$qid"`) may precede the filter. Records exactly one PASS or FAIL. +expect_parsed() { + local name="$1"; shift + if printf '%s' "$OUT" | jq -e "$@" >/dev/null 2>&1; then + record_pass "$name" + else + record_fail "$name" "assertion failed [ $* ]; got: $(_oneline "$OUT")" + fi +} + # expect_ok "<name>" <doriscli args...> — just requires exit 0 (raw, no --format). expect_ok() { local name="$1"; shift @@ -180,6 +195,19 @@ skip() { record_skip "$1" "$2"; } # jget '<jq filter>' — echo a scalar pulled from the last OUT (raw -r). Empty on error. jget() { printf '%s' "$OUT" | jq -r "$1" 2>/dev/null; } +# _capture_profile_fixture — persist the current `profile get --raw` $OUT (a JSON +# string holding the raw profile text) as the offline parser regression fixture. +# Doing it from a live run means the fixture is always a REAL Doris profile. +# Committing the generated file activates the cargo test in +# src/parser/profile_parser.rs (which is a visible no-op until the file exists). +_capture_profile_fixture() { + local dir="$REPO_ROOT/tests/e2e/fixtures" + mkdir -p "$dir" 2>/dev/null || return 0 + if printf '%s' "$OUT" | jq -r . > "$dir/sample_profile.txt" 2>/dev/null; then + log " ${C_DIM}captured real profile -> tests/e2e/fixtures/sample_profile.txt (commit it to activate the offline parser regression test)${C_RESET}" + fi +} + # ---- final summary ------------------------------------------------------- print_summary() { local total=$((N_PASS + N_FAIL + N_SKIP)) diff --git a/tests/e2e/suite_profile.sh b/tests/e2e/suite_profile.sh index a9cd716..17c8da9 100644 --- a/tests/e2e/suite_profile.sh +++ b/tests/e2e/suite_profile.sh @@ -1,34 +1,54 @@ # shellcheck shell=bash -# suite_profile — query profile analysis. +# suite_profile — query profile analysis, tested against REAL profiles. +# +# Philosophy: send real SQL, fetch the REAL profile over the FE HTTP API, and +# assert on the PARSED VALUES — not just the JSON shape. The full profile text is +# available ONLY over HTTP (see fetch.rs: REST v2 / legacy; the SQL path yields +# summary metadata with no operators). So the FE HTTP profile API is a HARD +# requirement here: if it is unreachable the parser surface cannot be exercised +# at all, and we FAIL loudly rather than SKIP — a silent skip behind a green run +# would hide the entire parser. # # Dependency map (from the source): -# profile list / list --active MySQL only (always testable) -# profile get <id> (summary) HTTP, with SQL fallback (testable if --profile worked) -# profile get --full / --raw HTTP profile fetch ONLY -> SKIP if HTTP_OK=0 -# profile diff HTTP profile fetch ONLY -> SKIP if HTTP_OK=0 -# profile history __internal_schema.audit_log -> SKIP if absent +# profile list / list --active MySQL only (always testable) +# profile get <id> (summary) HTTP profile text -> parsed (FAIL if HTTP down) +# profile get --full / --raw HTTP profile text -> parsed (FAIL if HTTP down) +# profile diff HTTP profile text -> parsed (FAIL if HTTP down) +# profile history __internal_schema.audit_log (SKIP if absent) +# +# A profile that was evicted before we could fetch it (FE retains a limited +# number) is a cluster precondition, not a parser bug -> SKIP, distinguished from +# HTTP-down (FAIL) and from a genuinely wrong parse (FAIL). # # HTTP_OK is set in preflight from `auth status`.http_status. suite_profile() { - suite_banner "profile (list / get / full / raw / diff / history)" + suite_banner "profile (real-profile parse: list / get / full / raw / diff / history)" DCLI_STATELESS=1 - # Generate two profiled queries and capture their ids. - DCLI_STATELESS=1 _run_dcli --format json sql \ - "SELECT event_type, COUNT(*) AS c FROM \`$CFG_DB\`.events GROUP BY event_type ORDER BY c DESC" --profile + # ── Generate REAL profiled queries and capture their ids ──────────────── + # A, A2: the SAME group-by over seeded `events`, run twice. A drives the + # get/full/raw value assertions; (A, A2) drive diff (same operators match). + # J: a hash join events⨝dim_users, to exercise join-operator + multi-scan. + local gb_sql="SELECT event_type, COUNT(*) AS c FROM \`$CFG_DB\`.events GROUP BY event_type ORDER BY c DESC" + local join_sql="SELECT e.event_type, COUNT(u.name) AS c FROM \`$CFG_DB\`.events e JOIN \`$CFG_DB\`.dim_users u ON e.user_id = u.user_id GROUP BY e.event_type" + + DCLI_STATELESS=1 _run_dcli --format json sql "$gb_sql" --profile local qid_a; qid_a="$(jget '.query_id')" - DCLI_STATELESS=1 _run_dcli --format json sql \ - "SELECT user_id, SUM(amount) AS s FROM \`$CFG_DB\`.events GROUP BY user_id ORDER BY s DESC LIMIT 10" --profile - local qid_b; qid_b="$(jget '.query_id')" - log " ${C_DIM}profiled query ids: A=$qid_a B=$qid_b (HTTP_OK=$HTTP_OK)${C_RESET}" + DCLI_STATELESS=1 _run_dcli --format json sql "$gb_sql" --profile --no-cache + local qid_a2; qid_a2="$(jget '.query_id')" + DCLI_STATELESS=1 _run_dcli --format json sql "$join_sql" --profile + local qid_j; qid_j="$(jget '.query_id')" + log " ${C_DIM}profiled ids: A=$qid_a A2=$qid_a2 JOIN=$qid_j (HTTP_OK=$HTTP_OK)${C_RESET}" - # profile list -> JSON array. + # ── profile list -> JSON array carrying the real SHOW QUERY PROFILE fields ─ DCLI_STATELESS=1 _run_dcli --format json profile list if [ "$RC" -ne 0 ]; then record_fail "profile: list returns an array" "exit=$RC; $ERR" elif printf '%s' "$OUT" | jq -e 'type=="array"' >/dev/null 2>&1; then record_pass "profile: list returns an array" + expect_parsed "profile: list entries carry query_id/sql/total_time/state" \ + 'length==0 or (.[0]|has("query_id") and has("sql") and has("total_time") and has("state"))' if [ -n "$qid_a" ] && printf '%s' "$OUT" | jq -e --arg q "$qid_a" 'any(.[]?; .query_id==$q)' >/dev/null 2>&1; then record_pass "profile: list includes the just-profiled query" else @@ -42,41 +62,128 @@ suite_profile() { expect_json "profile: list --active returns an array" 'type=="array"' \ profile list --active + # ── HARD GATE: real profile parsing needs the FE HTTP profile API ─────── + if [ "$HTTP_OK" != "1" ]; then + record_fail "profile: FE HTTP profile API reachable (required to fetch real profiles)" \ + "http_status != connected — cannot fetch profile text to parse. Cloud deployments use --http-port 8080; self-hosted Doris uses 8030. Run 'doriscli auth status' to verify." + fi + if [ -z "$qid_a" ]; then - skip "profile: get <id> summary" "no query_id captured (--profile produced none)" - skip "profile: get --full" "no query_id captured" - skip "profile: get --raw" "no query_id captured" - skip "profile: diff slow vs fast" "no query_id captured" + record_fail "profile: 'sql --profile' produced a query_id to fetch" \ + "no query_id returned; cannot exercise the parser" + elif [ "$HTTP_OK" != "1" ]; then + record_fail "profile: get parses the real profile (BLOCKED)" \ + "FE HTTP profile API unreachable — see the gate failure above" else - # Default get: summary object. Works even without HTTP via the SQL fallback. - expect_json "profile: get <id> returns a summary" \ - '(.summary|type=="object") and (.summary|has("query_id"))' \ - profile get "$qid_a" - - # --full and --raw require the FE HTTP profile API. - if [ "$HTTP_OK" = "1" ]; then - expect_json "profile: get --full returns the parsed tree" \ - '(.profile|type=="object") and (.operators|type=="array")' \ - profile get "$qid_a" --full - expect_json "profile: get --raw returns the raw profile text" \ - 'type=="string" and (contains("Summary"))' \ - profile get "$qid_a" --raw + # ── Default get: parse the REAL profile, assert VALUES ──────────────── + DCLI_STATELESS=1 _run_dcli --format json profile get "$qid_a" + if [ "$RC" -ne 0 ]; then + record_fail "profile: get parses the real profile" "exit=$RC; $ERR" + elif [ "$(jget '.operators|length')" = "0" ] && [ -n "$(jget '.note')" ]; then + # HTTP is up, but THIS profile wasn't fetchable (evicted/timing): the + # command fell back to the SQL summary (operators:[] + a note). That is a + # cluster-retention precondition, not a parser bug -> SKIP the parse tests. + local why; why="$(jget '.note' | cut -c1-90)" + record_skip "profile: get parses the real profile" "profile not fetchable now (fallback: $why) — evicted/timing; raise max_query_profile_num on the FEs and re-run" else - skip "profile: get --full" "FE HTTP API not reachable (http_status != connected)" - skip "profile: get --raw" "FE HTTP API not reachable (http_status != connected)" - fi + # query_id round-trips: the parsed Profile ID equals the id we asked for. + expect_parsed "profile: get -> summary.query_id matches the sent query" \ + --arg q "$qid_a" '.summary.query_id==$q' + # The parsed SQL is the group-by we sent. + expect_parsed "profile: get -> summary.sql is the real query text" \ + '(.summary.sql|type=="string") and (.summary.sql|test("event_type"))' + # total_time parsed out of the profile text as a positive number of ms. + expect_parsed "profile: get -> total_time_ms parsed as a positive number" \ + '(.summary.total_time_ms|type=="number") and (.summary.total_time_ms>0)' + # Flattened operator tree is non-empty and includes a SCAN and an AGG. + expect_parsed "profile: get -> operators include a SCAN and an AGGREGATION" \ + '(.operators|length>0) and (any(.operators[]; .name|test("SCAN"))) and (any(.operators[]; .name|test("AGG")))' + # query_stats: scanned rows ≈ what we loaded; fragment/operator counts real. + expect_parsed "profile: get -> query_stats.total_scan_rows ≈ loaded rows" \ + '(.query_stats.total_scan_rows >= ('"${ROWS:-2000}"' * 0.9 | floor)) and (.query_stats.fragment_count>=1) and (.query_stats.operator_count>0)' + # Fragment breakdown must be REAL: exactly the 3 fragments of this group-by, + # count consistent with the array, and NO empty duplicates (regression guard — + # a DetailProfile/Appendix block bleeding into MergedProfile used to fabricate + # empty fragments and inflate fragment_count). + expect_parsed "profile: get -> fragment_count is real (3, no empty duplicates)" \ + '(.query_stats.fragment_count==3) and (.query_stats.fragment_count==(.fragments|length)) and (.fragments|all(.pipelines>0 and has("id") and has("exec_time_ms") and has("instances")))' + # The Physical Plan section is extracted (regression: header is spelled + # "PhysicalPlan" without a space on some Doris versions). + expect_parsed "profile: get -> physical_plan section is extracted" \ + '(.physical_plan|type=="string") and ((.physical_plan|length)>0)' + # Changed session variables are parsed (regression: JSON-array form + the + # "ChangedSessionVariables" header spelling). A --profile run always changes + # at least enable_profile, so this is deterministically non-empty. + expect_parsed "profile: get -> changed_session_vars parsed (incl. enable_profile)" \ + '(.changed_session_vars|type=="array") and ((.changed_session_vars|length)>0) and (any(.changed_session_vars[]; .name=="enable_profile"))' + # Table attribution is Doris-4.0+ (operator header carries table_name=...). + if printf '%s' "$OUT" | jq -e 'any(.operators[]; .table != null)' >/dev/null 2>&1; then + expect_parsed "profile: get -> a scan operator names the events table" \ + 'any(.operators[]; (.table // "")|test("events"))' + else + record_skip "profile: get -> a scan operator names the events table" "operator headers carry no table_name (pre-4.0 Doris)" + fi - # diff needs both ids + HTTP. - if [ "$HTTP_OK" = "1" ] && [ -n "$qid_b" ]; then - expect_json "profile: diff compares two runs" \ - '(.slow|type=="object") and (.fast|type=="object") and (.time_ratio|type=="number")' \ - profile diff "$qid_a" "$qid_b" - else - skip "profile: diff slow vs fast" "needs FE HTTP API and two query ids" + # ── --full: the complete parsed tree (fragments->pipelines->operators) ─ + DCLI_STATELESS=1 _run_dcli --format json profile get "$qid_a" --full + if [ "$RC" -ne 0 ]; then + record_fail "profile: get --full parses the full tree" "exit=$RC; $ERR" + else + expect_parsed "profile: --full -> profile.summary.query_id matches" \ + --arg q "$qid_a" '.profile.summary.query_id==$q' + expect_parsed "profile: --full -> fragments->pipelines->operators are populated" \ + '(.profile.fragments|length>0) and (.profile.fragments[0].pipelines|length>0) and (.operators|length>0)' + expect_parsed "profile: --full -> an operator exposes parsed all_counters" \ + 'any(.profile.fragments[].pipelines[].operators[]; (.all_counters|type=="object") and (.all_counters|length>0))' + fi + + # ── --raw: the raw profile text round-trips; capture it as the fixture ─ + DCLI_STATELESS=1 _run_dcli --format json profile get "$qid_a" --raw + if [ "$RC" -ne 0 ]; then + record_fail "profile: get --raw returns the raw profile text" "exit=$RC; $ERR" + elif printf '%s' "$OUT" | jq -e 'type=="string" and test("Summary") and test("MergedProfile")' >/dev/null 2>&1; then + record_pass "profile: get --raw returns the raw profile text" + _capture_profile_fixture + else + record_fail "profile: get --raw returns the raw profile text" "not a profile text: $(_oneline "$OUT")" + fi + + # ── JOIN query: a hash join + both tables scanned ───────────────────── + if [ -z "$qid_j" ]; then + record_fail "profile: join query produced a query_id" "join --profile returned no query_id" + else + DCLI_STATELESS=1 _run_dcli --format json profile get "$qid_j" + if [ "$RC" -ne 0 ]; then + record_fail "profile: get(join) parses the join profile" "exit=$RC; $ERR" + elif [ "$(jget '.operators|length')" = "0" ] && [ -n "$(jget '.note')" ]; then + record_skip "profile: get(join) parses the join profile" "join profile not fetchable now (evicted/timing)" + else + expect_parsed "profile: join -> a JOIN operator is parsed" \ + 'any(.operators[]; .name|test("JOIN"))' + expect_parsed "profile: join -> both tables are scanned (>=2 SCAN operators)" \ + '([.operators[] | select(.name|test("SCAN"))] | length) >= 2' + fi + fi + + # ── diff: two REAL runs of the same query ───────────────────────────── + if [ -z "$qid_a2" ]; then + record_fail "profile: second run produced a query_id for diff" "no qid_a2" + else + DCLI_STATELESS=1 _run_dcli --format json profile diff "$qid_a" "$qid_a2" + if [ "$RC" -ne 0 ]; then + record_fail "profile: diff compares two real runs" "exit=$RC; $ERR" + else + expect_parsed "profile: diff -> slow/fast carry parsed totals + numeric time_ratio" \ + --arg s "$qid_a" --arg f "$qid_a2" \ + '(.slow.query_id==$s) and (.fast.query_id==$f) and (.slow.operator_count>0) and (.fast.operator_count>0) and (.time_ratio|type=="number")' + expect_parsed "profile: diff -> operator_diffs is an array" \ + '.operator_diffs|type=="array"' + fi + fi fi fi - # profile history: depends on __internal_schema.audit_log being enabled. + # ── profile history: depends on __internal_schema.audit_log (SKIP if absent) DCLI_STATELESS=1 _run_dcli --format json profile history "events" --days 1 if [ "$RC" -ne 0 ]; then if printf '%s' "$ERR" | grep -qi "audit_log"; then diff --git a/tests/e2e/suite_sql.sh b/tests/e2e/suite_sql.sh index 8ee73a4..db00431 100644 --- a/tests/e2e/suite_sql.sh +++ b/tests/e2e/suite_sql.sh @@ -39,9 +39,10 @@ suite_sql() { '.rows_returned==1' \ sql "SELECT 1 AS one" --no-cache - # --profile: produces a non-empty query_id (reused by the profile suite). - expect_json "sql: --profile yields a query_id" \ - '(.query_id|type=="string") and ((.query_id|length)>0)' \ + # --profile: produces a real Doris query id (TUniqueId rendered as hex-hi-hex-lo, + # e.g. "a1b2c3d4...-e5f6..."), reused by the profile suite to fetch the profile. + expect_json "sql: --profile yields a real Doris query_id" \ + '(.query_id|type=="string") and (.query_id|test("^[0-9a-fA-F]+-[0-9a-fA-F]+$"))' \ sql "SELECT 2 AS two" --profile # Output formats: a TTY-style table and CSV both carry the column header. @@ -55,9 +56,10 @@ suite_sql() { '.rows_returned==0 and (.rows==[])' \ sql "SELECT table_name FROM information_schema.tables WHERE 1=0" - # End-to-end against loaded data: row count matches what setup loaded. + # End-to-end against loaded data: row count matches what setup loaded, and the + # envelope reports a real (non-negative) execution time for a query that ran. expect_json "sql: count over loaded table matches the load" \ - '.rows[0].c=='"${ROWS:-2000}" \ + '.rows[0].c=='"${ROWS:-2000}"' and (.exec_time_ms|type=="number") and (.exec_time_ms>=0)' \ sql "SELECT COUNT(*) AS c FROM \`$CFG_DB\`.events" # Error path: a bad reference exits non-zero with an "SQL error:" message. diff --git a/tests/e2e/suite_tablet.sh b/tests/e2e/suite_tablet.sh index bf4fc62..c17280b 100644 --- a/tests/e2e/suite_tablet.sh +++ b/tests/e2e/suite_tablet.sh @@ -37,14 +37,19 @@ suite_tablet() { '.model=="UNIQUE"' \ tablet "$dim" - # --detail: per-tablet + per-backend distribution. 2 partitions x 4 buckets = 8 tablets. - expect_json "tablet: --detail lists tablets and backends" \ - '(.partitions|type=="array") and (.tablets|type=="array") and ((.tablets|length)>=8) and (.backends|type=="array")' \ + # --detail: per-tablet + per-backend distribution. 2 partitions x 4 buckets = 8 + # tablets. Assert each tablet/backend row carries its real identifying fields, + # not just that the arrays exist. + expect_json "tablet: --detail lists tablets and backends with real fields" \ + '(.partitions|type=="array") and ((.tablets|length)>=8) and ((.backends|length)>=1) + and (.tablets|all(has("tablet_id") and has("backend_id") and has("partition") and has("row_count"))) + and (.backends|all(has("backend_id") and has("tablet_count")))' \ tablet "$events" --detail - # --partition narrows to one partition's 4 tablets. + # --partition narrows to one partition's 4 tablets, and every tablet returned + # is actually attributed to that partition. expect_json "tablet: --detail --partition filters to one partition" \ - '((.partitions|length)==1) and (.partitions[0].name=="p20240101") and ((.tablets|length)==4)' \ + '((.partitions|length)==1) and (.partitions[0].name=="p20240101") and ((.tablets|length)==4) and (.tablets|all(.partition=="p20240101"))' \ tablet "$events" --detail --partition p20240101 # Negative: a missing table errors (SHOW CREATE TABLE fails). --------------------------------------------------------------------- To unsubscribe, e-mail: [email protected] For additional commands, e-mail: [email protected]
