Skip to content

[fix](fe) Fix bugs in SummaryProfile and StmtExecutor metric reporting#61601

Merged
morningman merged 1 commit intoapache:masterfrom
morningman:fix/summary-profile-bugs
Mar 24, 2026
Merged

[fix](fe) Fix bugs in SummaryProfile and StmtExecutor metric reporting#61601
morningman merged 1 commit intoapache:masterfrom
morningman:fix/summary-profile-bugs

Conversation

@morningman
Copy link
Copy Markdown
Contributor

What problem does this PR solve?

Issue Number: close #xxx

Problem Summary:

Fix three bugs found in SummaryProfile and StmtExecutor:

  1. Wrong field assignment in addNereidsPartitiionPruneTime() (SummaryProfile.java):
    The method was incorrectly accumulating partition prune time into externalTvfInitTime
    instead of nereidsPartitiionPruneTime. This caused:

    • nereidsPartitiionPruneTime to always be 0, so HISTO_PLAN_PARTITION_PRUNE_DURATION
      metric never collected correct data
    • externalTvfInitTime to be polluted with unrelated partition prune time data
  2. Wrong guard variable for translate metric (StmtExecutor.java):
    When reporting HISTO_PLAN_TRANSLATE_DURATION, the condition checked
    nereidsOptimizeTimeMs >= 0 instead of nereidsTranslateTimeMs >= 0.
    This means the translate metric was gated by the optimize time value
    rather than the translate time value itself.

Release note

None

Check List (For Author)

  • Test: No need to test - trivial one-line bug fix with obvious correctness
  • Behavior changed: No
  • Does this need documentation: No

### What problem does this PR solve?

Issue Number: close #xxx

Problem Summary:

Fix three bugs found in SummaryProfile and StmtExecutor:

1. **Wrong field assignment in `addNereidsPartitiionPruneTime()`** (SummaryProfile.java):
   The method was incorrectly accumulating partition prune time into `externalTvfInitTime`
   instead of `nereidsPartitiionPruneTime`. This caused:
   - `nereidsPartitiionPruneTime` to always be 0, so `HISTO_PLAN_PARTITION_PRUNE_DURATION`
     metric never collected correct data
   - `externalTvfInitTime` to be polluted with unrelated partition prune time data

2. **Wrong guard variable for translate metric** (StmtExecutor.java):
   When reporting `HISTO_PLAN_TRANSLATE_DURATION`, the condition checked
   `nereidsOptimizeTimeMs >= 0` instead of `nereidsTranslateTimeMs >= 0`.
   This means the translate metric was gated by the optimize time value
   rather than the translate time value itself.

### Release note

None

### Check List (For Author)

- Test: No need to test - trivial bug fix with obvious correctness
- Behavior changed: No
- Does this need documentation: No
@Thearas
Copy link
Copy Markdown
Contributor

Thearas commented Mar 22, 2026

Thank you for your contribution to Apache Doris.
Don't know what should be done next? See How to process your PR.

Please clearly describe your PR:

  1. What problem was fixed (it's best to include specific error reporting information). How it was fixed.
  2. Which behaviors were modified. What was the previous behavior, what is it now, why was it modified, and what possible impacts might there be.
  3. What features were added. Why was this function added?
  4. Which code was refactored and why was this part of the code refactored?
  5. Which functions were optimized and what is the difference before and after the optimization?

@morningman
Copy link
Copy Markdown
Contributor Author

run buildall

@doris-robot
Copy link
Copy Markdown

TPC-H: Total hot run time: 26767 ms
machine: 'aliyun_ecs.c7a.8xlarge_32C64G'
scripts: https://github.com/apache/doris/tree/master/tools/tpch-tools
Tpch sf100 test result on commit 5ba9e70bdd6ffaef16d2296c5fc32c96c759e040, data reload: false

------ Round 1 ----------------------------------
orders	Doris	NULL	NULL	0	0	0	NULL	0	NULL	NULL	2023-12-26 18:27:23	2023-12-26 18:42:55	NULL	utf-8	NULL	NULL	
============================================
q1	17641	4537	4305	4305
q2	q3	10655	763	538	538
q4	4677	350	251	251
q5	7554	1215	1018	1018
q6	175	173	146	146
q7	766	858	670	670
q8	9531	1450	1300	1300
q9	4995	4729	4680	4680
q10	6313	1891	1653	1653
q11	470	267	247	247
q12	747	579	476	476
q13	18042	2923	2147	2147
q14	227	232	224	224
q15	q16	733	731	671	671
q17	732	827	468	468
q18	5888	5443	5280	5280
q19	1174	976	593	593
q20	546	497	385	385
q21	4509	1832	1408	1408
q22	432	481	307	307
Total cold run time: 95807 ms
Total hot run time: 26767 ms

----- Round 2, with runtime_filter_mode=off -----
orders	Doris	NULL	NULL	150000000	42	6422171781	NULL	22778155	NULL	NULL	2023-12-26 18:27:23	2023-12-26 18:42:55	NULL	utf-8	NULL	NULL	
============================================
q1	4866	4681	4695	4681
q2	q3	3870	4391	3813	3813
q4	937	1234	783	783
q5	4065	4305	4331	4305
q6	187	175	134	134
q7	1764	1678	1520	1520
q8	2501	2682	2570	2570
q9	7515	7317	7308	7308
q10	3818	3997	3620	3620
q11	502	422	424	422
q12	461	628	455	455
q13	2740	3278	2314	2314
q14	280	313	289	289
q15	q16	714	786	750	750
q17	1166	1291	1321	1291
q18	7223	6889	6706	6706
q19	849	899	902	899
q20	2022	2133	1999	1999
q21	4072	3599	3351	3351
q22	495	449	395	395
Total cold run time: 50047 ms
Total hot run time: 47605 ms

@doris-robot
Copy link
Copy Markdown

TPC-DS: Total hot run time: 168793 ms
machine: 'aliyun_ecs.c7a.8xlarge_32C64G'
scripts: https://github.com/apache/doris/tree/master/tools/tpcds-tools
TPC-DS sf100 test result on commit 5ba9e70bdd6ffaef16d2296c5fc32c96c759e040, data reload: false

query5	4326	644	507	507
query6	350	242	215	215
query7	4216	491	281	281
query8	356	254	236	236
query9	8674	2719	2751	2719
query10	534	399	347	347
query11	7037	5085	4856	4856
query12	183	132	125	125
query13	1279	476	370	370
query14	5664	3734	3446	3446
query14_1	2886	2849	2818	2818
query15	202	194	179	179
query16	1007	454	454	454
query17	897	736	630	630
query18	2471	465	354	354
query19	211	211	188	188
query20	135	128	131	128
query21	211	137	115	115
query22	13137	14011	14380	14011
query23	16066	15682	15623	15623
query23_1	15612	15880	15742	15742
query24	7171	1611	1208	1208
query24_1	1218	1220	1222	1220
query25	571	475	427	427
query26	1226	263	146	146
query27	2794	475	291	291
query28	4486	1823	1851	1823
query29	840	577	488	488
query30	329	220	187	187
query31	981	932	887	887
query32	80	68	73	68
query33	513	330	290	290
query34	907	890	556	556
query35	661	705	598	598
query36	1140	1150	995	995
query37	145	98	83	83
query38	3024	2931	2927	2927
query39	851	849	826	826
query39_1	795	792	797	792
query40	247	157	140	140
query41	63	62	58	58
query42	262	255	252	252
query43	235	252	230	230
query44	
query45	193	187	183	183
query46	880	987	594	594
query47	2119	2100	2072	2072
query48	305	310	237	237
query49	646	459	380	380
query50	680	292	212	212
query51	4079	4044	4061	4044
query52	258	262	255	255
query53	283	342	290	290
query54	297	278	276	276
query55	93	86	85	85
query56	317	344	318	318
query57	1926	1853	1756	1756
query58	288	278	266	266
query59	2741	2934	2716	2716
query60	348	335	342	335
query61	160	152	154	152
query62	619	594	546	546
query63	307	275	282	275
query64	5018	1272	993	993
query65	
query66	1465	458	356	356
query67	24264	24253	24098	24098
query68	
query69	413	313	295	295
query70	988	957	942	942
query71	345	315	307	307
query72	2831	2762	2605	2605
query73	537	557	318	318
query74	9579	9557	9415	9415
query75	2844	2730	2501	2501
query76	2278	1052	686	686
query77	373	397	330	330
query78	10913	11136	10437	10437
query79	1113	793	566	566
query80	896	667	572	572
query81	513	263	233	233
query82	1327	150	122	122
query83	356	269	251	251
query84	311	128	112	112
query85	946	500	451	451
query86	379	334	282	282
query87	3128	3100	2953	2953
query88	3547	2665	2650	2650
query89	429	366	350	350
query90	1897	182	173	173
query91	174	162	139	139
query92	83	73	68	68
query93	891	854	494	494
query94	510	316	293	293
query95	590	341	381	341
query96	643	514	231	231
query97	2552	2498	2396	2396
query98	236	219	213	213
query99	1016	975	937	937
Total cold run time: 247928 ms
Total hot run time: 168793 ms

@github-actions github-actions Bot added the approved Indicates a PR has been approved by one committer. label Mar 24, 2026
@github-actions
Copy link
Copy Markdown
Contributor

PR approved by at least one committer and no changes requested.

@github-actions
Copy link
Copy Markdown
Contributor

PR approved by anyone and no changes requested.

@morningman morningman merged commit d19cfa7 into apache:master Mar 24, 2026
36 of 38 checks passed
github-actions Bot pushed a commit that referenced this pull request Mar 24, 2026
#61601)

### What problem does this PR solve?

Issue Number: close #xxx

Problem Summary:

Fix three bugs found in SummaryProfile and StmtExecutor:

1. **Wrong field assignment in `addNereidsPartitiionPruneTime()`**
(SummaryProfile.java):
The method was incorrectly accumulating partition prune time into
`externalTvfInitTime`
   instead of `nereidsPartitiionPruneTime`. This caused:
- `nereidsPartitiionPruneTime` to always be 0, so
`HISTO_PLAN_PARTITION_PRUNE_DURATION`
     metric never collected correct data
- `externalTvfInitTime` to be polluted with unrelated partition prune
time data

2. **Wrong guard variable for translate metric** (StmtExecutor.java):
   When reporting `HISTO_PLAN_TRANSLATE_DURATION`, the condition checked
`nereidsOptimizeTimeMs >= 0` instead of `nereidsTranslateTimeMs >= 0`.
   This means the translate metric was gated by the optimize time value
   rather than the translate time value itself.
github-actions Bot pushed a commit that referenced this pull request Mar 24, 2026
#61601)

### What problem does this PR solve?

Issue Number: close #xxx

Problem Summary:

Fix three bugs found in SummaryProfile and StmtExecutor:

1. **Wrong field assignment in `addNereidsPartitiionPruneTime()`**
(SummaryProfile.java):
The method was incorrectly accumulating partition prune time into
`externalTvfInitTime`
   instead of `nereidsPartitiionPruneTime`. This caused:
- `nereidsPartitiionPruneTime` to always be 0, so
`HISTO_PLAN_PARTITION_PRUNE_DURATION`
     metric never collected correct data
- `externalTvfInitTime` to be polluted with unrelated partition prune
time data

2. **Wrong guard variable for translate metric** (StmtExecutor.java):
   When reporting `HISTO_PLAN_TRANSLATE_DURATION`, the condition checked
`nereidsOptimizeTimeMs >= 0` instead of `nereidsTranslateTimeMs >= 0`.
   This means the translate metric was gated by the optimize time value
   rather than the translate time value itself.
yiguolei pushed a commit that referenced this pull request Mar 24, 2026
…ric reporting #61601 (#61643)

Cherry-picked from #61601

Co-authored-by: Mingyu Chen (Rayner) <yunyou@selectdb.com>
yiguolei pushed a commit that referenced this pull request Mar 25, 2026
…ric reporting #61601 (#61644)

Cherry-picked from #61601

Co-authored-by: Mingyu Chen (Rayner) <yunyou@selectdb.com>
HappenLee pushed a commit to HappenLee/incubator-doris that referenced this pull request Mar 31, 2026
apache#61601)

### What problem does this PR solve?

Issue Number: close #xxx

Problem Summary:

Fix three bugs found in SummaryProfile and StmtExecutor:

1. **Wrong field assignment in `addNereidsPartitiionPruneTime()`**
(SummaryProfile.java):
The method was incorrectly accumulating partition prune time into
`externalTvfInitTime`
   instead of `nereidsPartitiionPruneTime`. This caused:
- `nereidsPartitiionPruneTime` to always be 0, so
`HISTO_PLAN_PARTITION_PRUNE_DURATION`
     metric never collected correct data
- `externalTvfInitTime` to be polluted with unrelated partition prune
time data

2. **Wrong guard variable for translate metric** (StmtExecutor.java):
   When reporting `HISTO_PLAN_TRANSLATE_DURATION`, the condition checked
`nereidsOptimizeTimeMs >= 0` instead of `nereidsTranslateTimeMs >= 0`.
   This means the translate metric was gated by the optimize time value
   rather than the translate time value itself.
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

approved Indicates a PR has been approved by one committer. dev/3.1.x dev/4.0.5-merged dev/4.1.0-merged reviewed

Projects

None yet

Development

Successfully merging this pull request may close these issues.

8 participants