[MDEV-29822] mtr failure: sysschema.pr_statement_performance_analyzer Created: 2022-10-19  Updated: 2023-03-09

Status: Stalled
Project: MariaDB Server
Component/s: Tests
Affects Version/s: 10.6, 10.11
Fix Version/s: 10.6

Type: Bug Priority: Major
Reporter: Daniel Black Assignee: Unassigned
Resolution: Unresolved Votes: 0
Labels: None


 Description   

both occurred in 10.6

Windows failures - e.g. https://buildbot.mariadb.org/#/builders/239/builds/4710

[Revision hash: f9e95ada32f454cd160a18d7c7baf9c444584063]
 
sysschema.pr_statement_performance_analyzer w26 [ fail ]
        Test ended at 2022-10-18 20:30:28
 
CURRENT_TEST: sysschema.pr_statement_performance_analyzer
mysqltest: At line 150: Can't initialize replace from 'replace_result $query_insert QUERY_INSERT $query_select QUERY_SELECT $query_update QUERY_UPDATE $digest_insert DIGEST_INSERT $digest_update DIGEST_UPDATE $digest_select DIGEST_SELECT $d_upd_total_latency LATENCY $o_upd_max_latency LATENCY $o_upd_first_seen FIRST_SEEN $o_upd_last_seen LAST_SEEN $d_upd_tock_latency LATENCY $d_sel_total_latency LATENCY $o_sel_max_latency LATENCY $o_sel_first_seen FIRST_SEEN $o_sel_last_seen LAST_SEEN $d_sel_tock_latency LATENCY $d_ins_total_latency LATENCY $o_ins_max_latency LATENCY $o_ins_first_seen FIRST_SEEN $o_ins_last_seen LAST_SEEN $d_ins_tock_latency LATENCY'
 
The result from queries just before the failure was:
< snip >
id	val
1	1
2	1
disconnect con1;
connection default;
CALL sys.statement_performance_analyzer('snapshot', NULL, NULL);
SELECT DIGEST, COUNT_STAR FROM performance_schema.events_statements_summary_by_digest;
DIGEST	COUNT_STAR
DIGEST_INSERT	2
DIGEST_SELECT	2
DIGEST_UPDATE	2
CALL sys.statement_performance_analyzer('overall', NULL, 'with_runtimes_in_95th_percentile');
CALL sys.statement_performance_analyzer('delta', 'test.tmp_digests_ini', 'with_runtimes_in_95th_percentile');
CALL sys.statement_performance_analyzer('overall', NULL, 'analysis');
Next Output
QUERY_INSERT	test		2	0	0	LATENCY	LATENCY	LATENCY	LATENCY	0	0	0	0	2	1	0	0	0	0	DIGEST_INSERT	FIRST_SEEN	LAST_SEEN
QUERY_SELECT	test	*	2	0	0	LATENCY	LATENCY	LATENCY	LATENCY	3	2	9	5	0	0	0	0	2	0	DIGEST_SELECT	FIRST_SEEN	LAST_SEEN
QUERY_UPDATE	test		2	0	0	LATENCY	LATENCY	LATENCY	LATENCY	0	0	2	1	2	1	0	0	0	0	DIGEST_UPDATE	FIRST_SEEN	LAST_SEEN
Top 100 Queries Ordered by Total Latency
query	db	full_scan	exec_count	err_count	warn_count	total_latency	max_latency	avg_latency	lock_latency	rows_sent	rows_sent_avg	rows_examined	rows_examined_avg	rows_affected	rows_affected_avg	tmp_tables	tmp_disk_tables	rows_sorted	sort_merge_passes	digest	first_seen	last_seen
 
More results from queries before failure can be found in C:\Buildbot\amd64-windows-packages\build\mysql-test\var\26\log\pr_statement_performance_analyzer.log

ubuntu error e.g. https://buildbot.askmonty.org/buildbot/builders/kvm-deb-focal-amd64/builds/6924

[Revision hash: ba875e939619baefb08936863a889830]
 
sysschema.pr_statement_performance_analyzer w2 [ fail ]
        Test ended at 2022-09-30 23:47:57
 
CURRENT_TEST: sysschema.pr_statement_performance_analyzer
--- /usr/share/mysql/mysql-test/suite/sysschema/r/pr_statement_performance_analyzer.result	2022-09-30 21:15:59.000000000 +0000
+++ /dev/shm/var/2/log/pr_statement_performance_analyzer.reject	2022-09-30 23:47:57.604950136 +0000
@@ -37,6 +37,7 @@
 CALL sys.statement_performance_analyzer('snapshot', NULL, NULL);
 SELECT DIGEST, COUNT_STAR FROM performance_schema.events_statements_summary_by_digest;
 DIGEST	COUNT_STAR
+372796eb9c3d6a7940382e933ae64646	1
 DIGEST_INSERT	2
 DIGEST_SELECT	2
 DIGEST_UPDATE	2
@@ -47,6 +48,7 @@
 QUERY_INSERT	test		2	0	0	LATENCY	LATENCY	LATENCY	LATENCY	0	0	0	0	2	1	0	0	0	0	DIGEST_INSERT	FIRST_SEEN	LAST_SEEN
 QUERY_SELECT	test	*	2	0	0	LATENCY	LATENCY	LATENCY	LATENCY	3	2	9	5	0	0	0	0	2	0	DIGEST_SELECT	FIRST_SEEN	LAST_SEEN
 QUERY_UPDATE	test		2	0	0	LATENCY	LATENCY	LATENCY	LATENCY	0	0	2	1	2	1	0	0	0	0	DIGEST_UPDATE	FIRST_SEEN	LAST_SEEN
+SELECT `THREAD_ID` FROM `perfo ... IST_ID` = `CONNECTION_ID` ( ) 	test	*	1	0	0	5.37 ms	5.37 ms	5.37 ms	65.00 us	1	1	7	7	0	0	0	0	0	0	372796eb9c3d6a7940382e933ae64646	FIRST_SEEN	FIRST_SEEN
 Top 100 Queries Ordered by Total Latency
 query	db	full_scan	exec_count	err_count	warn_count	total_latency	max_latency	avg_latency	lock_latency	rows_sent	rows_sent_avg	rows_examined	rows_examined_avg	rows_affected	rows_affected_avg	tmp_tables	tmp_disk_tables	rows_sorted	sort_merge_passes	digest	first_seen	last_seen
 CALL sys.statement_performance_analyzer('delta', 'test.tmp_digests_ini', 'analysis');
@@ -68,6 +70,7 @@
 Next Output
 Top 100 Queries with Full Table Scan
 query	db	exec_count	total_latency	no_index_used_count	no_good_index_used_count	no_index_used_pct	rows_sent	rows_examined	rows_sent_avg	rows_examined_avg	first_seen	last_seen	digest
+SELECT `THREAD_ID` FROM `perfo ... IST_ID` = `CONNECTION_ID` ( ) 	test	1	5.37 ms	1	0	100	1	7	1	7	FIRST_SEEN	FIRST_SEEN	372796eb9c3d6a7940382e933ae64646
 QUERY_SELECT	test	2	LATENCY	1	0	50	3	9	2	5	FIRST_SEEN	LAST_SEEN	DIGEST_SELECT
 CALL sys.statement_performance_analyzer('delta', 'test.tmp_digests_ini', 'with_full_table_scans');
 Next Output
@@ -110,6 +113,7 @@
 Top 100 Queries Using Custom View
 query	db	exec_count	total_latency	avg_latency	rows_sent_avg	rows_examined_avg	rows_affected_avg	digest
 QUERY_INSERT	test	2	LATENCY	LATENCY	0	0	1	DIGEST_INSERT
+SELECT `THREAD_ID` FROM `perfo ... IST_ID` = `CONNECTION_ID` ( ) 	test	1	5.37 ms	5.37 ms	1	7	0	372796eb9c3d6a7940382e933ae64646
 QUERY_SELECT	test	2	LATENCY	LATENCY	2	5	0	DIGEST_SELECT
 QUERY_UPDATE	test	2	LATENCY	LATENCY	0	1	1	DIGEST_UPDATE
 CALL sys.statement_performance_analyzer('delta', 'test.tmp_digests_ini', 'custom');
@@ -125,7 +129,7 @@
 Top 2 Queries Using Custom View
 query	db	exec_count	total_latency	avg_latency	rows_sent_avg	rows_examined_avg	rows_affected_avg	digest
 QUERY_INSERT	test	2	LATENCY	LATENCY	0	0	1	DIGEST_INSERT
-QUERY_SELECT	test	2	LATENCY	LATENCY	2	5	0	DIGEST_SELECT
+SELECT `THREAD_ID` FROM `perfo ... IST_ID` = `CONNECTION_ID` ( ) 	test	1	5.37 ms	5.37 ms	1	7	0	372796eb9c3d6a7940382e933ae64646
 SET SESSION sql_mode = 'NO_AUTO_CREATE_USER';
 CALL sys.statement_performance_analyzer('do magic', NULL, NULL);
 ERROR 45000: Unknown action. Supported actions are: cleanup, create_table, create_tmp, delta, overall, save, snapshot


Generated at Thu Feb 08 10:11:33 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.