[fix](nereids) fix This stopwatch is already running #37095

mymeiyi · 2024-07-01T11:30:55Z

Proposed changes

If plan throws exception, the stop watch is not stopped, and when execute next sql will get exception:

2024-07-01 19:05:01,679 WARN (mysql-nio-pool-21|660) [StmtExecutor.execute():601] Analyze failed. stmt[10651860, 6cea9e53220940ee-b324d18af20d9ab7]
org.apache.doris.common.NereidsException: errCode = 2, detailMessage = This stopwatch is already running.
        at org.apache.doris.qe.StmtExecutor.executeByNereids(StmtExecutor.java:755) ~[doris-fe.jar:1.2-SNAPSHOT]
        at org.apache.doris.qe.StmtExecutor.execute(StmtExecutor.java:584) ~[doris-fe.jar:1.2-SNAPSHOT]
        at org.apache.doris.qe.StmtExecutor.execute(StmtExecutor.java:537) ~[doris-fe.jar:1.2-SNAPSHOT]
        at org.apache.doris.nereids.trees.plans.commands.ExecuteCommand.run(ExecuteCommand.java:82) ~[doris-fe.jar:1.2-SNAPSHOT]
        at org.apache.doris.qe.StmtExecutor.executeByNereids(StmtExecutor.java:727) ~[doris-fe.jar:1.2-SNAPSHOT]
        at org.apache.doris.qe.StmtExecutor.execute(StmtExecutor.java:584) ~[doris-fe.jar:1.2-SNAPSHOT]
        at org.apache.doris.qe.StmtExecutor.execute(StmtExecutor.java:537) ~[doris-fe.jar:1.2-SNAPSHOT]
        at org.apache.doris.qe.MysqlConnectProcessor.handleExecute(MysqlConnectProcessor.java:201) ~[doris-fe.jar:1.2-SNAPSHOT]
        at org.apache.doris.qe.MysqlConnectProcessor.handleExecute(MysqlConnectProcessor.java:246) ~[doris-fe.jar:1.2-SNAPSHOT]
        at org.apache.doris.qe.MysqlConnectProcessor.dispatch(MysqlConnectProcessor.java:291) ~[doris-fe.jar:1.2-SNAPSHOT]
        at org.apache.doris.qe.MysqlConnectProcessor.processOnce(MysqlConnectProcessor.java:342) ~[doris-fe.jar:1.2-SNAPSHOT]
        at org.apache.doris.mysql.ReadListener.lambda$handleEvent$0(ReadListener.java:52) ~[doris-fe.jar:1.2-SNAPSHOT]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) ~[?:?]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) ~[?:?]
        at java.lang.Thread.run(Thread.java:833) ~[?:?]
Caused by: org.apache.doris.common.AnalysisException: errCode = 2, detailMessage = This stopwatch is already running.
        ... 15 more
Caused by: java.lang.IllegalStateException: This stopwatch is already running.
        at com.google.common.base.Preconditions.checkState(Preconditions.java:512) ~[guava-32.1.2-jre.jar:?]
        at com.google.common.base.Stopwatch.start(Stopwatch.java:166) ~[guava-32.1.2-jre.jar:?]
        at org.apache.doris.nereids.NereidsPlanner.plan(NereidsPlanner.java:140) ~[doris-fe.jar:1.2-SNAPSHOT]
        at org.apache.doris.nereids.trees.plans.commands.insert.InsertIntoTableCommand.initPlan(InsertIntoTableCommand
.java:155) ~[doris-fe.jar:1.2-SNAPSHOT]
        at org.apache.doris.nereids.trees.plans.commands.insert.InsertIntoTableCommand.runInternal(InsertIntoTableComm
and.java:226) ~[doris-fe.jar:1.2-SNAPSHOT]
        at org.apache.doris.nereids.trees.plans.commands.insert.InsertIntoTableCommand.run(InsertIntoTableCommand.java
:105) ~[doris-fe.jar:1.2-SNAPSHOT]
        at org.apache.doris.qe.StmtExecutor.executeByNereids(StmtExecutor.java:727) ~[doris-fe.jar:1.2-SNAPSHOT]
        ... 14 more

doris-robot · 2024-07-01T11:31:00Z

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

Since 2024-03-18, the Document has been moved to doris-website.
See Doris Document.

mymeiyi · 2024-07-01T12:14:36Z

run buildall

doris-robot · 2024-07-01T12:51:33Z

TPC-H: Total hot run time: 40402 ms

machine: 'aliyun_ecs.c7a.8xlarge_32C64G'
scripts: https://github.com/apache/doris/tree/master/tools/tpch-tools
Tpch sf100 test result on commit 0fedde33fb13b8bf423be90143f568b3694e4175, data reload: false

------ Round 1 ----------------------------------
q1	17629	4299	4257	4257
q2	2012	184	179	179
q3	10483	1212	1131	1131
q4	10198	812	863	812
q5	7466	2673	2606	2606
q6	220	138	133	133
q7	933	595	606	595
q8	9224	2057	2041	2041
q9	9005	6517	6489	6489
q10	9002	3728	3709	3709
q11	464	234	235	234
q12	411	230	229	229
q13	17754	2943	2937	2937
q14	266	236	220	220
q15	524	499	484	484
q16	523	370	373	370
q17	965	618	735	618
q18	8021	7472	7415	7415
q19	7764	1536	1525	1525
q20	660	328	322	322
q21	4771	3760	4011	3760
q22	394	337	336	336
Total cold run time: 118689 ms
Total hot run time: 40402 ms

----- Round 2, with runtime_filter_mode=off -----
q1	4376	4238	4278	4238
q2	369	270	271	270
q3	3019	2867	2921	2867
q4	1927	1744	1718	1718
q5	5479	5497	5456	5456
q6	234	129	137	129
q7	2276	1846	1830	1830
q8	3278	3438	3419	3419
q9	8675	8824	8675	8675
q10	4180	3673	3825	3673
q11	587	506	492	492
q12	823	680	619	619
q13	16311	3189	3153	3153
q14	320	265	263	263
q15	533	489	493	489
q16	486	435	431	431
q17	1803	1548	1512	1512
q18	8038	7929	7971	7929
q19	1855	1547	1543	1543
q20	2556	1871	1819	1819
q21	5101	5035	4592	4592
q22	742	578	569	569
Total cold run time: 72968 ms
Total hot run time: 55686 ms

doris-robot · 2024-07-01T13:02:30Z

TPC-DS: Total hot run time: 173627 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 0fedde33fb13b8bf423be90143f568b3694e4175, data reload: false

query1	925	382	371	371
query2	6445	2387	2412	2387
query3	6639	211	231	211
query4	19633	17564	17284	17284
query5	3552	487	481	481
query6	296	175	164	164
query7	4597	291	305	291
query8	338	295	295	295
query9	8464	2345	2342	2342
query10	574	305	276	276
query11	10464	10024	10098	10024
query12	116	83	82	82
query13	1633	353	360	353
query14	10057	6944	6822	6822
query15	227	183	198	183
query16	7563	263	262	262
query17	1487	571	531	531
query18	1908	272	261	261
query19	190	141	147	141
query20	90	86	83	83
query21	206	130	120	120
query22	4360	4249	4099	4099
query23	33832	33658	33609	33609
query24	11313	2830	2896	2830
query25	622	367	369	367
query26	719	165	154	154
query27	2338	330	323	323
query28	5920	2138	2104	2104
query29	886	638	626	626
query30	254	161	157	157
query31	990	762	744	744
query32	93	51	53	51
query33	774	317	308	308
query34	1056	508	483	483
query35	744	638	625	625
query36	1106	954	972	954
query37	137	76	76	76
query38	3003	2819	2861	2819
query39	880	834	853	834
query40	205	130	129	129
query41	54	51	50	50
query42	105	98	103	98
query43	599	535	554	535
query44	1167	714	737	714
query45	190	158	155	155
query46	1069	715	706	706
query47	1862	1797	1776	1776
query48	372	291	297	291
query49	851	409	408	408
query50	755	388	399	388
query51	6968	6724	6807	6724
query52	99	92	88	88
query53	359	296	281	281
query54	900	481	428	428
query55	71	71	70	70
query56	280	262	257	257
query57	1127	1025	1062	1025
query58	237	236	235	235
query59	3510	3248	3103	3103
query60	292	281	282	281
query61	96	90	95	90
query62	603	437	427	427
query63	318	289	287	287
query64	8685	2283	1745	1745
query65	3176	3095	3118	3095
query66	732	336	326	326
query67	15507	14967	15089	14967
query68	4513	523	519	519
query69	564	432	314	314
query70	1088	1093	1159	1093
query71	367	278	278	278
query72	7108	5724	5871	5724
query73	756	329	325	325
query74	5911	5502	5569	5502
query75	3322	2689	2618	2618
query76	2195	887	904	887
query77	557	301	289	289
query78	10494	10038	9714	9714
query79	2637	518	517	517
query80	1907	458	463	458
query81	557	233	216	216
query82	851	114	110	110
query83	340	172	168	168
query84	271	87	86	86
query85	1704	351	272	272
query86	479	304	325	304
query87	3288	3075	3080	3075
query88	4101	2368	2377	2368
query89	477	384	378	378
query90	1726	184	180	180
query91	126	97	103	97
query92	55	49	47	47
query93	2584	493	495	493
query94	1112	181	184	181
query95	393	308	307	307
query96	594	265	269	265
query97	3215	3029	3040	3029
query98	224	204	196	196
query99	1167	811	853	811
Total cold run time: 269303 ms
Total hot run time: 173627 ms

doris-robot · 2024-07-01T13:08:02Z

ClickBench: Total hot run time: 30.49 s

machine: 'aliyun_ecs.c7a.8xlarge_32C64G'
scripts: https://github.com/apache/doris/tree/master/tools/clickbench-tools
ClickBench test result on commit 0fedde33fb13b8bf423be90143f568b3694e4175, data reload: false

query1	0.04	0.03	0.03
query2	0.08	0.04	0.04
query3	0.22	0.05	0.05
query4	1.69	0.07	0.07
query5	0.50	0.48	0.49
query6	1.13	0.72	0.73
query7	0.02	0.01	0.01
query8	0.06	0.05	0.04
query9	0.55	0.49	0.49
query10	0.54	0.54	0.55
query11	0.15	0.11	0.10
query12	0.15	0.12	0.12
query13	0.59	0.58	0.58
query14	0.79	0.79	0.79
query15	0.85	0.82	0.82
query16	0.37	0.36	0.37
query17	0.96	1.05	0.99
query18	0.21	0.25	0.25
query19	1.76	1.70	1.81
query20	0.02	0.01	0.01
query21	15.43	0.77	0.65
query22	4.21	8.02	1.72
query23	18.28	1.32	1.27
query24	2.12	0.24	0.23
query25	0.15	0.08	0.10
query26	0.27	0.19	0.18
query27	0.08	0.08	0.08
query28	13.23	1.01	1.00
query29	12.64	3.33	3.33
query30	0.26	0.06	0.06
query31	2.86	0.40	0.39
query32	3.27	0.48	0.47
query33	2.93	2.94	2.88
query34	17.08	4.43	4.43
query35	4.50	4.46	4.54
query36	0.65	0.48	0.47
query37	0.18	0.15	0.16
query38	0.15	0.14	0.15
query39	0.04	0.03	0.04
query40	0.16	0.15	0.17
query41	0.09	0.05	0.05
query42	0.05	0.05	0.04
query43	0.04	0.04	0.04
Total cold run time: 109.35 s
Total hot run time: 30.49 s

dataroaring

LGTM

github-actions · 2024-07-02T01:20:26Z

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

github-actions · 2024-07-02T01:20:28Z

PR approved by anyone and no changes requested.

If plan throws exception, the stop watch is not stopped, and when execute next sql will get exception: 2024-07-01 19:05:01,679 WARN (mysql-nio-pool-21|660) [StmtExecutor.execute():601] Analyze failed. stmt[10651860, 6cea9e53220940ee-b324d18af20d9ab7] org.apache.doris.common.NereidsException: errCode = 2, detailMessage = This stopwatch is already running. at org.apache.doris.qe.StmtExecutor.executeByNereids(StmtExecutor.java:755) ~[doris-fe.jar:1.2-SNAPSHOT] at org.apache.doris.qe.StmtExecutor.execute(StmtExecutor.java:584) ~[doris-fe.jar:1.2-SNAPSHOT] at org.apache.doris.qe.StmtExecutor.execute(StmtExecutor.java:537) ~[doris-fe.jar:1.2-SNAPSHOT] at org.apache.doris.nereids.trees.plans.commands.ExecuteCommand.run(ExecuteCommand.java:82) ~[doris-fe.jar:1.2-SNAPSHOT] at org.apache.doris.qe.StmtExecutor.executeByNereids(StmtExecutor.java:727) ~[doris-fe.jar:1.2-SNAPSHOT] at org.apache.doris.qe.StmtExecutor.execute(StmtExecutor.java:584) ~[doris-fe.jar:1.2-SNAPSHOT] at org.apache.doris.qe.StmtExecutor.execute(StmtExecutor.java:537) ~[doris-fe.jar:1.2-SNAPSHOT] at org.apache.doris.qe.MysqlConnectProcessor.handleExecute(MysqlConnectProcessor.java:201) ~[doris-fe.jar:1.2-SNAPSHOT] at org.apache.doris.qe.MysqlConnectProcessor.handleExecute(MysqlConnectProcessor.java:246) ~[doris-fe.jar:1.2-SNAPSHOT] at org.apache.doris.qe.MysqlConnectProcessor.dispatch(MysqlConnectProcessor.java:291) ~[doris-fe.jar:1.2-SNAPSHOT] at org.apache.doris.qe.MysqlConnectProcessor.processOnce(MysqlConnectProcessor.java:342) ~[doris-fe.jar:1.2-SNAPSHOT] at org.apache.doris.mysql.ReadListener.lambda$handleEvent$0(ReadListener.java:52) ~[doris-fe.jar:1.2-SNAPSHOT] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) ~[?:?] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) ~[?:?] at java.lang.Thread.run(Thread.java:833) ~[?:?] Caused by: org.apache.doris.common.AnalysisException: errCode = 2, detailMessage = This stopwatch is already running. ... 15 more Caused by: java.lang.IllegalStateException: This stopwatch is already running. at com.google.common.base.Preconditions.checkState(Preconditions.java:512) ~[guava-32.1.2-jre.jar:?] at com.google.common.base.Stopwatch.start(Stopwatch.java:166) ~[guava-32.1.2-jre.jar:?] at org.apache.doris.nereids.NereidsPlanner.plan(NereidsPlanner.java:140) ~[doris-fe.jar:1.2-SNAPSHOT] at org.apache.doris.nereids.trees.plans.commands.insert.InsertIntoTableCommand.initPlan(InsertIntoTableCommand .java:155) ~[doris-fe.jar:1.2-SNAPSHOT] at org.apache.doris.nereids.trees.plans.commands.insert.InsertIntoTableCommand.runInternal(InsertIntoTableComm and.java:226) ~[doris-fe.jar:1.2-SNAPSHOT] at org.apache.doris.nereids.trees.plans.commands.insert.InsertIntoTableCommand.run(InsertIntoTableCommand.java :105) ~[doris-fe.jar:1.2-SNAPSHOT] at org.apache.doris.qe.StmtExecutor.executeByNereids(StmtExecutor.java:727) ~[doris-fe.jar:1.2-SNAPSHOT] ... 14 more

Pick #37168 and #37095

…e#37507) Pick apache#37168 and apache#37095

fix stop watch

0fedde3

dataroaring approved these changes Jul 2, 2024

View reviewed changes

github-actions bot added approved Indicates a PR has been approved by one committer. reviewed labels Jul 2, 2024

morrySnow approved these changes Jul 2, 2024

View reviewed changes

morrySnow merged commit d8da298 into apache:master Jul 2, 2024

mymeiyi mentioned this pull request Jul 7, 2024

[fix](nereids) Pick the stop watch is not reset (#37168) #37397

Merged

dataroaring pushed a commit that referenced this pull request Jul 8, 2024

[fix](nereids) Pick the stop watch is not reset (#37168) (#37397)

af7b69d

Pick #37168 and #37095

dataroaring added the dev/2.1.5-merged label Jul 8, 2024

mymeiyi mentioned this pull request Jul 9, 2024

[fix](nereids) Pick the stop watch is not reset (#37168) #37507

Merged

dataroaring pushed a commit that referenced this pull request Jul 9, 2024

[fix](nereids) Pick the stop watch is not reset (#37168) (#37507)

6182e4f

Pick #37168 and #37095

dataroaring added the dev/2.0.13-merged label Jul 9, 2024

dataroaring added the dev/3.0.0-merged label Aug 5, 2024

mongo360 pushed a commit to mongo360/doris that referenced this pull request Aug 16, 2024

[fix](nereids) Pick the stop watch is not reset (apache#37168) (apach…

5fb4beb

…e#37507) Pick apache#37168 and apache#37095

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Uh oh!

[fix](nereids) fix This stopwatch is already running #37095

[fix](nereids) fix This stopwatch is already running #37095

Uh oh!

mymeiyi commented Jul 1, 2024

Uh oh!

doris-robot commented Jul 1, 2024

Uh oh!

mymeiyi commented Jul 1, 2024

Uh oh!

doris-robot commented Jul 1, 2024

Uh oh!

doris-robot commented Jul 1, 2024

Uh oh!

doris-robot commented Jul 1, 2024

Uh oh!

dataroaring left a comment

Uh oh!

github-actions bot commented Jul 2, 2024

Uh oh!

github-actions bot commented Jul 2, 2024

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

4 participants

[fix](nereids) fix This stopwatch is already running #37095

[fix](nereids) fix This stopwatch is already running #37095

Uh oh!

Conversation

mymeiyi commented Jul 1, 2024

Proposed changes

Uh oh!

doris-robot commented Jul 1, 2024

Uh oh!

mymeiyi commented Jul 1, 2024

Uh oh!

doris-robot commented Jul 1, 2024

Uh oh!

doris-robot commented Jul 1, 2024

Uh oh!

doris-robot commented Jul 1, 2024

Uh oh!

dataroaring left a comment

Choose a reason for hiding this comment

Uh oh!

github-actions bot commented Jul 2, 2024

Uh oh!

github-actions bot commented Jul 2, 2024

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

4 participants