mirror of
https://github.com/MariaDB/server.git
synced 2025-11-04 04:46:15 +01:00
9a132d423a
This will makes it easier to find out what replication workers are doing and what they are waiting for. Things changed in processlist: - Slave_SQL time was not consistent. Now time for state "Slave has read all relay log; waiting for more updates" shows how long it has waited for getting the next event. - Slave_worker threads did often show "Closing tables" for a long time. Now the state is reverted to the previous state after "Closing tables" is done. - Commit and Rollback states where not shown for replication (and some other threads). Now Commit and Rollback states are always shown and the state is reverted to previous state when the Commit/Rollback have finished. Code changes: - Added thd->set_time_for_next_stage() for parallel replication when when starting to wait for prior transactions to commit, group commit, and FTWRL and for free space in thread pool. Before we reset the time only after the above events. - Moved THD_STAGE_INFO(stage_rollback) and THD_STAGE_INFO(stage_commit) from sql_parse.cc to transaction.cc to ensure this is done for all commits and not only 'normal connection queries'. Test case changes: - close_thread_tables() reverting stage to previous stage caused the counter in performance_schema to be increased. In many case it is the 'sql/starting' stage that was effected. - We only change to "Commit" stage if there is a need for a commit. This caused some "Commit" stages to disapper from perfschema reports. TODO in 11.#: - Slave_IO always showes "Waiting for master to send event" and the time is from SLAVE START. We should in 11.# change this to be the time since reading the last event.
274 lines
12 KiB
Text
274 lines
12 KiB
Text
connect con1, localhost, user1, , ;
|
|
select "MARKER_BEGIN" as marker;
|
|
marker
|
|
MARKER_BEGIN
|
|
select "This is simple statement one" as payload;
|
|
payload
|
|
This is simple statement one
|
|
select "This is simple statement two" as payload;
|
|
payload
|
|
This is simple statement two
|
|
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;
|
|
$$
|
|
payload
|
|
This is the first part of a multi query
|
|
payload
|
|
And this is the second part of a multi query
|
|
payload
|
|
With a third part to make things complete
|
|
select "MARKER_END" as marker;
|
|
marker
|
|
MARKER_END
|
|
select "Con1 is done with payload" as status;
|
|
status
|
|
Con1 is done with payload
|
|
connection default;
|
|
set @con1_tid = (select thread_id from performance_schema.threads
|
|
where processlist_user = 'user1');
|
|
select (@con1_tid is not null) as expected;
|
|
expected
|
|
1
|
|
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;
|
|
expected
|
|
1
|
|
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;
|
|
expected
|
|
1
|
|
show global status like "performance_schema%";
|
|
Variable_name Value
|
|
Performance_schema_accounts_lost 0
|
|
Performance_schema_cond_classes_lost 0
|
|
Performance_schema_cond_instances_lost 0
|
|
Performance_schema_digest_lost 0
|
|
Performance_schema_file_classes_lost 0
|
|
Performance_schema_file_handles_lost 0
|
|
Performance_schema_file_instances_lost 0
|
|
Performance_schema_hosts_lost 0
|
|
Performance_schema_index_stat_lost 0
|
|
Performance_schema_locker_lost 0
|
|
Performance_schema_memory_classes_lost 0
|
|
Performance_schema_metadata_lock_lost 0
|
|
Performance_schema_mutex_classes_lost 0
|
|
Performance_schema_mutex_instances_lost 0
|
|
Performance_schema_nested_statement_lost 0
|
|
Performance_schema_prepared_statements_lost 0
|
|
Performance_schema_program_lost 0
|
|
Performance_schema_rwlock_classes_lost 0
|
|
Performance_schema_rwlock_instances_lost 0
|
|
Performance_schema_session_connect_attrs_lost 0
|
|
Performance_schema_socket_classes_lost 0
|
|
Performance_schema_socket_instances_lost 0
|
|
Performance_schema_stage_classes_lost 0
|
|
Performance_schema_statement_classes_lost 0
|
|
Performance_schema_table_handles_lost 0
|
|
Performance_schema_table_instances_lost 0
|
|
Performance_schema_table_lock_stat_lost 0
|
|
Performance_schema_thread_classes_lost 0
|
|
Performance_schema_thread_instances_lost 0
|
|
Performance_schema_users_lost 0
|
|
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;
|
|
relative_event_id relative_end_event_id event_name comment nesting_event_type relative_nesting_event_id
|
|
0 21 statement/sql/select select "MARKER_BEGIN" as marker NULL NULL
|
|
1 5 stage/sql/starting (stage) STATEMENT 0
|
|
2 2 wait/io/socket/sql/client_connection recv STAGE 1
|
|
3 3 wait/synch/mutex/sql/THD::LOCK_thd_data lock STAGE 1
|
|
4 4 wait/synch/mutex/sql/THD::LOCK_thd_data lock STAGE 1
|
|
5 5 wait/io/file/sql/query_log write STAGE 1
|
|
6 6 stage/sql/checking permissions (stage) STATEMENT 0
|
|
7 7 stage/sql/Opening tables (stage) STATEMENT 0
|
|
8 8 stage/sql/After opening tables (stage) STATEMENT 0
|
|
9 9 stage/sql/init (stage) STATEMENT 0
|
|
10 10 stage/sql/Optimizing (stage) STATEMENT 0
|
|
11 11 stage/sql/Executing (stage) STATEMENT 0
|
|
12 12 stage/sql/End of update loop (stage) STATEMENT 0
|
|
13 13 stage/sql/Query end (stage) STATEMENT 0
|
|
14 14 stage/sql/closing tables (stage) STATEMENT 0
|
|
15 15 stage/sql/Query end (stage) STATEMENT 0
|
|
16 16 stage/sql/Starting cleanup (stage) STATEMENT 0
|
|
17 17 stage/sql/Freeing items (stage) STATEMENT 0
|
|
18 18 wait/io/socket/sql/client_connection send STATEMENT 0
|
|
19 19 wait/synch/mutex/sql/THD::LOCK_thd_kill lock STATEMENT 0
|
|
20 21 stage/sql/Reset for next command (stage) STATEMENT 0
|
|
21 21 wait/synch/mutex/sql/THD::LOCK_thd_data lock STAGE 20
|
|
22 22 wait/synch/mutex/sql/THD::LOCK_thd_data lock STATEMENT 0
|
|
23 23 idle idle NULL NULL
|
|
24 45 statement/sql/select select "This is simple statement one" as payload NULL NULL
|
|
25 29 stage/sql/starting (stage) STATEMENT 24
|
|
26 26 wait/io/socket/sql/client_connection recv STAGE 25
|
|
27 27 wait/synch/mutex/sql/THD::LOCK_thd_data lock STAGE 25
|
|
28 28 wait/synch/mutex/sql/THD::LOCK_thd_data lock STAGE 25
|
|
29 29 wait/io/file/sql/query_log write STAGE 25
|
|
30 30 stage/sql/checking permissions (stage) STATEMENT 24
|
|
31 31 stage/sql/Opening tables (stage) STATEMENT 24
|
|
32 32 stage/sql/After opening tables (stage) STATEMENT 24
|
|
33 33 stage/sql/init (stage) STATEMENT 24
|
|
34 34 stage/sql/Optimizing (stage) STATEMENT 24
|
|
35 35 stage/sql/Executing (stage) STATEMENT 24
|
|
36 36 stage/sql/End of update loop (stage) STATEMENT 24
|
|
37 37 stage/sql/Query end (stage) STATEMENT 24
|
|
38 38 stage/sql/closing tables (stage) STATEMENT 24
|
|
39 39 stage/sql/Query end (stage) STATEMENT 24
|
|
40 40 stage/sql/Starting cleanup (stage) STATEMENT 24
|
|
41 41 stage/sql/Freeing items (stage) STATEMENT 24
|
|
42 42 wait/io/socket/sql/client_connection send STATEMENT 24
|
|
43 43 wait/synch/mutex/sql/THD::LOCK_thd_kill lock STATEMENT 24
|
|
44 45 stage/sql/Reset for next command (stage) STATEMENT 24
|
|
45 45 wait/synch/mutex/sql/THD::LOCK_thd_data lock STAGE 44
|
|
46 46 wait/synch/mutex/sql/THD::LOCK_thd_data lock STATEMENT 24
|
|
47 47 idle idle NULL NULL
|
|
48 69 statement/sql/select select "This is simple statement two" as payload NULL NULL
|
|
49 53 stage/sql/starting (stage) STATEMENT 48
|
|
50 50 wait/io/socket/sql/client_connection recv STAGE 49
|
|
51 51 wait/synch/mutex/sql/THD::LOCK_thd_data lock STAGE 49
|
|
52 52 wait/synch/mutex/sql/THD::LOCK_thd_data lock STAGE 49
|
|
53 53 wait/io/file/sql/query_log write STAGE 49
|
|
54 54 stage/sql/checking permissions (stage) STATEMENT 48
|
|
55 55 stage/sql/Opening tables (stage) STATEMENT 48
|
|
56 56 stage/sql/After opening tables (stage) STATEMENT 48
|
|
57 57 stage/sql/init (stage) STATEMENT 48
|
|
58 58 stage/sql/Optimizing (stage) STATEMENT 48
|
|
59 59 stage/sql/Executing (stage) STATEMENT 48
|
|
60 60 stage/sql/End of update loop (stage) STATEMENT 48
|
|
61 61 stage/sql/Query end (stage) STATEMENT 48
|
|
62 62 stage/sql/closing tables (stage) STATEMENT 48
|
|
63 63 stage/sql/Query end (stage) STATEMENT 48
|
|
64 64 stage/sql/Starting cleanup (stage) STATEMENT 48
|
|
65 65 stage/sql/Freeing items (stage) STATEMENT 48
|
|
66 66 wait/io/socket/sql/client_connection send STATEMENT 48
|
|
67 67 wait/synch/mutex/sql/THD::LOCK_thd_kill lock STATEMENT 48
|
|
68 69 stage/sql/Reset for next command (stage) STATEMENT 48
|
|
69 69 wait/synch/mutex/sql/THD::LOCK_thd_data lock STAGE 68
|
|
70 70 wait/synch/mutex/sql/THD::LOCK_thd_data lock STATEMENT 48
|
|
71 71 idle idle NULL NULL
|
|
72 92 statement/sql/select 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 NULL NULL
|
|
73 78 stage/sql/starting (stage) STATEMENT 72
|
|
74 74 wait/io/socket/sql/client_connection recv STAGE 73
|
|
75 75 wait/synch/mutex/sql/THD::LOCK_thd_data lock STAGE 73
|
|
76 76 wait/synch/mutex/sql/THD::LOCK_thd_data lock STAGE 73
|
|
77 77 wait/io/file/sql/query_log write STAGE 73
|
|
78 78 wait/synch/mutex/sql/THD::LOCK_thd_data lock STAGE 73
|
|
79 79 stage/sql/checking permissions (stage) STATEMENT 72
|
|
80 80 stage/sql/Opening tables (stage) STATEMENT 72
|
|
81 81 stage/sql/After opening tables (stage) STATEMENT 72
|
|
82 82 stage/sql/init (stage) STATEMENT 72
|
|
83 83 stage/sql/Optimizing (stage) STATEMENT 72
|
|
84 84 stage/sql/Executing (stage) STATEMENT 72
|
|
85 85 stage/sql/End of update loop (stage) STATEMENT 72
|
|
86 86 stage/sql/Query end (stage) STATEMENT 72
|
|
87 87 stage/sql/closing tables (stage) STATEMENT 72
|
|
88 88 stage/sql/Query end (stage) STATEMENT 72
|
|
89 89 stage/sql/Starting cleanup (stage) STATEMENT 72
|
|
90 92 stage/sql/Freeing items (stage) STATEMENT 72
|
|
91 91 wait/io/socket/sql/client_connection send STAGE 90
|
|
92 92 wait/synch/mutex/sql/THD::LOCK_thd_kill lock STAGE 90
|
|
93 110 statement/sql/select select "And this is the second part of a multi query" as payload;
|
|
select "With a third part to make things complete" as payload NULL NULL
|
|
94 96 stage/sql/starting (stage) STATEMENT 93
|
|
95 95 wait/synch/mutex/sql/THD::LOCK_thd_data lock STAGE 94
|
|
96 96 wait/synch/mutex/sql/THD::LOCK_thd_data lock STAGE 94
|
|
97 97 stage/sql/checking permissions (stage) STATEMENT 93
|
|
98 98 stage/sql/Opening tables (stage) STATEMENT 93
|
|
99 99 stage/sql/After opening tables (stage) STATEMENT 93
|
|
100 100 stage/sql/init (stage) STATEMENT 93
|
|
101 101 stage/sql/Optimizing (stage) STATEMENT 93
|
|
102 102 stage/sql/Executing (stage) STATEMENT 93
|
|
103 103 stage/sql/End of update loop (stage) STATEMENT 93
|
|
104 104 stage/sql/Query end (stage) STATEMENT 93
|
|
105 105 stage/sql/closing tables (stage) STATEMENT 93
|
|
106 106 stage/sql/Query end (stage) STATEMENT 93
|
|
107 107 stage/sql/Starting cleanup (stage) STATEMENT 93
|
|
108 110 stage/sql/Freeing items (stage) STATEMENT 93
|
|
109 109 wait/io/socket/sql/client_connection send STAGE 108
|
|
110 110 wait/synch/mutex/sql/THD::LOCK_thd_kill lock STAGE 108
|
|
111 129 statement/sql/select select "With a third part to make things complete" as payload NULL NULL
|
|
112 113 stage/sql/starting (stage) STATEMENT 111
|
|
113 113 wait/synch/mutex/sql/THD::LOCK_thd_data lock STAGE 112
|
|
114 114 stage/sql/checking permissions (stage) STATEMENT 111
|
|
115 115 stage/sql/Opening tables (stage) STATEMENT 111
|
|
116 116 stage/sql/After opening tables (stage) STATEMENT 111
|
|
117 117 stage/sql/init (stage) STATEMENT 111
|
|
118 118 stage/sql/Optimizing (stage) STATEMENT 111
|
|
119 119 stage/sql/Executing (stage) STATEMENT 111
|
|
120 120 stage/sql/End of update loop (stage) STATEMENT 111
|
|
121 121 stage/sql/Query end (stage) STATEMENT 111
|
|
122 122 stage/sql/closing tables (stage) STATEMENT 111
|
|
123 123 stage/sql/Query end (stage) STATEMENT 111
|
|
124 124 stage/sql/Starting cleanup (stage) STATEMENT 111
|
|
125 125 stage/sql/Freeing items (stage) STATEMENT 111
|
|
126 126 wait/io/socket/sql/client_connection send STATEMENT 111
|
|
127 127 wait/synch/mutex/sql/THD::LOCK_thd_kill lock STATEMENT 111
|
|
128 129 stage/sql/Reset for next command (stage) STATEMENT 111
|
|
129 129 wait/synch/mutex/sql/THD::LOCK_thd_data lock STAGE 128
|
|
130 130 wait/synch/mutex/sql/THD::LOCK_thd_data lock STATEMENT 111
|
|
131 131 idle idle NULL NULL
|
|
132 153 statement/sql/select select "MARKER_END" as marker NULL NULL
|
|
133 137 stage/sql/starting (stage) STATEMENT 132
|
|
134 134 wait/io/socket/sql/client_connection recv STAGE 133
|
|
135 135 wait/synch/mutex/sql/THD::LOCK_thd_data lock STAGE 133
|
|
136 136 wait/synch/mutex/sql/THD::LOCK_thd_data lock STAGE 133
|
|
137 137 wait/io/file/sql/query_log write STAGE 133
|
|
138 138 stage/sql/checking permissions (stage) STATEMENT 132
|
|
139 139 stage/sql/Opening tables (stage) STATEMENT 132
|
|
140 140 stage/sql/After opening tables (stage) STATEMENT 132
|
|
141 141 stage/sql/init (stage) STATEMENT 132
|
|
142 142 stage/sql/Optimizing (stage) STATEMENT 132
|
|
143 143 stage/sql/Executing (stage) STATEMENT 132
|
|
144 144 stage/sql/End of update loop (stage) STATEMENT 132
|
|
145 145 stage/sql/Query end (stage) STATEMENT 132
|
|
146 146 stage/sql/closing tables (stage) STATEMENT 132
|
|
147 147 stage/sql/Query end (stage) STATEMENT 132
|
|
148 148 stage/sql/Starting cleanup (stage) STATEMENT 132
|
|
149 149 stage/sql/Freeing items (stage) STATEMENT 132
|
|
150 150 wait/io/socket/sql/client_connection send STATEMENT 132
|
|
151 151 wait/synch/mutex/sql/THD::LOCK_thd_kill lock STATEMENT 132
|
|
152 153 stage/sql/Reset for next command (stage) STATEMENT 132
|
|
153 153 wait/synch/mutex/sql/THD::LOCK_thd_data lock STAGE 152
|
|
disconnect con1;
|