Percona Server moved to https://jira.percona.com/projects/PS

Merge lp:~tsarev/percona-server/test51_716210 into lp:percona-server/5.1

  1. test51_716210
  2. Merge into 5.1
Proposed by Oleg Tsarev
Status: Superseded
Proposed branch: lp:~tsarev/percona-server/test51_716210
Merge into: lp:percona-server/5.1
Diff against target: 319 lines (+76/-27)
6 files modified
patches/bug580324.patch (+3/-3)
patches/response_time_distribution.patch (+3/-3)
patches/show_slave_status_nolock.patch (+2/-2)
patches/show_temp_51.patch (+3/-3)
patches/slow_extended.patch (+53/-4)
patches/userstat.patch (+12/-12)
To merge this branch: bzr merge lp:~tsarev/percona-server/test51_716210
Reviewer Review Type Date Requested Status
Alexey Kopytov (community) Needs Fixing
Laurynas Biveinis (community) Approve
Review via email: mp+74998@code.launchpad.net

This proposal supersedes a proposal from 2011-09-06.

This proposal has been superseded by a proposal from 2011-09-29.

Description of the change

Fixed bug #716210 - incorrect last_errno in slow-query-log

To post a comment you must log in.
Revision history for this message
Oleg Tsarev (tsarev) wrote : Posted in a previous version of this proposal

http://jenkins.percona.com/view/Percona%20Server%205.1/job/percona-server-5.1-param/133/

Revision history for this message
Oleg Tsarev (tsarev) wrote :

http://jenkins.percona.com/view/Percona%20Server%205.1/job/percona-server-5.1-param/138

Revision history for this message
Laurynas Biveinis (laurynas-biveinis) wrote :

LGTM provided that Jenkins result are clean

review: Approve
Revision history for this message
Alexey Kopytov (akopytov) wrote :

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,examined,affected,read}, Bytes_sent, Tmp_tables, Tmp_disk_tables and Tmp_table_sizes.

I'm fairly sure InnoDB stats have the same problem.

Some comments on the test case:

- with use_global_long_query_time=1 do you really need to create a separate connection?
- please replace 1050 with ER_TABLE_EXISTS_ERROR.

review: Needs Fixing

Unmerged revisions

282. By Oleg Tsarev

Fixed bug #716210 - incorrect last_errno in slow-query-log

281. By Oleg Tsarev

1) move tests from mysql-test/ to patches
2) remove install_tests script and call of script from Makefile

Preview Diff

[H/L] Next/Prev Comment, [J/K] Next/Prev File, [N/P] Next/Prev Hunk
1=== modified file 'patches/bug580324.patch'
2--- patches/bug580324.patch 2011-08-09 13:35:34 +0000
3+++ patches/bug580324.patch 2011-09-12 13:47:56 +0000
4@@ -24,7 +24,7 @@
5 int4store(key + key_length, thd->server_id);
6 --- a/sql/sql_parse.cc
7 +++ b/sql/sql_parse.cc
8-@@ -1342,10 +1342,12 @@
9+@@ -1343,10 +1343,12 @@
10 break;
11 #else
12 {
13@@ -39,7 +39,7 @@
14
15 /* used as fields initializator */
16 lex_start(thd);
17-@@ -1357,26 +1359,22 @@
18+@@ -1358,26 +1360,22 @@
19 /*
20 We have name + wildcard in packet, separated by endzero
21 */
22@@ -77,7 +77,7 @@
23
24 if (is_schema_db(table_list.db, table_list.db_length))
25 {
26-@@ -1385,9 +1383,6 @@
27+@@ -1386,9 +1384,6 @@
28 table_list.schema_table= schema_table;
29 }
30
31
32=== modified file 'patches/response_time_distribution.patch'
33--- patches/response_time_distribution.patch 2011-07-30 23:07:03 +0000
34+++ patches/response_time_distribution.patch 2011-09-12 13:47:56 +0000
35@@ -3119,7 +3119,7 @@
36
37 /**
38 @defgroup Runtime_Environment Runtime Environment
39-@@ -1777,6 +1778,7 @@
40+@@ -1778,6 +1779,7 @@
41
42 ulonglong end_utime_of_query= thd->current_utime();
43 ulonglong query_exec_time= get_query_exec_time(thd, end_utime_of_query);
44@@ -3127,7 +3127,7 @@
45
46 /*
47 Low long_query_time value most likely means user is debugging stuff and even
48-@@ -1947,6 +1949,7 @@
49+@@ -1948,6 +1950,7 @@
50 case SCH_CHARSETS:
51 case SCH_ENGINES:
52 case SCH_COLLATIONS:
53@@ -3135,7 +3135,7 @@
54 case SCH_COLLATION_CHARACTER_SET_APPLICABILITY:
55 case SCH_USER_PRIVILEGES:
56 case SCH_SCHEMA_PRIVILEGES:
57-@@ -7306,6 +7309,12 @@
58+@@ -7307,6 +7310,12 @@
59 init_global_index_stats();
60 pthread_mutex_unlock(&LOCK_global_index_stats);
61 }
62
63=== modified file 'patches/show_slave_status_nolock.patch'
64--- patches/show_slave_status_nolock.patch 2011-09-06 08:23:51 +0000
65+++ patches/show_slave_status_nolock.patch 2011-09-12 13:47:56 +0000
66@@ -56,7 +56,7 @@
67 sql_command_flags[SQLCOM_SHOW_CREATE_PROC]= CF_STATUS_COMMAND;
68 sql_command_flags[SQLCOM_SHOW_CREATE_FUNC]= CF_STATUS_COMMAND;
69 sql_command_flags[SQLCOM_SHOW_CREATE_TRIGGER]= CF_STATUS_COMMAND;
70-@@ -2589,12 +2590,16 @@
71+@@ -2590,12 +2591,16 @@
72 pthread_mutex_unlock(&LOCK_active_mi);
73 break;
74 }
75@@ -74,7 +74,7 @@
76 if (active_mi != NULL)
77 {
78 res = show_master_info(thd, active_mi);
79-@@ -2605,7 +2610,10 @@
80+@@ -2606,7 +2611,10 @@
81 WARN_NO_MASTER_INFO, ER(WARN_NO_MASTER_INFO));
82 my_ok(thd);
83 }
84
85=== modified file 'patches/show_temp_51.patch'
86--- patches/show_temp_51.patch 2011-09-06 08:23:51 +0000
87+++ patches/show_temp_51.patch 2011-09-12 13:47:56 +0000
88@@ -38,7 +38,7 @@
89 sql_command_flags[SQLCOM_SHOW_TABLE_STATUS]= (CF_STATUS_COMMAND |
90 CF_SHOW_TABLE_COMMAND |
91 CF_REEXECUTION_FRAGILE);
92-@@ -1875,6 +1878,8 @@
93+@@ -1876,6 +1879,8 @@
94
95 case SCH_TABLE_NAMES:
96 case SCH_TABLES:
97@@ -47,7 +47,7 @@
98 case SCH_VIEWS:
99 case SCH_TRIGGERS:
100 case SCH_EVENTS:
101-@@ -2374,6 +2379,7 @@
102+@@ -2375,6 +2380,7 @@
103 }
104 case SQLCOM_SHOW_DATABASES:
105 case SQLCOM_SHOW_TABLES:
106@@ -55,7 +55,7 @@
107 case SQLCOM_SHOW_TRIGGERS:
108 case SQLCOM_SHOW_TABLE_STATUS:
109 case SQLCOM_SHOW_OPEN_TABLES:
110-@@ -5527,6 +5533,8 @@
111+@@ -5528,6 +5534,8 @@
112
113 case SCH_TABLE_NAMES:
114 case SCH_TABLES:
115
116=== modified file 'patches/slow_extended.patch'
117--- patches/slow_extended.patch 2011-08-09 13:35:34 +0000
118+++ patches/slow_extended.patch 2011-09-12 13:47:56 +0000
119@@ -1388,7 +1388,15 @@
120
121 const char *any_db="*any*"; // Special symbol for check_access
122
123-@@ -1700,6 +1701,50 @@
124+@@ -999,6 +1000,7 @@
125+ the slow log only if opt_log_slow_admin_statements is set.
126+ */
127+ thd->enable_slow_log= TRUE;
128++ thd->last_errno= 0;
129+ thd->lex->sql_command= SQLCOM_END; /* to avoid confusing VIEW detectors */
130+ thd->set_time();
131+ if (!thd->is_valid_time())
132+@@ -1700,6 +1702,50 @@
133 DBUG_RETURN(error);
134 }
135
136@@ -1439,7 +1447,7 @@
137
138 void log_slow_statement(THD *thd)
139 {
140-@@ -1713,17 +1758,51 @@
141+@@ -1713,17 +1759,51 @@
142 if (unlikely(thd->in_sub_stmt))
143 DBUG_VOID_RETURN; // Don't set time for sub stmt
144
145@@ -1494,7 +1502,7 @@
146 ((thd->server_status &
147 (SERVER_QUERY_NO_INDEX_USED | SERVER_QUERY_NO_GOOD_INDEX_USED)) &&
148 opt_log_queries_not_using_indexes &&
149-@@ -2099,6 +2178,9 @@
150+@@ -2099,6 +2179,9 @@
151 context.resolve_in_table_list_only(select_lex->
152 table_list.first);
153
154@@ -1504,7 +1512,7 @@
155 /*
156 Reset warning count for each query that uses tables
157 A better approach would be to reset this for any commands
158-@@ -5827,6 +5909,21 @@
159+@@ -5827,6 +5910,21 @@
160 thd->rand_used= 0;
161 thd->sent_row_count= thd->examined_row_count= 0;
162
163@@ -2575,3 +2583,44 @@
164 /* Intvar event post-header */
165
166 /* Intvar event data */
167+--- /dev/null
168++++ b/mysql-test/r/percona_log_slow_parse_error.result
169+@@ -0,0 +1,11 @@
170++SET GLOBAL long_query_time=0;
171++SET GLOBAL use_global_long_query_time=1;
172++SET GLOBAL log_slow_timestamp_every=1;
173++DROP TABLE IF EXISTS t1;
174++CREATE TABLE t1 (a INT);
175++[log_start.inc] percona.slow_extended.error_on_quit
176++CREATE TABLE t1 (a INT);
177++ERROR 42S01: Table 't1' already exists
178++[log_stop.inc] percona.slow_extended.error_on_quit
179++[log_grep.inc] file: percona.slow_extended.error_on_quit pattern: Last_errno: 1050
180++[log_grep.inc] lines: 1
181+--- /dev/null
182++++ b/mysql-test/t/percona_log_slow_parse_error.test
183+@@ -0,0 +1,24 @@
184++--let log_file=percona.slow_extended.error_on_quit
185++
186++SET GLOBAL long_query_time=0;
187++SET GLOBAL use_global_long_query_time=1;
188++SET GLOBAL log_slow_timestamp_every=1;
189++
190++connect (conn1,localhost,root,,);
191++connection conn1;
192++--disable_warnings
193++DROP TABLE IF EXISTS t1;
194++--enable_warnings
195++CREATE TABLE t1 (a INT);
196++--source include/log_start.inc
197++--error 1050
198++CREATE TABLE t1 (a INT);
199++disconnect conn1;
200++connection default;
201++--source include/log_stop.inc
202++--let grep_pattern = Last_errno: 1050
203++--source include/log_grep.inc
204++SET GLOBAL long_query_time=default;
205++SET GLOBAL use_global_long_query_time=default;
206++SET GLOBAL log_slow_timestamp_every=default;
207++DROP TABLE t1;
208
209=== modified file 'patches/userstat.patch'
210--- patches/userstat.patch 2011-09-06 08:23:51 +0000
211+++ patches/userstat.patch 2011-09-12 13:47:56 +0000
212@@ -1759,7 +1759,7 @@
213 /*
214 Commands which always take a long time are logged into
215 the slow log only if opt_log_slow_admin_statements is set.
216-@@ -1921,6 +1933,13 @@
217+@@ -1922,6 +1934,13 @@
218 thd->profiling.discard_current_query();
219 #endif
220 break;
221@@ -1773,7 +1773,7 @@
222 case SCH_OPEN_TABLES:
223 case SCH_VARIABLES:
224 case SCH_STATUS:
225-@@ -2077,6 +2096,7 @@
226+@@ -2078,6 +2097,7 @@
227 thd->security_ctx->priv_host)) &&
228 check_global_access(thd, SUPER_ACL))
229 {
230@@ -1781,7 +1781,7 @@
231 my_error(ER_SPECIFIC_ACCESS_DENIED_ERROR, MYF(0), "SUPER");
232 DBUG_RETURN(TRUE);
233 }
234-@@ -5418,6 +5438,7 @@
235+@@ -5419,6 +5439,7 @@
236 if (!no_errors)
237 {
238 const char *db_name= db ? db : thd->db;
239@@ -1789,7 +1789,7 @@
240 my_error(ER_DBACCESS_DENIED_ERROR, MYF(0),
241 sctx->priv_user, sctx->priv_host, db_name);
242 }
243-@@ -5450,12 +5471,15 @@
244+@@ -5451,12 +5472,15 @@
245 { // We can never grant this
246 DBUG_PRINT("error",("No possible access"));
247 if (!no_errors)
248@@ -1805,7 +1805,7 @@
249 DBUG_RETURN(TRUE); /* purecov: tested */
250 }
251
252-@@ -5481,11 +5505,15 @@
253+@@ -5482,11 +5506,15 @@
254
255 DBUG_PRINT("error",("Access denied"));
256 if (!no_errors)
257@@ -1821,7 +1821,7 @@
258 DBUG_RETURN(TRUE); /* purecov: tested */
259 }
260
261-@@ -5514,6 +5542,7 @@
262+@@ -5515,6 +5543,7 @@
263
264 if (!thd->col_access && check_grant_db(thd, dst_db_name))
265 {
266@@ -1829,7 +1829,7 @@
267 my_error(ER_DBACCESS_DENIED_ERROR, MYF(0),
268 thd->security_ctx->priv_user,
269 thd->security_ctx->priv_host,
270-@@ -5595,9 +5624,12 @@
271+@@ -5596,9 +5625,12 @@
272 (want_access & ~(SELECT_ACL | EXTRA_ACL | FILE_ACL)))
273 {
274 if (!no_errors)
275@@ -1842,7 +1842,7 @@
276 return TRUE;
277 }
278 /*
279-@@ -5760,6 +5792,7 @@
280+@@ -5761,6 +5793,7 @@
281 if ((thd->security_ctx->master_access & want_access))
282 return 0;
283 get_privilege_desc(command, sizeof(command), want_access);
284@@ -1850,7 +1850,7 @@
285 my_error(ER_SPECIFIC_ACCESS_DENIED_ERROR, MYF(0), command);
286 return 1;
287 #else
288-@@ -6134,6 +6167,32 @@
289+@@ -6135,6 +6168,32 @@
290 lex_start(thd);
291 mysql_reset_thd_for_next_command(thd);
292
293@@ -1883,7 +1883,7 @@
294 if (query_cache_send_result_to_client(thd, rawbuf, length) <= 0)
295 {
296 LEX *lex= thd->lex;
297-@@ -6214,6 +6273,43 @@
298+@@ -6215,6 +6274,43 @@
299 *found_semicolon= NULL;
300 }
301
302@@ -1927,7 +1927,7 @@
303 DBUG_VOID_RETURN;
304 }
305
306-@@ -7086,6 +7182,13 @@
307+@@ -7087,6 +7183,13 @@
308 if (flush_error_log())
309 result=1;
310 }
311@@ -1941,7 +1941,7 @@
312 #ifdef HAVE_QUERY_CACHE
313 if (options & REFRESH_QUERY_CACHE_FREE)
314 {
315-@@ -7186,6 +7289,40 @@
316+@@ -7187,6 +7290,40 @@
317 #endif
318 if (options & REFRESH_USER_RESOURCES)
319 reset_mqh((LEX_USER *) NULL, 0); /* purecov: inspected */

Subscribers

People subscribed via source and target branches