| Bug #49119 | Master crashes when executing 'REVOKE ... ON {PROCEDURE|FUNCTION} FROM ...' | ||
|---|---|---|---|
| Submitted: | 26 Nov 2009 4:18 | Modified: | 12 Mar 2010 16:44 |
| Reporter: | Libing Song | Email Updates: | |
| Status: | Closed | Impact on me: | |
| Category: | MySQL Server: Replication | Severity: | S3 (Non-critical) |
| Version: | 5.1+, 5.1.42-bzr | OS: | Any |
| Assigned to: | Luis Soares | CPU Architecture: | Any |
| Tags: | regression | ||
[26 Nov 2009 7:15]
Valeriy Kravchuk
Verified just as described with recent 5.1.42 from bzr on Linux: openxs@suse:/home2/openxs/dbs/5.1/mysql-test> ./mysql-test-run.pl --suite=rpl bug49119 Logging: ./mysql-test-run.pl --suite=rpl bug49119 100303 14:08:39 [Note] Plugin 'FEDERATED' is disabled. 100303 14:08:39 [Note] Plugin 'ndbcluster' is disabled. MySQL Version 5.1.42 Checking supported features... - using ndbcluster when necessary, mysqld supports it - SSL connections supported - binaries are debug compiled Collecting tests... - adding combinations for rpl vardir: /home2/openxs/dbs/5.1/mysql-test/var Checking leftover processes... - found old pid 6946 in 'mysqld.1.pid', killing it... process did not exist! Removing old var directory... Creating var directory '/home2/openxs/dbs/5.1/mysql-test/var'... Installing system database... Using server port 32769 ============================================================================== TEST RESULT TIME (ms) ------------------------------------------------------------ worker[1] Using MTR_BUILD_THREAD 300, with reserved ports 13000..13009 stop slave; drop table if exists t1,t2,t3,t4,t5,t6,t7,t8,t9; reset master; reset slave; drop table if exists t1,t2,t3,t4,t5,t6,t7,t8,t9; start slave; CREATE TABLE t1(c1 INT); CREATE PROCEDURE p1() SELECT * FROM t1 | rpl.bug49119 'row' [ fail ] Test ended at 2010-03-03 14:08:49 CURRENT_TEST: rpl.bug49119 mysqltest: At line 7: query 'REVOKE EXECUTE ON PROCEDURE p1 FROM 'root'@'localhost'' failed: 2013: Lost connection to MySQL server during query Server [mysqld.1 - pid: 6627, winpid: 6627, exit: 256] failed during test run Server log from this test: 100303 15:08:47 [Note] Plugin 'FEDERATED' is disabled. 100303 15:08:47 [Note] Plugin 'InnoDB' is disabled. 100303 15:08:47 [Note] Plugin 'ndbcluster' is disabled. 100303 15:08:47 [Note] Event Scheduler: Loaded 0 events 100303 15:08:47 [Note] /home2/openxs/dbs/5.1/libexec/mysqld: ready for connections. Version: '5.1.42-debug-log' socket: '/home2/openxs/dbs/5.1/mysql-test/var/tmp/mysqld.1.sock' port: 13000 Source distribution mysqld: protocol.cc:465: void net_end_statement(THD*): Assertion `0' failed. 100303 15:08:49 - mysqld got signal 6 ; This could be because you hit a bug. It is also possible that this binary or one of the libraries it was linked against is corrupt, improperly built, or misconfigured. This error can also be caused by malfunctioning hardware. We will try our best to scrape up some info that will hopefully help diagnose the problem, but since we have already crashed, something is definitely wrong and this may fail. key_buffer_size=1048576 read_buffer_size=131072 max_used_connections=4 max_threads=151 threads_connected=4 It is possible that mysqld could use up to key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 59976 K bytes of memory Hope that's ok; if not, decrease some variables in the equation. thd: 0x8aa0680 Attempting backtrace. You can use the following information to find out where mysqld died. If you see no messages after this, something went terribly wrong... stack_bottom = 0x4056b430 thread_stack 0x30000 /home2/openxs/dbs/5.1/libexec/mysqld(my_print_stacktrace+0x29)[0x86df72c] /home2/openxs/dbs/5.1/libexec/mysqld(handle_segfault+0x253)[0x82929df] [0xffffe420] /lib/tls/libc.so.6(abort+0x1a5)[0x400e6b75] /lib/tls/libc.so.6(__assert_fail+0x103)[0x400de903] /home2/openxs/dbs/5.1/libexec/mysqld(_Z17net_end_statementP3THD+0x1a9)[0x828747f] /home2/openxs/dbs/5.1/libexec/mysqld(_Z16dispatch_command19enum_server_commandP3THDPcj+0x1890)[0x82a272c] /home2/openxs/dbs/5.1/libexec/mysqld(_Z10do_commandP3THD+0x260)[0x82a0b62] /home2/openxs/dbs/5.1/libexec/mysqld(handle_one_connection+0x14e)[0x829ef98] /lib/tls/libpthread.so.0[0x40031aa7] /lib/tls/libc.so.6(__clone+0x5e)[0x40177c2e] Trying to get some variables. Some pointers may be invalid and cause the dump to abort... thd->query at 0x8aa2058 = REVOKE EXECUTE ON PROCEDURE p1 FROM 'root'@'localhost' thd->thread_id=3 thd->killed=NOT_KILLED The manual page at http://dev.mysql.com/doc/mysql/en/crashing.html contains information that should help you find out what is causing the crash. Writing a core file ...
[26 Nov 2009 7:19]
Valeriy Kravchuk
5.0.88 does NOT crash, so this is a regression bug: openxs@suse:/home2/openxs/dbs/5.0/mysql-test> ./mysql-test-run.pl rpl_bug49119 Logging: ./mysql-test-run.pl rpl_bug49119 MySQL Version 5.0.88 Using ndbcluster when necessary, mysqld supports it Setting mysqld to support SSL connections Binaries are debug compiled mysql-test-run: WARNING: Could not find all required ndb binaries, all ndb tests will fail, use --skip-ndbcluster to skip testing it. Using MTR_BUILD_THREAD = 0 Using MASTER_MYPORT = 9306 Using MASTER_MYPORT1 = 9307 Using SLAVE_MYPORT = 9308 Using SLAVE_MYPORT1 = 9309 Using SLAVE_MYPORT2 = 9310 Using NDBCLUSTER_PORT = 9311 Using IM_PORT = 9313 Using IM_MYSQLD1_PORT = 9314 Using IM_MYSQLD2_PORT = 9315 Killing Possible Leftover Processes Removing Stale Files Creating Directories Installing Master Database Installing Slave1 Database ======================================================= Starting Tests in the 'main' suite TEST RESULT TIME (ms) ------------------------------------------------------- rpl_bug49119 [ fail ] mysqltest: At line 7: query 'REVOKE EXECUTE ON PROCEDURE p1 FROM 'root'@'localhost'' failed: 1403: There is no such grant defined for user 'root' on host 'localhost' on routine 'p1' The result from queries just before the failure was: stop slave; drop table if exists t1,t2,t3,t4,t5,t6,t7,t8,t9; reset master; reset slave; drop table if exists t1,t2,t3,t4,t5,t6,t7,t8,t9; start slave; CREATE TABLE t1(c1 INT); CREATE PROCEDURE p1() SELECT * FROM t1 | REVOKE EXECUTE ON PROCEDURE p1 FROM 'root'@'localhost';
[29 Nov 2009 23:28]
Luis Soares
This does not seem to have anything related to the slave at all... Instead, this looks like it is an issue with the master when binlogging is active. Please, check the analysis below. The revoke operation is mostly handled in mysql_routine_grant function. Furthermore, this bug reports a scenario in which a revoke operation is requested, but the actual grant does not exist at that time. This should cause the command to fail with error 1403. However, when the binlog is active, the master will not return (an error in our scenario) from mysql_routine_grant without first checking if it should write to the binlog. Now... At this point, it will cause the statement to be written to the binlog by calling write_bin_log wrapper function, with its second parameter set to TRUE. This parameter value, causes write_bin_log to clear the thread's diagnostics area (meaning that the earlier revoke error, pushed in mysql_routine_grant, is removed). At the time binlogging is done, mysql_routine_grant will resume and return an error, which contradicts write_bin_log actions (the ones that cleared the diagnostics area). So... the result from this is that my_ok will not be called and neither the error will be signaled in the diagnostics area. Consequently, this will cause net_end_statement to trigger the assertion. You can check this with the following test case that does not require a slave (just an active binary log): === TEST CASE: -- source include/have_log_bin.inc CREATE TABLE t1(c1 INT); DELIMITER |; CREATE PROCEDURE p1() SELECT * FROM t1 | DELIMITER ;| REVOKE EXECUTE ON PROCEDURE p1 FROM 'user49119'@'localhost', 'root'@'localhost'; -- exit
[29 Nov 2009 23:45]
Bugs System
A patch for this bug has been committed. After review, it may be pushed to the relevant source trees for release in the next version. You can access the patch from: http://lists.mysql.com/commits/92015 3211 Luis Soares 2009-11-29 BUG#49119: Slave is crashed when replicating 'REVOKE ... ON {PROCEDURE|FUNCTION} FROM ...' The master would hit an assertion when binary loggging was active. This was due to the fact that the thread's diagnostics area was being cleared before writing to the binlog, independently of mysql_routine_grant returning an error or not. When mysql_routine_grant was to return an error, the return value and the diagnostics area contents would mismatch. Consequently, neither my_ok would be called nor an error would be signaled in the diagnostics area, eventually triggering the assertion in net_end_statement. We fix this by not clearing the diagnostics area at binlogging time.
[2 Dec 2009 13:24]
Libing Song
Luis, You are right, It is a crash on master, not on slave.
[4 Dec 2009 13:39]
Andrei Elkin
There should be no error code disabling in the REVOKE query log event. The patch corrects that piece of code. Approved.
[6 Dec 2009 22:44]
Bugs System
A patch for this bug has been committed. After review, it may be pushed to the relevant source trees for release in the next version. You can access the patch from: http://lists.mysql.com/commits/93005 3211 Luis Soares 2009-12-06 BUG#49119: Slave is crashed when replicating 'REVOKE ... ON {PROCEDURE|FUNCTION} FROM ...' The master would hit an assertion when binary log was active. This was due to the fact that the thread's diagnostics area was being cleared before writing to the binlog, independently of mysql_routine_grant returning an error or not. When mysql_routine_grant was to return an error, the return value and the diagnostics area contents would mismatch. Consequently, neither my_ok would be called nor an error would be signaled in the diagnostics area, eventually triggering the assertion in net_end_statement. We fix this by not clearing the diagnostics area at binlogging time.
[6 Dec 2009 22:47]
Bugs System
A patch for this bug has been committed. After review, it may be pushed to the relevant source trees for release in the next version. You can access the patch from: http://lists.mysql.com/commits/93006 3211 Luis Soares 2009-12-06 BUG#49119: Master crashes when executing 'REVOKE ... ON {PROCEDURE|FUNCTION} FROM ...' The master would hit an assertion when binary log was active. This was due to the fact that the thread's diagnostics area was being cleared before writing to the binlog, independently of mysql_routine_grant returning an error or not. When mysql_routine_grant was to return an error, the return value and the diagnostics area contents would mismatch. Consequently, neither my_ok would be called nor an error would be signaled in the diagnostics area, eventually triggering the assertion in net_end_statement. We fix this by not clearing the diagnostics area at binlogging time.
[6 Dec 2009 23:22]
Bugs System
A patch for this bug has been committed. After review, it may be pushed to the relevant source trees for release in the next version. You can access the patch from: http://lists.mysql.com/commits/93010 3211 Luis Soares 2009-12-06 BUG#49119: Master crashes when executing 'REVOKE ... ON {PROCEDURE|FUNCTION} FROM ...' The master would hit an assertion when binary log was active. This was due to the fact that the thread's diagnostics area was being cleared before writing to the binlog, independently of mysql_routine_grant returning an error or not. When mysql_routine_grant was to return an error, the return value and the diagnostics area contents would mismatch. Consequently, neither my_ok would be called nor an error would be signaled in the diagnostics area, eventually triggering the assertion in net_end_statement. We fix this by not clearing the diagnostics area at binlogging time.
[19 Dec 2009 8:28]
Bugs System
Pushed into 6.0.14-alpha (revid:alik@sun.com-20091219082307-f3i4fn0tm8trb3c0) (version source revid:alik@sun.com-20091216180721-eoa754i79j4ssd3m) (merge vers: 6.0.14-alpha) (pib:15)
[19 Dec 2009 8:31]
Bugs System
Pushed into 5.5.1-m2 (revid:alik@sun.com-20091219082021-f34nq4jytwamozz0) (version source revid:alexey.kopytov@sun.com-20091211164058-ycpe0f20d1c4h1gl) (merge vers: 5.5.0-beta) (pib:15)
[19 Dec 2009 8:35]
Bugs System
Pushed into mysql-next-mr (revid:alik@sun.com-20091219082213-nhjjgmphote4ntxj) (version source revid:alik@sun.com-20091216180221-a5ps59gajad3pip9) (pib:15)
[11 Jan 2010 17:34]
Paul DuBois
Noted in 5.5.1, 6.0.14 changelogs.
With binary logging enabled, REVOKE ... ON {PROCEDURE|FUNCTION} FROM
... could cause a crash.
Setting report to NDI pending push to Celosia.
[15 Jan 2010 8:59]
Bugs System
Pushed into 5.1.43 (revid:joro@sun.com-20100115085139-qkh0i0fpohd9u9p5) (version source revid:luis.soares@sun.com-20091206231445-kaz01b23kjm7keyl) (merge vers: 5.1.42) (pib:16)
[15 Jan 2010 18:46]
Paul DuBois
Noted in 5.1.43 changelog. Setting report to NDI pending push to Celosia.
[12 Mar 2010 14:11]
Bugs System
Pushed into 5.1.44-ndb-7.0.14 (revid:jonas@mysql.com-20100312135944-t0z8s1da2orvl66x) (version source revid:jonas@mysql.com-20100312115609-woou0te4a6s4ae9y) (merge vers: 5.1.44-ndb-7.0.14) (pib:16)
[12 Mar 2010 14:28]
Bugs System
Pushed into 5.1.44-ndb-6.2.19 (revid:jonas@mysql.com-20100312134846-tuqhd9w3tv4xgl3d) (version source revid:jonas@mysql.com-20100312060623-mx6407w2vx76h3by) (merge vers: 5.1.44-ndb-6.2.19) (pib:16)
[12 Mar 2010 14:43]
Bugs System
Pushed into 5.1.44-ndb-6.3.33 (revid:jonas@mysql.com-20100312135724-xcw8vw2lu3mijrhn) (version source revid:jonas@mysql.com-20100312103652-snkltsd197l7q2yg) (merge vers: 5.1.44-ndb-6.3.33) (pib:16)
[12 Mar 2010 16:44]
Paul DuBois
Fixed in earlier 5.1.x, 5.5.x.
Description: Slave is crashed when replicating "REVOKE ... ON {PROCEDURE|FUNCTION} FROM 'user1'@'localhost'", if "GRANT ... ON {PROCEDURE|FUNCTION} TO 'user1'@'localhost'" is not executed before it. How to repeat: source include/master-slave.inc; CREATE TABLE t1(c1 INT); DELIMITER |; CREATE PROCEDURE p1() SELECT * FROM t1 | DELIMITER ;| REVOKE EXECUTE ON PROCEDURE p1 FROM 'root'@'localhost'; source include/master-slave-end.inc;