MySQL Bugs: #14614: TRIGGER crashing on UPDATE if other database selected

Bug #14614	TRIGGER crashing on UPDATE if other database selected
Submitted:	3 Nov 2005 16:58	Modified:	21 Dec 2005 8:32
Reporter:	Beat Vontobel (Silver Quality Contributor) (OCA)	Email Updates:
Status:	Closed	Impact on me:	None
Category:	MySQL Server: Replication	Severity:	S1 (Critical)
Version:	5.0.15-standard-log-i686-glibc23	OS:	Linux (SuSE Linux 2.4.21-273-smp4G)
Assigned to:	Alexander Ivanov	CPU Architecture:	Any

Description:
MySQL replication slave servers crash on some BEFORE UPDATE TRIGGERs if the UPDATE query is not executed in the database where the table with the TRIGGER resides but from another default database. This happened on our production servers with a custom my.cnf as well as in a test environment with the default my-medium.cnf.

mysqld got signal 11;
This could be because you hit a bug. [...]

key_buffer_size=134217728
read_buffer_size=4190208
max_used_connections=2
max_connections=200
threads_connected=0
It is possible that mysqld could use up to 
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_connections = 1768670 K
bytes of memory
Hope that's ok; if not, decrease some variables in the equation.

thd=0x8a930e8
Attempting backtrace. [...]
Cannot determine thread, fp=0x4e019be8, backtrace may not be correct.
Stack range sanity check OK, backtrace follows:
0x814e7f8 handle_segfault + 356
0x4004e96c _end + 934387484
0x40049f02 _end + 934368434
0x40173266 _end + 935585814
0x81f8bb3 _Z15mysql_change_dbP3THDPKcb + 119
0x8240d56 _Z13sp_use_new_dbP3THDPcS1_jbPb + 94
0x823aee0 _ZN7sp_head7executeEP3THD + 1500
0x823b16b _ZN7sp_head16execute_functionEP3THDPP4ItemjS4_ + 491
0x8245276 _ZN19Table_triggers_list16process_triggersEP3THD14trg_event_type20trg_action_time_typeb + 98
0x8185362 _Z36fill_record_n_invoke_before_triggersP3THDR4ListI4ItemES4_bP19Table_triggers_list14trg_event_type + 62
0x81b15d8 _Z12mysql_updateP3THDP13st_table_listR4ListI4ItemES6_PS4_jP8st_ordery15enum_duplicatesb + 2076
0x8162e04 _Z21mysql_execute_commandP3THD + 3828
0x8168d82 _Z11mysql_parseP3THDPcj + 306
0x81bf14b _ZN15Query_log_event10exec_eventEP17st_relay_log_infoPKcj + 1467
0x81beb8c _ZN15Query_log_event10exec_eventEP17st_relay_log_info + 24
0x8222586 _Z20exec_relay_log_eventP3THDP17st_relay_log_info + 610
0x8220387 handle_slave_sql + 999
0x40048f60 _end + 934364432
0x401db327 _end + 936011991
New value of fp=(nil) failed sanity check, terminating stack trace!
Please read [...], so please do resolve it
Trying to get some variables.
Some pointers may be invalid and cause the dump to abort...
thd->query at 0x8c7e705 = UPDATE `met_data`.`swissmetnet_sdm` SET `lum` = ROUND(POW(10, (`lum_old` + 245) / 100)) WHERE 
`datetime` > NOW() - INTERVAL 7 DAY AND `lum` IS NULL AND `lum_old` IS NOT NULL
thd->thread_id=2
[...]
Number of processes running now: 0

How to repeat:
Set up a master/slave replication environment with the default install of 5.0.15-standard-log-i686-glibc23 on Linux. We used my-medium.cnf for the tests and just changed the id for one of the servers and set up a root@% account on the master for the replication slave to login. No other changes.

Use the test database on the master and load the attached tables from test.sql. Then switch the database (that's the important step) and execute an update query against the table with the triggers:

# mysql test
...
mysql> source test.sql
...
mysql> use mysql
...
mysql> UPDATE `test`.`swissmetnet_sdm` SET `lum` = 1 WHERE `datetime` > NOW() - INTERVAL 7 DAY AND `lum` IS NULL;
...

The replication slave will now crash. The master is not affected.

Suggested fix:
-

With latest source I was unable to repeat the crash, however the server
slave displayed the error message:

Error: Freeing wrong aligned pointer at line 1165, 'sql_db.cc'

Then I am marking as verified for further analyze of replication team
regarding that error message.

051104 12:30:19 [Note] Slave SQL thread initialized, starting replication in log 'mysql-bin.000001' at position 226, relay log './hegel-relay-bin.000001' position: 4
051104 12:30:19 [Note] Slave I/O thread: connected to master 'slaveuser@localhost:3306',  replication started in log 'mysql-bin.000001' at position 226
051104 12:30:19 [Note] next log './hegel-relay-bin.000002' is currently active
Error: Freeing wrong aligned pointer at line 1165, 'sql_db.cc'

miguel@hegel:~/dbs/5.0> bin/mysql --defaults-file=/home/miguel/dbs/5.0/var/my.cnf -uroot --prompt="master >"
Welcome to the MySQL monitor.  Commands end with ; or \g.
Your MySQL connection id is 1 to server version: 5.0.16-debug-log

Type 'help;' or '\h' for help. Type '\c' to clear the buffer.

master >grant all on *.* to 'slaveuser'@'localhost' identified by 'slaveuser';
Query OK, 0 rows affected (0.00 sec)

master >show master status;
+------------------+----------+--------------+------------------+
| File             | Position | Binlog_Do_DB | Binlog_Ignore_DB |
+------------------+----------+--------------+------------------+
| mysql-bin.000001 |      226 |              |                  |
+------------------+----------+--------------+------------------+
1 row in set (0.00 sec)

master >use test
Database changed
master >source /home/miguel/a/test.sql
Query OK, 0 rows affected (0.00 sec)

<cut>

Query OK, 0 rows affected (0.00 sec)

master >use mysql
Database changed
master >UPDATE `test`.`swissmetnet_sdm` SET `lum` = 1 WHERE `datetime` > NOW() -
    -> INTERVAL 7 DAY AND `lum` IS NULL;
Query OK, 1139 rows affected (1.25 sec)
Rows matched: 1139  Changed: 1139  Warnings: 0

master >

miguel@hegel:~/dbs/5.0s> bin/mysql --defaults-file=/home/miguel/dbs/5.0s/var/my.cnf -uroot --prompt="slave >"
Welcome to the MySQL monitor.  Commands end with ; or \g.
Your MySQL connection id is 1 to server version: 5.0.16-debug-log

Type 'help;' or '\h' for help. Type '\c' to clear the buffer.

slave >CHANGE MASTER TO
    -> MASTER_HOST='localhost',
    -> MASTER_USER='slaveuser',
    -> MASTER_PASSWORD='slaveuser',
    -> MASTER_LOG_FILE='mysql-bin.000001',
    -> MASTER_LOG_POS=226;
Query OK, 0 rows affected (0.24 sec)

slave >slave start;
Query OK, 0 rows affected (0.01 sec)

slave >show slave status\G
*************************** 1. row ***************************
             Slave_IO_State: Waiting for master to send event
                Master_Host: localhost
                Master_User: slaveuser
                Master_Port: 3306
              Connect_Retry: 60
            Master_Log_File: mysql-bin.000001
        Read_Master_Log_Pos: 226
             Relay_Log_File: hegel-relay-bin.000002
              Relay_Log_Pos: 235
      Relay_Master_Log_File: mysql-bin.000001
           Slave_IO_Running: Yes
          Slave_SQL_Running: Yes
            Replicate_Do_DB: 
        Replicate_Ignore_DB: 
         Replicate_Do_Table: 
     Replicate_Ignore_Table: 
    Replicate_Wild_Do_Table: 
Replicate_Wild_Ignore_Table: 
                 Last_Errno: 0
                 Last_Error: 
               Skip_Counter: 0
        Exec_Master_Log_Pos: 226
            Relay_Log_Space: 235
            Until_Condition: None
             Until_Log_File: 
              Until_Log_Pos: 0
         Master_SSL_Allowed: No
         Master_SSL_CA_File: 
         Master_SSL_CA_Path: 
            Master_SSL_Cert: 
          Master_SSL_Cipher: 
             Master_SSL_Key: 
      Seconds_Behind_Master: 0
1 row in set (0.00 sec)

slave >show slave status\G
*************************** 1. row ***************************
             Slave_IO_State: Waiting for master to send event
                Master_Host: localhost
                Master_User: slaveuser
                Master_Port: 3306
              Connect_Retry: 60
            Master_Log_File: mysql-bin.000001
        Read_Master_Log_Pos: 181494
             Relay_Log_File: hegel-relay-bin.000002
              Relay_Log_Pos: 181503
      Relay_Master_Log_File: mysql-bin.000001
           Slave_IO_Running: Yes
          Slave_SQL_Running: Yes
            Replicate_Do_DB: 
        Replicate_Ignore_DB: 
         Replicate_Do_Table: 
     Replicate_Ignore_Table: 
    Replicate_Wild_Do_Table: 
Replicate_Wild_Ignore_Table: 
                 Last_Errno: 0
                 Last_Error: 
               Skip_Counter: 0
        Exec_Master_Log_Pos: 181494
            Relay_Log_Space: 181503
            Until_Condition: None
             Until_Log_File: 
              Until_Log_Pos: 0
         Master_SSL_Allowed: No
         Master_SSL_CA_File: 
         Master_SSL_CA_Path: 
            Master_SSL_Cert: 
          Master_SSL_Cipher: 
             Master_SSL_Key: 
      Seconds_Behind_Master: 0
1 row in set (0.01 sec)

slave >

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/65

Fixed in 5.0.18

Thank you for your bug report. This issue has been committed to our
source repository of that product and will be incorporated into the
next release.

If necessary, you can access the source repository and build the latest
available version, including the bugfix, yourself. More information 
about accessing the source trees is available at
    http://www.mysql.com/doc/en/Installing_source_tree.html

Additional info:

Documented in 5.0.18 changelog. Closed bug.