Merge lp:~tsarev/percona-server/5.5_fix_bug_716210 into lp:percona-server/5.5
- 5.5_fix_bug_716210
- Merge into 5.5
Status: | Superseded |
---|---|
Proposed branch: | lp:~tsarev/percona-server/5.5_fix_bug_716210 |
Merge into: | lp:percona-server/5.5 |
Diff against target: |
752 lines (+523/-92) (has conflicts) 1 file modified
patches/slow_extended.patch (+523/-92) Text conflict in patches/slow_extended.patch |
To merge this branch: | bzr merge lp:~tsarev/percona-server/5.5_fix_bug_716210 |
Related bugs: |
Reviewer | Review Type | Date Requested | Status |
---|---|---|---|
Laurynas Biveinis (community) | Needs Fixing | ||
Alexey Kopytov | Pending | ||
Review via email: mp+77458@code.launchpad.net |
This proposal supersedes a proposal from 2011-09-12.
This proposal has been superseded by a proposal from 2011-10-07.
Commit message
Description of the change
* "all statistics variables used in slow_extended.patch and thd->send_row_count and thd->examined_
* Added to class THD (sql/sql_class.h) following methods:
1) clear_slow_extended - clear SESV
2) reset_sub_
3) restore_
* Added to class Sub_statement_state (sql/sql_class.h) required for correct backup variables
* Added to class THD (sql/sql_class.h) comments near the SESV with explanations of purpose of variables
* Added call of clear_slow_extended to THD::init() (required on THD class initialisation and change_user)
* Fix admin command processing in LOGGER:
1) query and query_length according to comment in sql_class.h always correlated - if query == NULL => query_length == 0, and if query != NULL => query_length != 0
2) After "if (!query) { ... }" query_lenght always not 0
3) if (!query_length) (code before my fix) always trye
* Fixed accoring to code policy code formating in "increment_
* Fixed THD::reset_
* Fixed bug #716210: add thd->clear_
Clean Jenkins results: http://
Oleg Tsarev (tsarev) wrote : Posted in a previous version of this proposal | # |
Oleg Tsarev (tsarev) wrote : Posted in a previous version of this proposal | # |
Laurynas Biveinis (laurynas-biveinis) wrote : Posted in a previous version of this proposal | # |
LGTM provided that Jenkins result are clean
Alexey Kopytov (akopytov) wrote : Posted in a previous version of this proposal | # |
last_errno is not the only variable that has to be reset for admin commands after a failing statement. Most other counters from slow_extended are affected by the same problem.
Here's an test case:
create table t1(a int primary key);
insert into t1 values (1), (2), (3);
insert into t1 select * from t1 order by rand();
The last statement will fail ER_DUP_ENTRY, and the next admin command will have the same Last_errno, Rows_{sent,
I'm fairly sure InnoDB stats have the same problem.
Some comments on the test case:
- with use_global_
- please replace 1050 with ER_TABLE_
Laurynas Biveinis (laurynas-biveinis) wrote : | # |
- I am not sure the class Sub_statement_state is the best place to piggyback the backup info too (maybe Alexey can comment on this.) Perhaps a separate struct is needed?
- Please extend the testcase to show that other variables (Rows_{
Typos in the comment at 282--294:
1) "write_to_slow _log"
2) s/inited/
3) I'm not sure what "2)" and "3)" in the comment are trying to say.
Lines 313: I'm not sure what "Following Variables innodb_*** (is |should be) different from" is supposed to mean
Lines 324,329: s/collect/collects
Line 335: s/generates/
Line 337: s/contain/contains the
Line 346: constify the argument (unless something prevents this)
Oleg Tsarev (tsarev) wrote : | # |
> - I am not sure the class Sub_statement_state is the best place to piggyback
> the backup info too (maybe Alexey can comment on this.) Perhaps a separate
> struct is needed?
You can look intо:
void THD::reset_
This method use Sub_statement_state for backup all required variables.
I just extend it by me variables (as this was in first version of patch).
Of course, I can extract structure to separated Sub_statement_
> - Please extend the testcase to show that other variables
> (Rows_{
> and Tmp_table_sizes) are reset correctly, as pointed out by Alexey.
ACK
>
> Typos in the comment at 282--294:
> 1) "write_to_slow _log"
> 2) s/inited/
> 3) I'm not sure what "2)" and "3)" in the comment are trying to say.
2) and 3) about variable "write_
2) write_to_slow_log never changed (changed just on thread start time)
3) write_to_slow_log should be used in implementation of feature "sampling by query"
>
> Lines 313: I'm not sure what "Following Variables innodb_*** (is |should be)
> different from" is supposed to mean
> Lines 324,329: s/collect/collects
> Line 335: s/generates/
> Line 337: s/contain/contains the
> Line 346: constify the argument (unless something prevents this)
Laurynas Biveinis (laurynas-biveinis) wrote : | # |
> This method use Sub_statement_state for backup all required variables.
> I just extend it by me variables (as this was in first version of patch).
>
> Of course, I can extract structure to separated
> Sub_statement_
I have looked more carefully, and I see that some of the already-existing Sub_statement_state fields are used for backup too. Now I agree that just extending it is OK.
> > 3) I'm not sure what "2)" and "3)" in the comment are trying to say.
>
> 2) and 3) about variable "write_
> 2) write_to_slow_log never changed (changed just on thread start time)
> 3) write_to_slow_log should be used in implementation of feature "sampling
> by query"
2) The variable is initialized on the thread startup and remains constant afterwards. This will change when LP #712396 ("log_slow_
3) An implementation of LP #688646 ("Make query sampling possible by query") should use it.
- 152. By Oleg Tsarev
-
extend tests
Unmerged revisions
- 152. By Oleg Tsarev
-
extend tests
- 151. By Oleg Tsarev
-
* "all statistics variables used in slow_extended.patch and thd->send_row_count and thd->examined_
row_count" == SESV (Slow Extended Statistic Variables) * Added to class THD (sql/sql_class.h) following methods:
1) clear_slow_extended - clear SESV
2) reset_sub_statement_ state_slow_ extended( Sub_statement_ state *backup) - backup SESV to backup area
3) restore_sub_statement_ state_slow_ extended( Sub_statement_ state *backup) - restore SESV from backup area * Added to class Sub_statement_state (sql/sql_class.h) required for correct backup variables
* Added to class THD (sql/sql_class.h) comments near the SESV with explanations of purpose of variables
* Added call of clear_slow_extended to THD::init() (required on THD class initialisation and change_user)
* Fix admin command processing in LOGGER:
:slow_log_ print (sql/loc.cc). Before fix SESV don't clean correctly (because if(!query_length) never was true).
Explanation:
1) query and query_length according to comment in sql_class.h always correlated - if query == NULL => query_length == 0, and if query != NULL => query_length != 0
2) After "if (!query) { ... }" query_lenght always not 0
3) if (!query_length) (code before my fix) always trye* Fixed accoring to code policy code formating in "increment_
thd_innodb_ stats" (sql/sql_class.cc) * Fixed THD::reset_
for_next_ command (sql/sql_parse.cc) - replace variables cleaning by clear_slow_extended call * Fixed bug #716210: add thd->clear_
slow_extended( ) to dispatch_command()
Explanation: before dispatch_command mysql doesn't call "reset_for_next_ command" and SESV inherited from previous query
Preview Diff
1 | === modified file 'patches/slow_extended.patch' | |||
2 | --- patches/slow_extended.patch 2011-09-28 14:25:37 +0000 | |||
3 | +++ patches/slow_extended.patch 2011-10-06 23:44:24 +0000 | |||
4 | @@ -227,29 +227,16 @@ | |||
5 | 227 | } | 227 | } |
6 | 228 | else | 228 | else |
7 | 229 | { | 229 | { |
10 | 230 | @@ -1239,8 +1255,20 @@ | 230 | @@ -1240,7 +1256,7 @@ |
9 | 231 | query_length= command_name[thd->command].length; | ||
11 | 232 | } | 231 | } |
12 | 233 | 232 | ||
13 | 234 | + if (!query_length) | ||
14 | 235 | + { | ||
15 | 236 | + thd->sent_row_count= thd->examined_row_count= 0; | ||
16 | 237 | + thd->sent_row_count= 0; | ||
17 | 238 | + thd->bytes_sent_old= thd->status_var.bytes_sent; | ||
18 | 239 | + thd->tmp_tables_used= thd->tmp_tables_disk_used= 0; | ||
19 | 240 | + thd->tmp_tables_size= 0; | ||
20 | 241 | + thd->innodb_was_used= FALSE; | ||
21 | 242 | + thd->query_plan_flags= QPLAN_NONE; | ||
22 | 243 | + thd->query_plan_fsort_passes= 0; | ||
23 | 244 | + } | ||
24 | 245 | + | ||
25 | 246 | for (current_handler= slow_log_handler_list; *current_handler ;) | 233 | for (current_handler= slow_log_handler_list; *current_handler ;) |
26 | 247 | - error= (*current_handler++)->log_slow(thd, current_time, thd->start_time, | 234 | - error= (*current_handler++)->log_slow(thd, current_time, thd->start_time, |
27 | 248 | + error= (*current_handler++)->log_slow(thd, current_utime, thd->start_time, | 235 | + error= (*current_handler++)->log_slow(thd, current_utime, thd->start_time, |
28 | 249 | user_host_buff, user_host_len, | 236 | user_host_buff, user_host_len, |
29 | 250 | query_utime, lock_utime, is_command, | 237 | query_utime, lock_utime, is_command, |
30 | 251 | query, query_length) || error; | 238 | query, query_length) || error; |
32 | 252 | @@ -2656,12 +2684,13 @@ | 239 | @@ -2656,12 +2672,13 @@ |
33 | 253 | TRUE - error occured | 240 | TRUE - error occured |
34 | 254 | */ | 241 | */ |
35 | 255 | 242 | ||
36 | @@ -264,7 +251,7 @@ | |||
37 | 264 | bool error= 0; | 251 | bool error= 0; |
38 | 265 | DBUG_ENTER("MYSQL_QUERY_LOG::write"); | 252 | DBUG_ENTER("MYSQL_QUERY_LOG::write"); |
39 | 266 | 253 | ||
41 | 267 | @@ -2683,17 +2712,28 @@ | 254 | @@ -2683,17 +2700,28 @@ |
42 | 268 | 255 | ||
43 | 269 | if (!(specialflag & SPECIAL_SHORT_LOG_FORMAT)) | 256 | if (!(specialflag & SPECIAL_SHORT_LOG_FORMAT)) |
44 | 270 | { | 257 | { |
45 | @@ -300,9 +287,11 @@ | |||
46 | 300 | 287 | ||
47 | 301 | /* Note that my_b_write() assumes it knows the length for this */ | 288 | /* Note that my_b_write() assumes it knows the length for this */ |
48 | 302 | if (my_b_write(&log_file, (uchar*) buff, buff_len)) | 289 | if (my_b_write(&log_file, (uchar*) buff, buff_len)) |
50 | 303 | @@ -2711,12 +2751,69 @@ | 290 | @@ -2710,13 +2738,71 @@ |
51 | 291 | /* For slow query log */ | ||
52 | 304 | sprintf(query_time_buff, "%.6f", ulonglong2double(query_utime)/1000000.0); | 292 | sprintf(query_time_buff, "%.6f", ulonglong2double(query_utime)/1000000.0); |
53 | 305 | sprintf(lock_time_buff, "%.6f", ulonglong2double(lock_utime)/1000000.0); | 293 | sprintf(lock_time_buff, "%.6f", ulonglong2double(lock_utime)/1000000.0); |
54 | 294 | + DBUG_PRINT("info", ("Last_errno: %u", thd->last_errno)); | ||
55 | 306 | if (my_b_printf(&log_file, | 295 | if (my_b_printf(&log_file, |
56 | 307 | - "# Query_time: %s Lock_time: %s" | 296 | - "# Query_time: %s Lock_time: %s" |
57 | 308 | - " Rows_sent: %lu Rows_examined: %lu\n", | 297 | - " Rows_sent: %lu Rows_examined: %lu\n", |
58 | @@ -521,22 +510,22 @@ | |||
59 | 521 | 510 | ||
60 | 522 | +extern "C" | 511 | +extern "C" |
61 | 523 | +void increment_thd_innodb_stats(THD* thd, | 512 | +void increment_thd_innodb_stats(THD* thd, |
69 | 524 | + unsigned long long trx_id, | 513 | + unsigned long long trx_id, |
70 | 525 | + long io_reads, | 514 | + long io_reads, |
71 | 526 | + long long io_read, | 515 | + long long io_read, |
72 | 527 | + long io_reads_wait_timer, | 516 | + long io_reads_wait_timer, |
73 | 528 | + long lock_que_wait_timer, | 517 | + long lock_que_wait_timer, |
74 | 529 | + long que_wait_timer, | 518 | + long que_wait_timer, |
75 | 530 | + long page_access) | 519 | + long page_access) |
76 | 531 | +{ | 520 | +{ |
85 | 532 | + thd->innodb_was_used = TRUE; | 521 | + thd->innodb_was_used= TRUE; |
86 | 533 | + thd->innodb_trx_id = trx_id; | 522 | + thd->innodb_trx_id= trx_id; |
87 | 534 | + thd->innodb_io_reads += io_reads; | 523 | + thd->innodb_io_reads+= io_reads; |
88 | 535 | + thd->innodb_io_read += io_read; | 524 | + thd->innodb_io_read+= io_read; |
89 | 536 | + thd->innodb_io_reads_wait_timer += io_reads_wait_timer; | 525 | + thd->innodb_io_reads_wait_timer+= io_reads_wait_timer; |
90 | 537 | + thd->innodb_lock_que_wait_timer += lock_que_wait_timer; | 526 | + thd->innodb_lock_que_wait_timer+= lock_que_wait_timer; |
91 | 538 | + thd->innodb_innodb_que_wait_timer += que_wait_timer; | 527 | + thd->innodb_innodb_que_wait_timer+= que_wait_timer; |
92 | 539 | + thd->innodb_page_access += page_access; | 528 | + thd->innodb_page_access+= page_access; |
93 | 540 | +} | 529 | +} |
94 | 541 | + | 530 | + |
95 | 542 | +extern "C" | 531 | +extern "C" |
96 | @@ -562,44 +551,124 @@ | |||
97 | 562 | if (!m_internal_handler) | 551 | if (!m_internal_handler) |
98 | 563 | { | 552 | { |
99 | 564 | *cond_hdl= NULL; | 553 | *cond_hdl= NULL; |
101 | 565 | @@ -3656,6 +3689,12 @@ | 554 | @@ -1201,6 +1234,8 @@ |
102 | 555 | /* Initialize the Debug Sync Facility. See debug_sync.cc. */ | ||
103 | 556 | debug_sync_init_thread(this); | ||
104 | 557 | #endif /* defined(ENABLED_DEBUG_SYNC) */ | ||
105 | 558 | + | ||
106 | 559 | + clear_slow_extended(); | ||
107 | 560 | } | ||
108 | 561 | |||
109 | 562 | |||
110 | 563 | @@ -3647,8 +3682,6 @@ | ||
111 | 564 | backup->in_sub_stmt= in_sub_stmt; | ||
112 | 565 | backup->enable_slow_log= enable_slow_log; | ||
113 | 566 | backup->limit_found_rows= limit_found_rows; | ||
114 | 567 | - backup->examined_row_count= examined_row_count; | ||
115 | 568 | - backup->sent_row_count= sent_row_count; | ||
116 | 569 | backup->cuted_fields= cuted_fields; | ||
117 | 570 | backup->client_capabilities= client_capabilities; | ||
118 | 571 | backup->savepoints= transaction.savepoints; | ||
119 | 572 | @@ -3656,6 +3689,7 @@ | ||
120 | 566 | first_successful_insert_id_in_prev_stmt; | 573 | first_successful_insert_id_in_prev_stmt; |
121 | 567 | backup->first_successful_insert_id_in_cur_stmt= | 574 | backup->first_successful_insert_id_in_cur_stmt= |
122 | 568 | first_successful_insert_id_in_cur_stmt; | 575 | first_successful_insert_id_in_cur_stmt; |
129 | 569 | + backup->innodb_io_reads= innodb_io_reads; | 576 | + reset_sub_statement_state_slow_extended(backup); |
124 | 570 | + backup->innodb_io_read= innodb_io_read; | ||
125 | 571 | + backup->innodb_io_reads_wait_timer= innodb_io_reads_wait_timer; | ||
126 | 572 | + backup->innodb_lock_que_wait_timer= innodb_lock_que_wait_timer; | ||
127 | 573 | + backup->innodb_innodb_que_wait_timer= innodb_innodb_que_wait_timer; | ||
128 | 574 | + backup->innodb_page_access= innodb_page_access; | ||
130 | 575 | 577 | ||
131 | 576 | if ((!lex->requires_prelocking() || is_update_query(lex->sql_command)) && | 578 | if ((!lex->requires_prelocking() || is_update_query(lex->sql_command)) && |
132 | 577 | !is_current_stmt_binlog_format_row()) | 579 | !is_current_stmt_binlog_format_row()) |
134 | 578 | @@ -3676,6 +3715,14 @@ | 580 | @@ -3671,13 +3705,74 @@ |
135 | 581 | /* Disable result sets */ | ||
136 | 582 | client_capabilities &= ~CLIENT_MULTI_RESULTS; | ||
137 | 583 | in_sub_stmt|= new_state; | ||
138 | 584 | - examined_row_count= 0; | ||
139 | 585 | - sent_row_count= 0; | ||
140 | 579 | cuted_fields= 0; | 586 | cuted_fields= 0; |
141 | 580 | transaction.savepoints= 0; | 587 | transaction.savepoints= 0; |
142 | 581 | first_successful_insert_id_in_cur_stmt= 0; | 588 | first_successful_insert_id_in_cur_stmt= 0; |
149 | 582 | + last_errno= 0; | 589 | } |
150 | 583 | + innodb_trx_id= 0; | 590 | |
151 | 584 | + innodb_io_reads= 0; | 591 | +void THD::clear_slow_extended() |
152 | 585 | + innodb_io_read= 0; | 592 | +{ |
153 | 586 | + innodb_io_reads_wait_timer= 0; | 593 | + DBUG_ENTER("THD::clear_slow_extended"); |
154 | 587 | + innodb_lock_que_wait_timer= 0; | 594 | + sent_row_count= 0; |
155 | 595 | + examined_row_count= 0; | ||
156 | 596 | + bytes_sent_old= status_var.bytes_sent; | ||
157 | 597 | + tmp_tables_used= 0; | ||
158 | 598 | + tmp_tables_disk_used= 0; | ||
159 | 599 | + tmp_tables_size= 0; | ||
160 | 600 | + innodb_was_used= FALSE; | ||
161 | 601 | + innodb_trx_id= 0; | ||
162 | 602 | + innodb_io_reads= 0; | ||
163 | 603 | + innodb_io_read= 0; | ||
164 | 604 | + innodb_io_reads_wait_timer= 0; | ||
165 | 605 | + innodb_lock_que_wait_timer= 0; | ||
166 | 588 | + innodb_innodb_que_wait_timer= 0; | 606 | + innodb_innodb_que_wait_timer= 0; |
172 | 589 | + innodb_page_access= 0; | 607 | + innodb_page_access= 0; |
173 | 590 | } | 608 | + query_plan_flags= QPLAN_NONE; |
174 | 591 | 609 | + query_plan_fsort_passes= 0; | |
175 | 592 | 610 | + last_errno= 0; | |
176 | 593 | @@ -3738,6 +3785,12 @@ | 611 | + DBUG_VOID_RETURN; |
177 | 612 | +} | ||
178 | 613 | + | ||
179 | 614 | +void THD::reset_sub_statement_state_slow_extended(Sub_statement_state *backup) | ||
180 | 615 | +{ | ||
181 | 616 | + DBUG_ENTER("THD::reset_sub_statement_state_slow_extended"); | ||
182 | 617 | + backup->sent_row_count= sent_row_count; | ||
183 | 618 | + backup->examined_row_count= examined_row_count; | ||
184 | 619 | + backup->tmp_tables_used= tmp_tables_used; | ||
185 | 620 | + backup->tmp_tables_disk_used= tmp_tables_disk_used; | ||
186 | 621 | + backup->tmp_tables_size= tmp_tables_size; | ||
187 | 622 | + backup->innodb_was_used= innodb_was_used; | ||
188 | 623 | + backup->innodb_io_reads= innodb_io_reads; | ||
189 | 624 | + backup->innodb_io_read= innodb_io_read; | ||
190 | 625 | + backup->innodb_io_reads_wait_timer= innodb_io_reads_wait_timer; | ||
191 | 626 | + backup->innodb_lock_que_wait_timer= innodb_lock_que_wait_timer; | ||
192 | 627 | + backup->innodb_innodb_que_wait_timer= innodb_innodb_que_wait_timer; | ||
193 | 628 | + backup->innodb_page_access= innodb_page_access; | ||
194 | 629 | + backup->query_plan_flags= query_plan_flags; | ||
195 | 630 | + backup->query_plan_fsort_passes= query_plan_fsort_passes; | ||
196 | 631 | + clear_slow_extended(); | ||
197 | 632 | + DBUG_VOID_RETURN; | ||
198 | 633 | +} | ||
199 | 634 | + | ||
200 | 635 | +void THD::restore_sub_statement_state_slow_extended(Sub_statement_state *backup) | ||
201 | 636 | +{ | ||
202 | 637 | + DBUG_ENTER("THD::restore_sub_statement_state_slow_extended"); | ||
203 | 638 | + sent_row_count= backup->sent_row_count; | ||
204 | 639 | + examined_row_count+= backup->examined_row_count; | ||
205 | 640 | + tmp_tables_used+= backup->tmp_tables_used; | ||
206 | 641 | + tmp_tables_disk_used+= backup->tmp_tables_disk_used; | ||
207 | 642 | + tmp_tables_size+= backup->tmp_tables_size; | ||
208 | 643 | + innodb_was_used= (innodb_was_used || backup->innodb_was_used); | ||
209 | 644 | + innodb_io_reads+= backup->innodb_io_reads; | ||
210 | 645 | + innodb_io_read+= backup->innodb_io_read; | ||
211 | 646 | + innodb_io_reads_wait_timer+= backup->innodb_io_reads_wait_timer; | ||
212 | 647 | + innodb_lock_que_wait_timer+= backup->innodb_lock_que_wait_timer; | ||
213 | 648 | + innodb_innodb_que_wait_timer+= backup->innodb_innodb_que_wait_timer; | ||
214 | 649 | + innodb_page_access+= backup->innodb_page_access; | ||
215 | 650 | + query_plan_flags|= backup->query_plan_flags; | ||
216 | 651 | + query_plan_fsort_passes+= backup->query_plan_fsort_passes; | ||
217 | 652 | + DBUG_VOID_RETURN; | ||
218 | 653 | +} | ||
219 | 654 | |||
220 | 655 | void THD::restore_sub_statement_state(Sub_statement_state *backup) | ||
221 | 656 | { | ||
222 | 657 | @@ -3718,7 +3813,6 @@ | ||
223 | 658 | first_successful_insert_id_in_cur_stmt= | ||
224 | 659 | backup->first_successful_insert_id_in_cur_stmt; | ||
225 | 660 | limit_found_rows= backup->limit_found_rows; | ||
226 | 661 | - sent_row_count= backup->sent_row_count; | ||
227 | 662 | client_capabilities= backup->client_capabilities; | ||
228 | 663 | /* | ||
229 | 664 | If we've left sub-statement mode, reset the fatal error flag. | ||
230 | 665 | @@ -3736,8 +3830,8 @@ | ||
231 | 666 | The following is added to the old values as we are interested in the | ||
232 | 667 | total complexity of the query | ||
233 | 594 | */ | 668 | */ |
235 | 595 | examined_row_count+= backup->examined_row_count; | 669 | - examined_row_count+= backup->examined_row_count; |
236 | 596 | cuted_fields+= backup->cuted_fields; | 670 | cuted_fields+= backup->cuted_fields; |
243 | 597 | + innodb_io_reads+= backup->innodb_io_reads; | 671 | + restore_sub_statement_state_slow_extended(backup); |
238 | 598 | + innodb_io_read+= backup->innodb_io_read; | ||
239 | 599 | + innodb_io_reads_wait_timer+= backup->innodb_io_reads_wait_timer; | ||
240 | 600 | + innodb_lock_que_wait_timer+= backup->innodb_lock_que_wait_timer; | ||
241 | 601 | + innodb_innodb_que_wait_timer+= backup->innodb_innodb_que_wait_timer; | ||
242 | 602 | + innodb_page_access+= backup->innodb_page_access; | ||
244 | 603 | DBUG_VOID_RETURN; | 672 | DBUG_VOID_RETURN; |
245 | 604 | } | 673 | } |
246 | 605 | 674 | ||
247 | @@ -661,11 +730,17 @@ | |||
248 | 661 | double long_query_time_double; | 730 | double long_query_time_double; |
249 | 662 | 731 | ||
250 | 663 | } SV; | 732 | } SV; |
252 | 664 | @@ -1140,6 +1182,14 @@ | 733 | @@ -1140,6 +1182,24 @@ |
253 | 665 | uint in_sub_stmt; | 734 | uint in_sub_stmt; |
254 | 666 | bool enable_slow_log; | 735 | bool enable_slow_log; |
255 | 667 | bool last_insert_id_used; | 736 | bool last_insert_id_used; |
256 | 668 | + | 737 | + |
257 | 738 | + /*** Following variables used in slow_extended.patch ***/ | ||
258 | 739 | + ulong tmp_tables_used; | ||
259 | 740 | + ulong tmp_tables_disk_used; | ||
260 | 741 | + ulonglong tmp_tables_size; | ||
261 | 742 | + | ||
262 | 743 | + bool innodb_was_used; | ||
263 | 669 | + ulong innodb_io_reads; | 744 | + ulong innodb_io_reads; |
264 | 670 | + ulonglong innodb_io_read; | 745 | + ulonglong innodb_io_read; |
265 | 671 | + ulong innodb_io_reads_wait_timer; | 746 | + ulong innodb_io_reads_wait_timer; |
266 | @@ -673,20 +748,50 @@ | |||
267 | 673 | + ulong innodb_innodb_que_wait_timer; | 748 | + ulong innodb_innodb_que_wait_timer; |
268 | 674 | + ulong innodb_page_access; | 749 | + ulong innodb_page_access; |
269 | 675 | + | 750 | + |
270 | 751 | + ulong query_plan_flags; | ||
271 | 752 | + ulong query_plan_fsort_passes; | ||
272 | 753 | + /*** Belowing variables and methods used in slow_extended.patch ***/ | ||
273 | 754 | + | ||
274 | 676 | SAVEPOINT *savepoints; | 755 | SAVEPOINT *savepoints; |
275 | 677 | enum enum_check_fields count_cuted_fields; | 756 | enum enum_check_fields count_cuted_fields; |
276 | 678 | }; | 757 | }; |
278 | 679 | @@ -1588,6 +1638,26 @@ | 758 | @@ -1588,6 +1648,72 @@ |
279 | 680 | thr_lock_type update_lock_default; | 759 | thr_lock_type update_lock_default; |
280 | 681 | Delayed_insert *di; | 760 | Delayed_insert *di; |
281 | 682 | 761 | ||
282 | 762 | + /*** Following variables used in slow_extended.patch ***/ | ||
283 | 763 | + /* | ||
284 | 764 | + Variable write_to_slow _log: | ||
285 | 765 | + 1) inited in | ||
286 | 766 | + * sql_connect.cc (log_slow_rate_limit support) | ||
287 | 767 | + * slave.cc (log_slow_slave_statements support) | ||
288 | 768 | + 2) variable never changed while thread works | ||
289 | 769 | + * ATTENTION: this would be changed according to: | ||
290 | 770 | + Launchpad bug #712396: "log_slow_slave_statements not work | ||
291 | 771 | + on replication threads without RESTART" | ||
292 | 772 | + 3) variable should be used for: | ||
293 | 773 | + LP bug #688646: "Make query sampling possible by query" | ||
294 | 774 | + */ | ||
295 | 683 | + bool write_to_slow_log; | 775 | + bool write_to_slow_log; |
297 | 684 | + | 776 | + /* |
298 | 777 | + Variable bytes_send_old save value of thd->status_var.bytes_sent | ||
299 | 778 | + before query execution. | ||
300 | 779 | + */ | ||
301 | 685 | + ulonglong bytes_sent_old; | 780 | + ulonglong bytes_sent_old; |
302 | 781 | + /* | ||
303 | 782 | + Variables tmp_tables_*** collect statistics about usage of temporary tables | ||
304 | 783 | + */ | ||
305 | 686 | + ulong tmp_tables_used; | 784 | + ulong tmp_tables_used; |
306 | 687 | + ulong tmp_tables_disk_used; | 785 | + ulong tmp_tables_disk_used; |
307 | 688 | + ulonglong tmp_tables_size; | 786 | + ulonglong tmp_tables_size; |
308 | 787 | + /* | ||
309 | 788 | + Variable innodb_was used show used or not InnoDB engine in current query. | ||
310 | 789 | + */ | ||
311 | 689 | + bool innodb_was_used; | 790 | + bool innodb_was_used; |
312 | 791 | + /* | ||
313 | 792 | + Following Variables innodb_*** (is |should be) different from | ||
314 | 793 | + default values only if (innodb_was_used==TRUE) | ||
315 | 794 | + */ | ||
316 | 690 | + ulonglong innodb_trx_id; | 795 | + ulonglong innodb_trx_id; |
317 | 691 | + ulong innodb_io_reads; | 796 | + ulong innodb_io_reads; |
318 | 692 | + ulonglong innodb_io_read; | 797 | + ulonglong innodb_io_read; |
319 | @@ -695,10 +800,30 @@ | |||
320 | 695 | + ulong innodb_innodb_que_wait_timer; | 800 | + ulong innodb_innodb_que_wait_timer; |
321 | 696 | + ulong innodb_page_access; | 801 | + ulong innodb_page_access; |
322 | 697 | + | 802 | + |
323 | 803 | + /* | ||
324 | 804 | + Variable query_plan_flags collect information about query plan entites | ||
325 | 805 | + used on query execution. | ||
326 | 806 | + */ | ||
327 | 698 | + ulong query_plan_flags; | 807 | + ulong query_plan_flags; |
328 | 808 | + /* | ||
329 | 809 | + Variable query_plan_fsort_passes collect information about file sort passes | ||
330 | 810 | + acquired during query execution. | ||
331 | 811 | + */ | ||
332 | 699 | + ulong query_plan_fsort_passes; | 812 | + ulong query_plan_fsort_passes; |
334 | 700 | + | 813 | + /* |
335 | 814 | + Query can generates several errors/warnings during execution | ||
336 | 815 | + (see THD::handle_condition comment in sql_class.h) | ||
337 | 816 | + Variable last_errno contain last error/warning acquired during | ||
338 | 817 | + query execution. | ||
339 | 818 | + */ | ||
340 | 701 | + uint last_errno; | 819 | + uint last_errno; |
341 | 820 | + /*** Belowing variables and methods used in slow_extended.patch ***/ | ||
342 | 821 | + | ||
343 | 822 | + /*** Following methods used in slow_extended.patch ***/ | ||
344 | 823 | + void clear_slow_extended(); | ||
345 | 824 | + void reset_sub_statement_state_slow_extended(Sub_statement_state *backup); | ||
346 | 825 | + void restore_sub_statement_state_slow_extended(Sub_statement_state *backup); | ||
347 | 826 | + /*** Belowing methods used in slow_extended.patch ***/ | ||
348 | 702 | + | 827 | + |
349 | 703 | /* <> 0 if we are inside of trigger or stored function. */ | 828 | /* <> 0 if we are inside of trigger or stored function. */ |
350 | 704 | uint in_sub_stmt; | 829 | uint in_sub_stmt; |
351 | @@ -731,7 +856,15 @@ | |||
352 | 731 | 856 | ||
353 | 732 | const char *any_db="*any*"; // Special symbol for check_access | 857 | const char *any_db="*any*"; // Special symbol for check_access |
354 | 733 | 858 | ||
356 | 734 | @@ -1430,6 +1431,60 @@ | 859 | @@ -888,6 +889,7 @@ |
357 | 860 | the slow log only if opt_log_slow_admin_statements is set. | ||
358 | 861 | */ | ||
359 | 862 | thd->enable_slow_log= TRUE; | ||
360 | 863 | + thd->clear_slow_extended(); | ||
361 | 864 | thd->lex->sql_command= SQLCOM_END; /* to avoid confusing VIEW detectors */ | ||
362 | 865 | thd->set_time(); | ||
363 | 866 | if (!thd->is_valid_time()) | ||
364 | 867 | @@ -1430,6 +1432,60 @@ | ||
365 | 735 | DBUG_RETURN(error); | 868 | DBUG_RETURN(error); |
366 | 736 | } | 869 | } |
367 | 737 | 870 | ||
368 | @@ -792,7 +925,7 @@ | |||
369 | 792 | 925 | ||
370 | 793 | void log_slow_statement(THD *thd) | 926 | void log_slow_statement(THD *thd) |
371 | 794 | { | 927 | { |
373 | 795 | @@ -1443,13 +1498,48 @@ | 928 | @@ -1443,13 +1499,48 @@ |
374 | 796 | if (unlikely(thd->in_sub_stmt)) | 929 | if (unlikely(thd->in_sub_stmt)) |
375 | 797 | DBUG_VOID_RETURN; // Don't set time for sub stmt | 930 | DBUG_VOID_RETURN; // Don't set time for sub stmt |
376 | 798 | 931 | ||
377 | @@ -842,38 +975,16 @@ | |||
378 | 842 | thd_proc_info(thd, "logging slow query"); | 975 | thd_proc_info(thd, "logging slow query"); |
379 | 843 | 976 | ||
380 | 844 | if (((thd->server_status & SERVER_QUERY_WAS_SLOW) || | 977 | if (((thd->server_status & SERVER_QUERY_WAS_SLOW) || |
392 | 845 | @@ -1879,6 +1969,9 @@ | 978 | @@ -5295,7 +5386,8 @@ |
393 | 846 | context.resolve_in_table_list_only(select_lex-> | 979 | thd->stmt_da->reset_diagnostics_area(); |
394 | 847 | table_list.first); | 980 | thd->warning_info->reset_for_next_command(); |
384 | 848 | |||
385 | 849 | + /* Reset the counter at all cases for the extended slow query log */ | ||
386 | 850 | + thd->sent_row_count= 0; | ||
387 | 851 | + | ||
388 | 852 | /* | ||
389 | 853 | Reset warning count for each query that uses tables | ||
390 | 854 | A better approach would be to reset this for any commands | ||
391 | 855 | @@ -5297,6 +5390,21 @@ | ||
395 | 856 | thd->rand_used= 0; | 981 | thd->rand_used= 0; |
397 | 857 | thd->sent_row_count= thd->examined_row_count= 0; | 982 | - thd->sent_row_count= thd->examined_row_count= 0; |
398 | 983 | + | ||
399 | 984 | + thd->clear_slow_extended(); | ||
400 | 858 | 985 | ||
401 | 859 | + thd->bytes_sent_old= thd->status_var.bytes_sent; | ||
402 | 860 | + thd->tmp_tables_used= thd->tmp_tables_disk_used= 0; | ||
403 | 861 | + thd->tmp_tables_size= 0; | ||
404 | 862 | + thd->innodb_was_used= FALSE; | ||
405 | 863 | + thd->innodb_trx_id= 0; | ||
406 | 864 | + thd->innodb_io_reads= 0; | ||
407 | 865 | + thd->innodb_io_read= 0; | ||
408 | 866 | + thd->innodb_io_reads_wait_timer= 0; | ||
409 | 867 | + thd->innodb_lock_que_wait_timer= 0; | ||
410 | 868 | + thd->innodb_innodb_que_wait_timer= 0; | ||
411 | 869 | + thd->innodb_page_access= 0; | ||
412 | 870 | + thd->query_plan_flags= QPLAN_NONE; | ||
413 | 871 | + thd->query_plan_fsort_passes= 0; | ||
414 | 872 | + thd->last_errno= 0; | ||
415 | 873 | + | ||
416 | 874 | thd->reset_current_stmt_binlog_format_row(); | 986 | thd->reset_current_stmt_binlog_format_row(); |
417 | 875 | thd->binlog_unsafe_warning_flags= 0; | 987 | thd->binlog_unsafe_warning_flags= 0; |
418 | 876 | |||
419 | 877 | --- a/sql/sql_select.cc | 988 | --- a/sql/sql_select.cc |
420 | 878 | +++ b/sql/sql_select.cc | 989 | +++ b/sql/sql_select.cc |
421 | 879 | @@ -6902,7 +6902,10 @@ | 990 | @@ -6902,7 +6902,10 @@ |
422 | @@ -2425,6 +2536,7 @@ | |||
423 | 2425 | +--let grep_pattern = Last_errno: 1050 | 2536 | +--let grep_pattern = Last_errno: 1050 |
424 | 2426 | +--source include/log_grep.inc | 2537 | +--source include/log_grep.inc |
425 | 2427 | +DROP TABLE t; | 2538 | +DROP TABLE t; |
426 | 2539 | <<<<<<< TREE | ||
427 | 2428 | --- /dev/null | 2540 | --- /dev/null |
428 | 2429 | +++ b/mysql-test/suite/sys_vars/t/log_slow_admin_statements_basic.test | 2541 | +++ b/mysql-test/suite/sys_vars/t/log_slow_admin_statements_basic.test |
429 | 2430 | @@ -0,0 +1 @@ | 2542 | @@ -0,0 +1 @@ |
430 | @@ -2574,3 +2686,322 @@ | |||
431 | 2574 | @@ -0,0 +1,2 @@ | 2686 | @@ -0,0 +1,2 @@ |
432 | 2575 | +SHOW GLOBAL VARIABLES like 'log_slow_admin_statements'; | 2687 | +SHOW GLOBAL VARIABLES like 'log_slow_admin_statements'; |
433 | 2576 | +SELECT * FROM INFORMATION_SCHEMA.GLOBAL_VARIABLES WHERE VARIABLE_NAME='log_slow_admin_statements'; | 2688 | +SELECT * FROM INFORMATION_SCHEMA.GLOBAL_VARIABLES WHERE VARIABLE_NAME='log_slow_admin_statements'; |
434 | 2689 | ======= | ||
435 | 2690 | --- /dev/null | ||
436 | 2691 | +++ b/mysql-test/t/percona_slow_extended_error_on_quit.test | ||
437 | 2692 | @@ -0,0 +1,87 @@ | ||
438 | 2693 | +################################################################################ | ||
439 | 2694 | +# Current test check following attributes: # | ||
440 | 2695 | +# 1) "Last_errno" # | ||
441 | 2696 | +# 2) "Rows_{sent,examined|affected|read} # | ||
442 | 2697 | +# 3) Bytes_sent # | ||
443 | 2698 | +# 4) Tmp_{tables|dist_tables|table_size} # | ||
444 | 2699 | +# 5) InnoDB statistic counters # | ||
445 | 2700 | +# in Slow Query Log # | ||
446 | 2701 | +# for administrative command "Quit" # | ||
447 | 2702 | +# # | ||
448 | 2703 | +# See Launchpad Bug #716210 # | ||
449 | 2704 | +################################################################################ | ||
450 | 2705 | + | ||
451 | 2706 | +--source include/have_innodb.inc | ||
452 | 2707 | + | ||
453 | 2708 | +################################################################################ | ||
454 | 2709 | +--let log_file=percona.slow_extended.error_on_quit | ||
455 | 2710 | +--let wait_condition=SELECT COUNT(*) = 1 FROM INFORMATION_SCHEMA.PROCESSLIST; | ||
456 | 2711 | +################################################################################ | ||
457 | 2712 | + | ||
458 | 2713 | +--disable_warnings | ||
459 | 2714 | +DROP TABLE IF EXISTS t; | ||
460 | 2715 | +--enable_warnings | ||
461 | 2716 | +CREATE TABLE t(a INT) engine=InnoDB; | ||
462 | 2717 | +INSERT INTO t VALUES(0),(1),(2),(3),(4); | ||
463 | 2718 | + | ||
464 | 2719 | +################################################################################ | ||
465 | 2720 | +--source include/log_start.inc | ||
466 | 2721 | + | ||
467 | 2722 | +--connect(additional,localhost,root,,) | ||
468 | 2723 | +--connection additional | ||
469 | 2724 | + | ||
470 | 2725 | + SET log_slow_verbosity=innodb; | ||
471 | 2726 | + SET long_query_time= 0; | ||
472 | 2727 | + | ||
473 | 2728 | +--disable_result_log | ||
474 | 2729 | +--error ER_TABLE_EXISTS_ERROR | ||
475 | 2730 | + CREATE TABLE t(a INT) engine=InnoDB; | ||
476 | 2731 | +--enable_result_log | ||
477 | 2732 | + | ||
478 | 2733 | +--connection default | ||
479 | 2734 | +--echo # Disconnecting (passing to Slow Query Log "# administrative command: Quit") | ||
480 | 2735 | +--disconnect additional | ||
481 | 2736 | +--source include/wait_condition.inc | ||
482 | 2737 | +--source include/log_stop.inc | ||
483 | 2738 | +--source include/percona_slow_extended_error_on_quit.inc | ||
484 | 2739 | +################################################################################ | ||
485 | 2740 | +--source include/log_start.inc | ||
486 | 2741 | + | ||
487 | 2742 | +--connect(additional,localhost,root,,) | ||
488 | 2743 | +--connection additional | ||
489 | 2744 | + | ||
490 | 2745 | + SET log_slow_verbosity=innodb; | ||
491 | 2746 | + SET long_query_time= 0; | ||
492 | 2747 | + | ||
493 | 2748 | +--disable_result_log | ||
494 | 2749 | + INSERT INTO t SELECT * FROM t ORDER BY RAND(); | ||
495 | 2750 | +--enable_result_log | ||
496 | 2751 | + | ||
497 | 2752 | +--connection default | ||
498 | 2753 | +--echo # Disconnecting (passing to Slow Query Log "# administrative command: Quit") | ||
499 | 2754 | +--disconnect additional | ||
500 | 2755 | +--source include/wait_condition.inc | ||
501 | 2756 | +--source include/log_stop.inc | ||
502 | 2757 | +--source include/percona_slow_extended_error_on_quit.inc | ||
503 | 2758 | +################################################################################ | ||
504 | 2759 | +--source include/log_start.inc | ||
505 | 2760 | + | ||
506 | 2761 | +--connect(additional,localhost,root,,) | ||
507 | 2762 | +--connection additional | ||
508 | 2763 | + | ||
509 | 2764 | + SET log_slow_verbosity=innodb; | ||
510 | 2765 | + SET long_query_time= 0; | ||
511 | 2766 | + | ||
512 | 2767 | +--disable_result_log | ||
513 | 2768 | + SELECT * FROM t; | ||
514 | 2769 | +--enable_result_log | ||
515 | 2770 | + | ||
516 | 2771 | +--connection default | ||
517 | 2772 | +--echo # Disconnecting (passing to Slow Query Log "# administrative command: Quit") | ||
518 | 2773 | +--disconnect additional | ||
519 | 2774 | +--source include/wait_condition.inc | ||
520 | 2775 | +--source include/log_stop.inc | ||
521 | 2776 | +--source include/percona_slow_extended_error_on_quit.inc | ||
522 | 2777 | +################################################################################ | ||
523 | 2778 | + | ||
524 | 2779 | +DROP TABLE t; | ||
525 | 2780 | --- /dev/null | ||
526 | 2781 | +++ b/mysql-test/r/percona_slow_extended_error_on_quit.result | ||
527 | 2782 | @@ -0,0 +1,171 @@ | ||
528 | 2783 | +DROP TABLE IF EXISTS t; | ||
529 | 2784 | +CREATE TABLE t(a INT) engine=InnoDB; | ||
530 | 2785 | +INSERT INTO t VALUES(0),(1),(2),(3),(4); | ||
531 | 2786 | +[log_start.inc] percona.slow_extended.error_on_quit | ||
532 | 2787 | +SET log_slow_verbosity=innodb; | ||
533 | 2788 | +SET long_query_time= 0; | ||
534 | 2789 | +CREATE TABLE t(a INT) engine=InnoDB; | ||
535 | 2790 | +# Disconnecting (passing to Slow Query Log "# administrative command: Quit") | ||
536 | 2791 | +[log_stop.inc] percona.slow_extended.error_on_quit | ||
537 | 2792 | +################################################################################ | ||
538 | 2793 | +[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: CREATE | ||
539 | 2794 | +[log_grep.inc] lines: 1 | ||
540 | 2795 | +[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: INSERT | ||
541 | 2796 | +[log_grep.inc] lines: 0 | ||
542 | 2797 | +[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: SELECT | ||
543 | 2798 | +[log_grep.inc] lines: 0 | ||
544 | 2799 | +[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Quit | ||
545 | 2800 | +[log_grep.inc] lines: 1 | ||
546 | 2801 | +[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Last_errno: [^0]+ | ||
547 | 2802 | +[log_grep.inc] lines: 1 | ||
548 | 2803 | +[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Last_errno: 0 | ||
549 | 2804 | +[log_grep.inc] lines: 2 | ||
550 | 2805 | +[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Rows_sent: [^0]+ | ||
551 | 2806 | +[log_grep.inc] lines: 0 | ||
552 | 2807 | +[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Rows_sent: 0 | ||
553 | 2808 | +[log_grep.inc] lines: 3 | ||
554 | 2809 | +[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Rows_examined: [^0]+ | ||
555 | 2810 | +[log_grep.inc] lines: 0 | ||
556 | 2811 | +[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Rows_examined: 0 | ||
557 | 2812 | +[log_grep.inc] lines: 3 | ||
558 | 2813 | +[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Rows_affected: [^0]+ | ||
559 | 2814 | +[log_grep.inc] lines: 0 | ||
560 | 2815 | +[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Rows_affected: 0 | ||
561 | 2816 | +[log_grep.inc] lines: 3 | ||
562 | 2817 | +[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Rows_read: [^0]+ | ||
563 | 2818 | +[log_grep.inc] lines: 0 | ||
564 | 2819 | +[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Rows_read: 0 | ||
565 | 2820 | +[log_grep.inc] lines: 3 | ||
566 | 2821 | +[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Bytes_sent: [^0]+ | ||
567 | 2822 | +[log_grep.inc] lines: 2 | ||
568 | 2823 | +[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Bytes_sent: 0 | ||
569 | 2824 | +[log_grep.inc] lines: 1 | ||
570 | 2825 | +[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Tmp_tables: [^0]+ | ||
571 | 2826 | +[log_grep.inc] lines: 0 | ||
572 | 2827 | +[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Tmp_tables: 0 | ||
573 | 2828 | +[log_grep.inc] lines: 3 | ||
574 | 2829 | +[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Tmp_disk_tables: [^0]+ | ||
575 | 2830 | +[log_grep.inc] lines: 0 | ||
576 | 2831 | +[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Tmp_disk_tables: 0 | ||
577 | 2832 | +[log_grep.inc] lines: 3 | ||
578 | 2833 | +[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Tmp_table_sizes: [^0]+ | ||
579 | 2834 | +[log_grep.inc] lines: 0 | ||
580 | 2835 | +[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Tmp_table_sizes: 0 | ||
581 | 2836 | +[log_grep.inc] lines: 3 | ||
582 | 2837 | +[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: # No InnoDB statistics available for this query | ||
583 | 2838 | +[log_grep.inc] lines: 2 | ||
584 | 2839 | +[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: # InnoDB_trx_id: | ||
585 | 2840 | +[log_grep.inc] lines: 1 | ||
586 | 2841 | +################################################################################ | ||
587 | 2842 | +[log_start.inc] percona.slow_extended.error_on_quit | ||
588 | 2843 | +SET log_slow_verbosity=innodb; | ||
589 | 2844 | +SET long_query_time= 0; | ||
590 | 2845 | +INSERT INTO t SELECT * FROM t ORDER BY RAND(); | ||
591 | 2846 | +# Disconnecting (passing to Slow Query Log "# administrative command: Quit") | ||
592 | 2847 | +[log_stop.inc] percona.slow_extended.error_on_quit | ||
593 | 2848 | +################################################################################ | ||
594 | 2849 | +[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: CREATE | ||
595 | 2850 | +[log_grep.inc] lines: 0 | ||
596 | 2851 | +[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: INSERT | ||
597 | 2852 | +[log_grep.inc] lines: 1 | ||
598 | 2853 | +[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: SELECT | ||
599 | 2854 | +[log_grep.inc] lines: 1 | ||
600 | 2855 | +[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Quit | ||
601 | 2856 | +[log_grep.inc] lines: 1 | ||
602 | 2857 | +[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Last_errno: [^0]+ | ||
603 | 2858 | +[log_grep.inc] lines: 0 | ||
604 | 2859 | +[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Last_errno: 0 | ||
605 | 2860 | +[log_grep.inc] lines: 3 | ||
606 | 2861 | +[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Rows_sent: [^0]+ | ||
607 | 2862 | +[log_grep.inc] lines: 0 | ||
608 | 2863 | +[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Rows_sent: 0 | ||
609 | 2864 | +[log_grep.inc] lines: 3 | ||
610 | 2865 | +[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Rows_examined: [^0]+ | ||
611 | 2866 | +[log_grep.inc] lines: 1 | ||
612 | 2867 | +[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Rows_examined: 0 | ||
613 | 2868 | +[log_grep.inc] lines: 2 | ||
614 | 2869 | +[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Rows_affected: [^0]+ | ||
615 | 2870 | +[log_grep.inc] lines: 2 | ||
616 | 2871 | +[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Rows_affected: 0 | ||
617 | 2872 | +[log_grep.inc] lines: 1 | ||
618 | 2873 | +[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Rows_read: [^0]+ | ||
619 | 2874 | +[log_grep.inc] lines: 0 | ||
620 | 2875 | +[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Rows_read: 0 | ||
621 | 2876 | +[log_grep.inc] lines: 3 | ||
622 | 2877 | +[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Bytes_sent: [^0]+ | ||
623 | 2878 | +[log_grep.inc] lines: 2 | ||
624 | 2879 | +[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Bytes_sent: 0 | ||
625 | 2880 | +[log_grep.inc] lines: 1 | ||
626 | 2881 | +[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Tmp_tables: [^0]+ | ||
627 | 2882 | +[log_grep.inc] lines: 1 | ||
628 | 2883 | +[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Tmp_tables: 0 | ||
629 | 2884 | +[log_grep.inc] lines: 2 | ||
630 | 2885 | +[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Tmp_disk_tables: [^0]+ | ||
631 | 2886 | +[log_grep.inc] lines: 0 | ||
632 | 2887 | +[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Tmp_disk_tables: 0 | ||
633 | 2888 | +[log_grep.inc] lines: 3 | ||
634 | 2889 | +[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Tmp_table_sizes: [^0]+ | ||
635 | 2890 | +[log_grep.inc] lines: 1 | ||
636 | 2891 | +[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Tmp_table_sizes: 0 | ||
637 | 2892 | +[log_grep.inc] lines: 2 | ||
638 | 2893 | +[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: # No InnoDB statistics available for this query | ||
639 | 2894 | +[log_grep.inc] lines: 2 | ||
640 | 2895 | +[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: # InnoDB_trx_id: | ||
641 | 2896 | +[log_grep.inc] lines: 1 | ||
642 | 2897 | +################################################################################ | ||
643 | 2898 | +[log_start.inc] percona.slow_extended.error_on_quit | ||
644 | 2899 | +SET log_slow_verbosity=innodb; | ||
645 | 2900 | +SET long_query_time= 0; | ||
646 | 2901 | +SELECT * FROM t; | ||
647 | 2902 | +# Disconnecting (passing to Slow Query Log "# administrative command: Quit") | ||
648 | 2903 | +[log_stop.inc] percona.slow_extended.error_on_quit | ||
649 | 2904 | +################################################################################ | ||
650 | 2905 | +[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: CREATE | ||
651 | 2906 | +[log_grep.inc] lines: 0 | ||
652 | 2907 | +[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: INSERT | ||
653 | 2908 | +[log_grep.inc] lines: 0 | ||
654 | 2909 | +[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: SELECT | ||
655 | 2910 | +[log_grep.inc] lines: 1 | ||
656 | 2911 | +[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Quit | ||
657 | 2912 | +[log_grep.inc] lines: 1 | ||
658 | 2913 | +[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Last_errno: [^0]+ | ||
659 | 2914 | +[log_grep.inc] lines: 0 | ||
660 | 2915 | +[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Last_errno: 0 | ||
661 | 2916 | +[log_grep.inc] lines: 3 | ||
662 | 2917 | +[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Rows_sent: [^0]+ | ||
663 | 2918 | +[log_grep.inc] lines: 1 | ||
664 | 2919 | +[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Rows_sent: 0 | ||
665 | 2920 | +[log_grep.inc] lines: 2 | ||
666 | 2921 | +[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Rows_examined: [^0]+ | ||
667 | 2922 | +[log_grep.inc] lines: 1 | ||
668 | 2923 | +[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Rows_examined: 0 | ||
669 | 2924 | +[log_grep.inc] lines: 2 | ||
670 | 2925 | +[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Rows_affected: [^0]+ | ||
671 | 2926 | +[log_grep.inc] lines: 0 | ||
672 | 2927 | +[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Rows_affected: 0 | ||
673 | 2928 | +[log_grep.inc] lines: 3 | ||
674 | 2929 | +[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Rows_read: [^0]+ | ||
675 | 2930 | +[log_grep.inc] lines: 1 | ||
676 | 2931 | +[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Rows_read: 0 | ||
677 | 2932 | +[log_grep.inc] lines: 2 | ||
678 | 2933 | +[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Bytes_sent: [^0]+ | ||
679 | 2934 | +[log_grep.inc] lines: 2 | ||
680 | 2935 | +[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Bytes_sent: 0 | ||
681 | 2936 | +[log_grep.inc] lines: 1 | ||
682 | 2937 | +[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Tmp_tables: [^0]+ | ||
683 | 2938 | +[log_grep.inc] lines: 0 | ||
684 | 2939 | +[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Tmp_tables: 0 | ||
685 | 2940 | +[log_grep.inc] lines: 3 | ||
686 | 2941 | +[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Tmp_disk_tables: [^0]+ | ||
687 | 2942 | +[log_grep.inc] lines: 0 | ||
688 | 2943 | +[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Tmp_disk_tables: 0 | ||
689 | 2944 | +[log_grep.inc] lines: 3 | ||
690 | 2945 | +[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Tmp_table_sizes: [^0]+ | ||
691 | 2946 | +[log_grep.inc] lines: 0 | ||
692 | 2947 | +[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Tmp_table_sizes: 0 | ||
693 | 2948 | +[log_grep.inc] lines: 3 | ||
694 | 2949 | +[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: # No InnoDB statistics available for this query | ||
695 | 2950 | +[log_grep.inc] lines: 2 | ||
696 | 2951 | +[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: # InnoDB_trx_id: | ||
697 | 2952 | +[log_grep.inc] lines: 1 | ||
698 | 2953 | +################################################################################ | ||
699 | 2954 | --- /dev/null | ||
700 | 2955 | +++ b/mysql-test/include/percona_slow_extended_error_on_quit.inc | ||
701 | 2956 | @@ -0,0 +1,50 @@ | ||
702 | 2957 | +--echo ################################################################################ | ||
703 | 2958 | +--let grep_pattern=CREATE | ||
704 | 2959 | +--source include/log_grep.inc | ||
705 | 2960 | +--let grep_pattern=INSERT | ||
706 | 2961 | +--source include/log_grep.inc | ||
707 | 2962 | +--let grep_pattern=SELECT | ||
708 | 2963 | +--source include/log_grep.inc | ||
709 | 2964 | +--let grep_pattern=Quit | ||
710 | 2965 | +--source include/log_grep.inc | ||
711 | 2966 | +--let grep_pattern=Last_errno: [^0]+ | ||
712 | 2967 | +--source include/log_grep.inc | ||
713 | 2968 | +--let grep_pattern=Last_errno: 0 | ||
714 | 2969 | +--source include/log_grep.inc | ||
715 | 2970 | +--let grep_pattern=Rows_sent: [^0]+ | ||
716 | 2971 | +--source include/log_grep.inc | ||
717 | 2972 | +--let grep_pattern=Rows_sent: 0 | ||
718 | 2973 | +--source include/log_grep.inc | ||
719 | 2974 | +--let grep_pattern=Rows_examined: [^0]+ | ||
720 | 2975 | +--source include/log_grep.inc | ||
721 | 2976 | +--let grep_pattern=Rows_examined: 0 | ||
722 | 2977 | +--source include/log_grep.inc | ||
723 | 2978 | +--let grep_pattern=Rows_affected: [^0]+ | ||
724 | 2979 | +--source include/log_grep.inc | ||
725 | 2980 | +--let grep_pattern=Rows_affected: 0 | ||
726 | 2981 | +--source include/log_grep.inc | ||
727 | 2982 | +--let grep_pattern=Rows_read: [^0]+ | ||
728 | 2983 | +--source include/log_grep.inc | ||
729 | 2984 | +--let grep_pattern=Rows_read: 0 | ||
730 | 2985 | +--source include/log_grep.inc | ||
731 | 2986 | +--let grep_pattern=Bytes_sent: [^0]+ | ||
732 | 2987 | +--source include/log_grep.inc | ||
733 | 2988 | +--let grep_pattern=Bytes_sent: 0 | ||
734 | 2989 | +--source include/log_grep.inc | ||
735 | 2990 | +--let grep_pattern=Tmp_tables: [^0]+ | ||
736 | 2991 | +--source include/log_grep.inc | ||
737 | 2992 | +--let grep_pattern=Tmp_tables: 0 | ||
738 | 2993 | +--source include/log_grep.inc | ||
739 | 2994 | +--let grep_pattern=Tmp_disk_tables: [^0]+ | ||
740 | 2995 | +--source include/log_grep.inc | ||
741 | 2996 | +--let grep_pattern=Tmp_disk_tables: 0 | ||
742 | 2997 | +--source include/log_grep.inc | ||
743 | 2998 | +--let grep_pattern=Tmp_table_sizes: [^0]+ | ||
744 | 2999 | +--source include/log_grep.inc | ||
745 | 3000 | +--let grep_pattern=Tmp_table_sizes: 0 | ||
746 | 3001 | +--source include/log_grep.inc | ||
747 | 3002 | +--let grep_pattern=# No InnoDB statistics available for this query | ||
748 | 3003 | +--source include/log_grep.inc | ||
749 | 3004 | +--let grep_pattern=# InnoDB_trx_id: | ||
750 | 3005 | +--source include/log_grep.inc | ||
751 | 3006 | +--echo ################################################################################ | ||
752 | 3007 | >>>>>>> MERGE-SOURCE |
http:// jenkins. percona. com/view/ Percona% 20Server% 205.1/job/ percona- server- 5.1-param/ 133/