Skip to content

[fix](metrics) Fix prepared statement QPS metrics not counted when audit log disabled#61621

Open
Yukang-Lian wants to merge 2 commits intoapache:masterfrom
Yukang-Lian:fix/prepared-stmt-qps-metric-missing
Open

[fix](metrics) Fix prepared statement QPS metrics not counted when audit log disabled#61621
Yukang-Lian wants to merge 2 commits intoapache:masterfrom
Yukang-Lian:fix/prepared-stmt-qps-metric-missing

Conversation

@Yukang-Lian
Copy link
Collaborator

Summary

  • When enable_prepared_stmt_audit_log = false (default), auditAfterExec() is entirely skipped for prepared statements. Since QPS metric counting (COUNTER_QUERY_ALL, COUNTER_QUERY_ERR, HISTO_QUERY_LATENCY, etc.) lives inside AuditLogHelper.logAuditLog(), these metrics are also lost for prepared statement SELECT queries.
  • Add AuditLogHelper.updateMetrics() to count metrics independently of audit log writing, and call it in the else branch when audit log is disabled.
  • This decouples the metric counting from audit log writing without modifying the existing logAuditLogImpl() logic.

Changes

  • AuditLogHelper.java: Add updateMetrics() + updateMetricsImpl() methods for standalone metric counting with enable_bdbje_debug_mode short-circuit and catch-all exception isolation (matching auditAfterExec protection semantics).
  • MysqlConnectProcessor.java: Add else branch in handleExecute() to call updateMetrics() when audit log is disabled.
  • AuditLogHelperTest.java: Unit tests covering OK query, ERR query, non-query (INSERT), and debug mode short-circuit scenarios.

Test plan

  • Unit tests pass (AuditLogHelperTest - 4 cases)
  • Existing regression tests pass (insert_group_commit_with_prepare_stmt.groovy)

🤖 Generated with Claude Code

@hello-stephen
Copy link
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?

…dit log disabled

When enable_prepared_stmt_audit_log is false (default), auditAfterExec() is
skipped entirely for prepared statements. Since QPS metric counting
(COUNTER_QUERY_ALL, COUNTER_QUERY_ERR, HISTO_QUERY_LATENCY, etc.) lives
inside auditAfterExec -> AuditLogHelper.logAuditLog(), these metrics are
also lost for prepared statement SELECT queries.

Add AuditLogHelper.updateMetrics() to count metrics independently of audit
log writing, and call it in the else branch when audit log is disabled.
@Yukang-Lian Yukang-Lian force-pushed the fix/prepared-stmt-qps-metric-missing branch from bbc8651 to a53c421 Compare March 23, 2026 07:01
…minate duplicate code

Let logAuditLogImpl() call updateMetricsImpl() for metric counting instead
of duplicating the same logic. Only audit-specific fields (setSqlDigest,
setScanBytes) remain in logAuditLogImpl.
@Yukang-Lian
Copy link
Collaborator Author

run buildall

@doris-robot
Copy link

TPC-H: Total hot run time: 26741 ms
machine: 'aliyun_ecs.c7a.8xlarge_32C64G'
scripts: https://github.com/apache/doris/tree/master/tools/tpch-tools
Tpch sf100 test result on commit bd3e53559ad06183f8221ad31eb9d1c32bd4e6e3, 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	17625	4527	4351	4351
q2	q3	10652	776	517	517
q4	4678	365	252	252
q5	7558	1203	1028	1028
q6	172	176	155	155
q7	777	850	674	674
q8	9300	1494	1336	1336
q9	4847	4719	4668	4668
q10	6295	1915	1676	1676
q11	462	267	251	251
q12	746	591	472	472
q13	18046	2894	2161	2161
q14	225	227	207	207
q15	q16	751	748	662	662
q17	734	855	423	423
q18	6149	5346	5110	5110
q19	1122	983	627	627
q20	541	485	390	390
q21	4445	1883	1454	1454
q22	444	451	327	327
Total cold run time: 95569 ms
Total hot run time: 26741 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	4802	4584	4616	4584
q2	q3	3838	4346	3777	3777
q4	890	1193	792	792
q5	4097	4402	4408	4402
q6	199	181	149	149
q7	1766	1605	1534	1534
q8	2481	2758	2646	2646
q9	7402	7514	7405	7405
q10	3838	4034	3625	3625
q11	508	424	410	410
q12	491	605	477	477
q13	2834	3203	2328	2328
q14	315	303	271	271
q15	q16	717	773	727	727
q17	1152	1325	1374	1325
q18	7233	6643	6545	6545
q19	1030	986	918	918
q20	2054	2149	2015	2015
q21	4090	3543	3368	3368
q22	441	429	376	376
Total cold run time: 50178 ms
Total hot run time: 47674 ms

@doris-robot
Copy link

TPC-DS: Total hot run time: 169386 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 bd3e53559ad06183f8221ad31eb9d1c32bd4e6e3, data reload: false

query5	4333	661	540	540
query6	334	235	233	233
query7	4220	497	282	282
query8	340	249	242	242
query9	8703	2732	2742	2732
query10	531	407	360	360
query11	7036	5182	4949	4949
query12	189	141	129	129
query13	1284	473	378	378
query14	5553	4029	3582	3582
query14_1	3123	3083	3098	3083
query15	216	216	183	183
query16	987	405	465	405
query17	985	768	639	639
query18	2443	470	367	367
query19	239	228	197	197
query20	138	136	133	133
query21	219	146	117	117
query22	13693	13427	13189	13189
query23	15898	15431	15887	15431
query23_1	15787	15965	15948	15948
query24	7438	1797	1332	1332
query24_1	1345	1296	1336	1296
query25	683	584	529	529
query26	1443	289	170	170
query27	3365	701	347	347
query28	5787	1968	2023	1968
query29	906	645	510	510
query30	306	240	203	203
query31	1071	972	883	883
query32	80	75	74	74
query33	535	353	295	295
query34	923	946	560	560
query35	710	720	638	638
query36	1129	1131	953	953
query37	140	97	84	84
query38	2943	2928	2861	2861
query39	867	846	826	826
query39_1	792	800	793	793
query40	238	162	140	140
query41	66	101	62	62
query42	272	260	262	260
query43	242	257	217	217
query44	
query45	208	193	189	189
query46	966	1047	616	616
query47	2081	2097	2766	2097
query48	317	323	229	229
query49	633	503	392	392
query50	702	290	215	215
query51	4058	4086	4005	4005
query52	273	281	267	267
query53	334	359	302	302
query54	304	287	271	271
query55	99	82	82	82
query56	338	330	330	330
query57	1961	1892	1677	1677
query58	292	291	290	290
query59	2893	3002	2761	2761
query60	358	350	330	330
query61	156	152	151	151
query62	640	609	541	541
query63	329	290	288	288
query64	4944	1309	1016	1016
query65	
query66	1482	487	382	382
query67	24248	24290	24182	24182
query68	
query69	416	327	302	302
query70	991	944	976	944
query71	365	324	309	309
query72	2819	2694	2440	2440
query73	550	576	325	325
query74	9671	9662	9420	9420
query75	3076	2894	2553	2553
query76	2300	1123	715	715
query77	376	400	307	307
query78	10985	11012	10438	10438
query79	3107	827	581	581
query80	1731	660	561	561
query81	578	277	232	232
query82	995	167	125	125
query83	341	274	253	253
query84	291	118	108	108
query85	905	524	496	496
query86	511	316	347	316
query87	3187	3112	3006	3006
query88	3674	2680	2661	2661
query89	460	400	365	365
query90	1993	184	180	180
query91	171	165	149	149
query92	80	74	71	71
query93	1835	842	497	497
query94	661	304	279	279
query95	592	334	311	311
query96	657	528	232	232
query97	2530	2490	2380	2380
query98	262	229	221	221
query99	1007	949	893	893
Total cold run time: 256721 ms
Total hot run time: 169386 ms

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

4 participants