Skip to content

[feat](audit log) add queue_time_ms in audit_log - #60418

Merged
924060929 merged 2 commits into
apache:masterfrom
YangShaw:dev-queue_time_in_audit_log
Feb 24, 2026
Merged

[feat](audit log) add queue_time_ms in audit_log#60418
924060929 merged 2 commits into
apache:masterfrom
YangShaw:dev-queue_time_in_audit_log

Conversation

@YangShaw

@YangShawYangShaw commented Feb 2, 2026

Copy link
Copy Markdown
Contributor

What problem does this PR solve?

Add a queue_time_ms column to table __internal_schema.audit_log to track per-query queueing behavior and elapsed time.

Release note

None

Check List (For Author)

  • Test

    • Regression test
    • Unit Test
    • Manual test (add detailed scripts or steps below)
    • No need to test or manual test. Explain why:
      • This is a refactor/code format and no logic has been changed.
      • Previous test can cover this change.
      • No code files have been changed.
      • Other reason

  • Behavior changed:

    • No.
    • Yes.

  • Does this need documentation?

    • No.
    • Yes.

Check List (For Reviewer who merge this PR)

  • Confirm the release note
  • Confirm test cases
  • Confirm document
  • Add branch pick label

@hello-stephen

hello-stephen commented Feb 2, 2026

Copy link
Copy Markdown
Contributor

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?

@YangShawYangShaw changed the title [feat] add queue_time_ms in audit_log[feat](audit log) add queue_time_ms in audit_logFeb 2, 2026
@YangShaw

YangShaw commented Feb 2, 2026

Copy link
Copy Markdown
ContributorAuthor

run buildall

@hello-stephen

hello-stephen commented Feb 2, 2026

Copy link
Copy Markdown
Contributor

FE UT Coverage Report

Increment line coverage 91.67% (11/12) 🎉
Increment coverage report
Complete coverage report

@doris-robot

doris-robot commented Feb 2, 2026

Copy link
Copy Markdown
TPC-H: Total hot run time: 31965 ms
machine: 'aliyun_ecs.c7a.8xlarge_32C64G'
scripts: https://github.com/apache/doris/tree/master/tools/tpch-tools
Tpch sf100 test result on commit fe297b7eff1ca3c87280bcc00df05458946c2f63, data reload: false
------ Round 1 ----------------------------------
q1	17619	5366	5097	5097
q2	2023	322	192	192
q3	10224	1310	759	759
q4	10218	860	321	321
q5	7719	2185	1912	1912
q6	212	180	149	149
q7	879	746	615	615
q8	9261	1378	1159	1159
q9	5491	4833	4794	4794
q10	6863	1950	1561	1561
q11	517	315	278	278
q12	391	375	224	224
q13	17767	4003	3229	3229
q14	238	232	219	219
q15	891	827	811	811
q16	678	670	632	632
q17	637	823	480	480
q18	6799	6610	6368	6368
q19	1618	990	635	635
q20	399	359	229	229
q21	2605	2021	2017	2017
q22	361	317	284	284
Total cold run time: 103410 ms
Total hot run time: 31965 ms
----- Round 2, with runtime_filter_mode=off -----
q1	5459	5307	5326	5307
q2	268	339	268	268
q3	2197	2719	2245	2245
q4	1385	1749	1286	1286
q5	4295	4177	4287	4177
q6	220	189	142	142
q7	2453	2044	1798	1798
q8	2576	2511	2409	2409
q9	7683	7445	7609	7445
q10	2922	3001	2538	2538
q11	555	497	460	460
q12	661	728	650	650
q13	3972	4592	3697	3697
q14	287	324	305	305
q15	887	821	823	821
q16	682	867	689	689
q17	1168	1319	1360	1319
q18	8318	7827	7861	7827
q19	880	888	892	888
q20	2122	2221	1915	1915
q21	4462	4347	4033	4033
q22	583	570	500	500
Total cold run time: 54035 ms
Total hot run time: 50719 ms

@doris-robot

doris-robot commented Feb 2, 2026

Copy link
Copy Markdown
ClickBench: Total hot run time: 28.14 s
machine: 'aliyun_ecs.c7a.8xlarge_32C64G'
scripts: https://github.com/apache/doris/tree/master/tools/clickbench-tools
ClickBench test result on commit fe297b7eff1ca3c87280bcc00df05458946c2f63, data reload: false
query1	0.05	0.05	0.05
query2	0.08	0.04	0.04
query3	0.26	0.08	0.09
query4	1.60	0.10	0.10
query5	0.27	0.26	0.25
query6	1.16	0.69	0.67
query7	0.03	0.02	0.02
query8	0.06	0.04	0.05
query9	0.57	0.50	0.48
query10	0.56	0.54	0.54
query11	0.14	0.09	0.10
query12	0.14	0.10	0.11
query13	0.63	0.62	0.62
query14	1.08	1.06	1.06
query15	0.87	0.85	0.88
query16	0.39	0.40	0.39
query17	1.13	1.08	1.07
query18	0.23	0.21	0.21
query19	2.09	2.00	1.92
query20	0.02	0.01	0.02
query21	15.41	0.28	0.16
query22	5.20	0.05	0.05
query23	16.12	0.26	0.10
query24	1.78	0.26	0.58
query25	0.10	0.12	0.07
query26	0.15	0.14	0.13
query27	0.06	0.09	0.08
query28	4.69	1.13	0.97
query29	12.63	3.89	3.15
query30	0.28	0.14	0.12
query31	2.82	0.63	0.40
query32	3.24	0.60	0.49
query33	3.24	3.40	3.19
query34	16.56	5.38	4.73
query35	4.78	4.87	4.80
query36	0.65	0.51	0.49
query37	0.10	0.06	0.06
query38	0.08	0.04	0.04
query39	0.04	0.04	0.03
query40	0.19	0.16	0.15
query41	0.08	0.04	0.03
query42	0.04	0.02	0.02
query43	0.05	0.03	0.04
Total cold run time: 99.65 s
Total hot run time: 28.14 s

@YangShaw
YangShawforce-pushed the dev-queue_time_in_audit_log branch from 751d34e to 2975478CompareFebruary 2, 2026 06:49
@YangShaw

YangShaw commented Feb 2, 2026

Copy link
Copy Markdown
ContributorAuthor

run buildall

@doris-robot

doris-robot commented Feb 2, 2026

Copy link
Copy Markdown
TPC-H: Total hot run time: 32216 ms
machine: 'aliyun_ecs.c7a.8xlarge_32C64G'
scripts: https://github.com/apache/doris/tree/master/tools/tpch-tools
Tpch sf100 test result on commit 2975478725a3ab7bbc6a513986afcaedeb27de7b, data reload: false
------ Round 1 ----------------------------------
q1	17688	5352	5064	5064
q2	2036	315	196	196
q3	10199	1422	747	747
q4	10194	786	316	316
q5	7536	2171	1910	1910
q6	202	179	150	150
q7	894	751	627	627
q8	9286	1406	1082	1082
q9	5206	4935	4863	4863
q10	6782	1953	1555	1555
q11	515	309	286	286
q12	343	380	215	215
q13	17765	4120	3254	3254
q14	238	245	226	226
q15	884	812	822	812
q16	679	691	622	622
q17	646	767	507	507
q18	6767	6553	7578	6553
q19	1249	1033	632	632
q20	403	359	257	257
q21	3124	2239	2074	2074
q22	374	307	268	268
Total cold run time: 103010 ms
Total hot run time: 32216 ms
----- Round 2, with runtime_filter_mode=off -----
q1	5632	5530	5448	5448
q2	276	343	259	259
q3	2433	2834	2604	2604
q4	1408	1849	1358	1358
q5	4715	4687	4498	4498
q6	236	186	140	140
q7	2097	1928	1789	1789
q8	2534	2312	2433	2312
q9	7724	7557	7468	7468
q10	2989	3114	2603	2603
q11	544	468	452	452
q12	646	776	610	610
q13	3880	4332	3657	3657
q14	302	320	273	273
q15	869	803	802	802
q16	646	675	622	622
q17	1074	1255	1242	1242
q18	7476	7426	7285	7285
q19	826	797	788	788
q20	1977	2042	1871	1871
q21	4480	4159	4103	4103
q22	588	545	517	517
Total cold run time: 53352 ms
Total hot run time: 50701 ms

@doris-robot

doris-robot commented Feb 2, 2026

Copy link
Copy Markdown
ClickBench: Total hot run time: 28.35 s
machine: 'aliyun_ecs.c7a.8xlarge_32C64G'
scripts: https://github.com/apache/doris/tree/master/tools/clickbench-tools
ClickBench test result on commit 2975478725a3ab7bbc6a513986afcaedeb27de7b, data reload: false
query1	0.06	0.06	0.06
query2	0.11	0.05	0.04
query3	0.26	0.09	0.09
query4	1.61	0.12	0.12
query5	0.26	0.26	0.25
query6	1.17	0.69	0.67
query7	0.03	0.03	0.03
query8	0.06	0.05	0.05
query9	0.56	0.50	0.49
query10	0.54	0.54	0.56
query11	0.15	0.10	0.11
query12	0.14	0.11	0.12
query13	0.64	0.63	0.63
query14	1.06	1.05	1.06
query15	0.88	0.86	0.87
query16	0.39	0.39	0.39
query17	1.15	1.14	1.07
query18	0.23	0.21	0.21
query19	2.13	2.03	2.10
query20	0.02	0.02	0.02
query21	15.42	0.28	0.14
query22	5.36	0.06	0.06
query23	16.32	0.29	0.11
query24	0.99	0.50	0.20
query25	0.13	0.06	0.06
query26	0.14	0.13	0.14
query27	0.06	0.06	0.05
query28	3.75	1.15	0.96
query29	12.58	3.95	3.18
query30	0.32	0.16	0.14
query31	2.84	0.63	0.41
query32	3.25	0.60	0.49
query33	3.19	3.29	3.20
query34	16.40	5.38	4.75
query35	4.75	4.77	4.86
query36	0.64	0.50	0.49
query37	0.12	0.07	0.07
query38	0.07	0.04	0.04
query39	0.05	0.04	0.04
query40	0.19	0.17	0.15
query41	0.09	0.03	0.04
query42	0.05	0.04	0.03
query43	0.05	0.04	0.04
Total cold run time: 98.21 s
Total hot run time: 28.35 s

@hello-stephen

hello-stephen commented Feb 2, 2026

Copy link
Copy Markdown
Contributor

FE UT Coverage Report

Increment line coverage 91.67% (11/12) 🎉
Increment coverage report
Complete coverage report

@github-actions

github-actionsBot commented Feb 2, 2026

Copy link
Copy Markdown
Contributor

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

@github-actionsgithub-actionsBot added approved Indicates a PR has been approved by one committer. reviewed labels Feb 2, 2026
@github-actions

github-actionsBot commented Feb 2, 2026

Copy link
Copy Markdown
Contributor

PR approved by anyone and no changes requested.

@hello-stephen

hello-stephen commented Feb 2, 2026

Copy link
Copy Markdown
Contributor

FE Regression Coverage Report

Increment line coverage 100.00% (12/12) 🎉
Increment coverage report
Complete coverage report

@YangShaw

YangShaw commented Feb 4, 2026

Copy link
Copy Markdown
ContributorAuthor

run buildall

@doris-robot

doris-robot commented Feb 4, 2026

Copy link
Copy Markdown
TPC-H: Total hot run time: 32167 ms
machine: 'aliyun_ecs.c7a.8xlarge_32C64G'
scripts: https://github.com/apache/doris/tree/master/tools/tpch-tools
Tpch sf100 test result on commit 66f7ca7829b22b32d8c06ad74260cf97c5b6778d, data reload: false
------ Round 1 ----------------------------------
q1	17619	5264	5050	5050
q2	2031	301	189	189
q3	10249	1288	759	759
q4	10202	774	316	316
q5	7545	2184	1870	1870
q6	207	182	157	157
q7	872	743	626	626
q8	9255	1338	1134	1134
q9	5539	4951	4804	4804
q10	6852	1918	1566	1566
q11	524	308	282	282
q12	389	371	224	224
q13	17807	4013	3211	3211
q14	235	248	223	223
q15	903	816	825	816
q16	677	679	616	616
q17	640	795	505	505
q18	6682	6638	7491	6638
q19	1333	1003	618	618
q20	408	362	236	236
q21	2921	2268	2045	2045
q22	364	322	282	282
Total cold run time: 103254 ms
Total hot run time: 32167 ms
----- Round 2, with runtime_filter_mode=off -----
q1	5569	5479	5536	5479
q2	279	355	264	264
q3	2340	2899	2509	2509
q4	1451	1849	1413	1413
q5	5020	4584	4516	4516
q6	220	197	141	141
q7	2083	1929	1813	1813
q8	2557	2456	2315	2315
q9	7433	7507	7427	7427
q10	2771	3014	2616	2616
q11	552	520	462	462
q12	658	795	622	622
q13	3559	3967	3201	3201
q14	278	289	284	284
q15	821	795	787	787
q16	640	671	639	639
q17	1058	1266	1309	1266
q18	7560	7389	7278	7278
q19	810	800	781	781
q20	1956	2037	1899	1899
q21	4438	4159	4021	4021
q22	560	556	505	505
Total cold run time: 52613 ms
Total hot run time: 50238 ms

@doris-robot

doris-robot commented Feb 4, 2026

Copy link
Copy Markdown
ClickBench: Total hot run time: 28.44 s
machine: 'aliyun_ecs.c7a.8xlarge_32C64G'
scripts: https://github.com/apache/doris/tree/master/tools/clickbench-tools
ClickBench test result on commit 66f7ca7829b22b32d8c06ad74260cf97c5b6778d, data reload: false
query1	0.05	0.05	0.05
query2	0.10	0.04	0.04
query3	0.25	0.08	0.08
query4	1.60	0.11	0.12
query5	0.26	0.25	0.24
query6	1.16	0.68	0.67
query7	0.03	0.02	0.03
query8	0.05	0.04	0.04
query9	0.56	0.50	0.49
query10	0.55	0.57	0.55
query11	0.14	0.09	0.10
query12	0.14	0.11	0.11
query13	0.63	0.61	0.62
query14	1.06	1.06	1.05
query15	0.88	0.86	0.87
query16	0.39	0.42	0.40
query17	1.06	1.16	1.07
query18	0.23	0.22	0.21
query19	2.07	2.01	1.96
query20	0.01	0.02	0.01
query21	15.41	0.23	0.14
query22	5.13	0.05	0.05
query23	15.85	0.27	0.10
query24	1.45	0.52	1.33
query25	0.09	0.10	0.06
query26	0.15	0.13	0.13
query27	0.10	0.04	0.05
query28	5.01	1.14	0.98
query29	12.58	3.88	3.18
query30	0.28	0.14	0.12
query31	2.82	0.65	0.41
query32	3.23	0.59	0.49
query33	3.25	3.22	3.19
query34	16.42	5.39	4.74
query35	4.78	4.76	4.77
query36	0.65	0.50	0.49
query37	0.11	0.07	0.06
query38	0.07	0.04	0.03
query39	0.04	0.04	0.04
query40	0.19	0.17	0.15
query41	0.09	0.04	0.03
query42	0.05	0.03	0.03
query43	0.05	0.04	0.04
Total cold run time: 99.02 s
Total hot run time: 28.44 s

@hello-stephen

hello-stephen commented Feb 4, 2026

Copy link
Copy Markdown
Contributor

FE UT Coverage Report

Increment line coverage 91.67% (11/12) 🎉
Increment coverage report
Complete coverage report

@hello-stephen

hello-stephen commented Feb 4, 2026

Copy link
Copy Markdown
Contributor

FE Regression Coverage Report

Increment line coverage 100.00% (12/12) 🎉
Increment coverage report
Complete coverage report

@YangShaw

YangShaw commented Feb 4, 2026

Copy link
Copy Markdown
ContributorAuthor

run nonConcurrent

@hello-stephen

hello-stephen commented Feb 4, 2026

Copy link
Copy Markdown
Contributor

FE Regression Coverage Report

Increment line coverage 100.00% (12/12) 🎉
Increment coverage report
Complete coverage report

@924060929
924060929 merged commit b1fe567 into apache:masterFeb 24, 2026
28 checks passed
@bobhan1bobhan1 mentioned this pull request Aug 11, 2026
Merged
16 tasks
yiguolei pushed a commit that referenced this pull request Aug 11, 2026
@bobhan1@YangShaw
branch-4.1: [feat](audit log) add queue_time_ms in audit_log (#66641)
482d6d1
### What problem does this PR solve?
Related PR: #60418
Problem Summary:
Backport #60418 to `branch-4.1` for CIR-21335.
The audit log's `query_time` includes workload-group queue time, so
users cannot distinguish queue delay from the remaining end-to-end query
latency. This PR adds `queue_time_ms` to `__internal_schema.audit_log`
and propagates it through the audit event and loader paths.
`branch-4.1` already contained the `getQueueTimeMs()` helper, so the
conflict resolution keeps that implementation and ports the missing
schema, event, loader, call-site, unit-test, and regression-test
changes.
### Release note
Add `queue_time_ms` to `__internal_schema.audit_log`.
### Validation
- `./run-fe-ut.sh --run org.apache.doris.qe.AuditEventProcessorTest`
- `./build.sh --be --fe -j100`
- `./run-regression-test.sh --run -d regression-test/suites/audit -s
test_audit_log_queue_time`
- `git diff --check upstream/branch-4.1...HEAD`
### Check List (For Author)
- Test <!-- At least one of them must be included. -->
- [x] Regression test
- [x] Unit Test
- [ ] Manual test (add detailed scripts or steps below)
- [ ] No need to test or manual test. Explain why:
- [ ] This is a refactor/code format and no logic has been changed.
- [ ] Previous test can cover this change.
- [ ] No code files have been changed.
- [ ] Other reason <!-- Add your reason? -->
- Behavior changed:
- [x] No.
- [ ] Yes. <!-- Explain the behavior change -->
- Does this need documentation?
- [x] No.
- [ ] Yes. <!-- Add document PR link here. eg:
apache/doris-website#1214 -->
### Check List (For Reviewer who merge this PR)
- [ ] Confirm the release note
- [ ] Confirm test cases
- [ ] Confirm document
- [ ] Add branch pick label <!-- Add branch pick label that this PR
should merge into -->
Co-authored-by: Fy <fuyu0824@pku.edu.cn>
Sign up for freeto join this conversation on GitHub. Already have an account? Sign in to comment

Reviewers

@924060929924060929924060929 approved these changes
@morrySnowmorrySnowmorrySnow approved these changes

Assignees

No one assigned

Labels

approvedIndicates a PR has been approved by one committer.dev/4.1.4-mergedreviewed

Projects

None yet

Milestone

No milestone

Development

Successfully merging this pull request may close these issues.

6 participants

@YangShaw@hello-stephen@doris-robot@924060929@morrySnow@yiguolei