mariadb/mysql-test/suite/perfschema/t/nesting.test
2020-11-17 18:15:13 +02:00

191 lines
6.2 KiB
Text

# Test to check the proper nesting of events
## To skip the test with QC enabled till BUG#14830950 is fixed.
#-- source include/have_QC_Disabled.inc
--source include/not_embedded.inc
--source include/have_perfschema.inc
# On windows, the socket instrumentation collects an extra "opt"
# event, which changes the test output.
--source include/not_windows.inc
--source include/no_protocol.inc
# Work around MDEV-24232: WSREP causes extra operations on LOCK_thd_data etc.
--source include/have_wsrep.inc
--source ../include/wait_for_pfs_thread_count.inc
--disable_query_log
create user user1@localhost;
grant ALL on *.* to user1@localhost;
flush privileges;
--disable_warnings
drop table if exists test.setup_actors;
--enable_warnings
create table test.setup_actors as
select * from performance_schema.setup_actors;
# Only instrument the user connections
truncate table performance_schema.setup_actors;
insert into performance_schema.setup_actors
set host= 'localhost', user= 'user1', role= '%';
update performance_schema.threads set instrumented='NO';
# Only instrument a few events of each kind
update performance_schema.setup_instruments set enabled='NO', timed='NO';
update performance_schema.setup_instruments set enabled='YES', timed='YES'
where name in ('idle',
'wait/io/table/sql/handler',
'wait/lock/table/sql/handler',
'wait/io/socket/sql/client_connection',
'wait/synch/rwlock/sql/LOCK_grant',
'wait/synch/mutex/sql/THD::LOCK_thd_data',
'wait/synch/mutex/sql/THD::LOCK_thd_kill',
'wait/synch/mutex/sql/THD::LOCK_thd_query',
'wait/io/file/sql/query_log');
update performance_schema.setup_instruments set enabled='YES', timed='YES'
where name like ('stage/sql/%');
update performance_schema.setup_instruments set enabled='YES', timed='YES'
where name in ('statement/sql/select',
'statement/abstract/new_packet',
'statement/abstract/Query',
'statement/com/error');
# Start from a known clean state, to avoid noise from previous tests
truncate table performance_schema.events_statements_summary_by_digest;
flush tables;
flush status;
truncate performance_schema.events_waits_current;
truncate performance_schema.events_waits_history;
truncate performance_schema.events_waits_history_long;
truncate performance_schema.events_stages_current;
truncate performance_schema.events_stages_history;
truncate performance_schema.events_stages_history_long;
truncate performance_schema.events_statements_current;
truncate performance_schema.events_statements_history;
truncate performance_schema.events_statements_history_long;
--enable_query_log
connect (con1, localhost, user1, , );
select "MARKER_BEGIN" as marker;
select "This is simple statement one" as payload;
select "This is simple statement two" as payload;
delimiter $$;
select "This is the first part of a multi query" as payload;
select "And this is the second part of a multi query" as payload;
select "With a third part to make things complete" as payload;
$$
delimiter ;$$
select "MARKER_END" as marker;
select "Con1 is done with payload" as status;
--connection default
set @con1_tid = (select thread_id from performance_schema.threads
where processlist_user = 'user1');
select (@con1_tid is not null) as expected;
set @marker_begin = (select event_id from performance_schema.events_statements_history_long
where sql_text like "%MARKER_BEGIN%" and thread_id = @con1_tid);
select (@marker_begin is not null) as expected;
set @marker_end = (select end_event_id from performance_schema.events_statements_history_long
where sql_text like "%MARKER_END%" and thread_id = @con1_tid);
select (@marker_end is not null) as expected;
# Will point to what happened on spurious test failures
show global status like "performance_schema%";
#
# This is the test itself:
# the full trace of every recorded event between MARKER_BEGIN
# end MARKER_END is dumped.
# The value of EVENT_ID, END_EVENT_ID, NESTING_EVENT_TYPE, NESTING_EVENT_ID
# should reflect the relations between each events,
# and this structure should stay the same between runs.
#
# Things to observe in the output:
# - there are IDLE events between top level queries,
# - there are no IDLE events between multi queries
# - STATEMENT starts right after the IDLE event
# - STAGE init starts right after
# - SOCKET events, when receiving the command,
# are childrens of the STATEMENT select / STAGE init
select * from (
(
select (event_id - @marker_begin) as relative_event_id,
(end_event_id - @marker_begin) as relative_end_event_id,
event_name,
sql_text as comment,
nesting_event_type,
(nesting_event_id - @marker_begin) as relative_nesting_event_id
from performance_schema.events_statements_history_long
where (thread_id = @con1_tid)
and (@marker_begin <= event_id)
and (end_event_id <= @marker_end)
)
union
(
select (event_id - @marker_begin) as relative_event_id,
(end_event_id - @marker_begin) as relative_end_event_id,
event_name,
"(stage)" as comment,
nesting_event_type,
(nesting_event_id - @marker_begin) as relative_nesting_event_id
from performance_schema.events_stages_history_long
where (thread_id = @con1_tid)
and (@marker_begin <= event_id)
and (end_event_id <= @marker_end)
)
union
(
select (event_id - @marker_begin) as relative_event_id,
(end_event_id - @marker_begin) as relative_end_event_id,
event_name,
operation as comment,
nesting_event_type,
(nesting_event_id - @marker_begin) as relative_nesting_event_id
from performance_schema.events_waits_history_long
where (thread_id = @con1_tid)
and (@marker_begin <= event_id)
and (end_event_id <= @marker_end)
)
) all_events
order by relative_event_id asc;
# test cleanup
--disconnect con1
--disable_query_log
revoke all privileges, grant option from user1@localhost;
drop user user1@localhost;
flush privileges;
truncate table performance_schema.setup_actors;
insert into performance_schema.setup_actors
select * from test.setup_actors;
drop table test.setup_actors;
update performance_schema.threads set instrumented='YES';
update performance_schema.setup_instruments set enabled='YES', timed='YES';
--enable_query_log