[Maria-discuss] Help needed. Replication slave hangs on 'stop slave; '
Hello, we have upgraded our MySQL Master/Slave server vom 10.1.24 to 10.1.48 on 25.01. Backups worked as usual, but since friday (29.01.) our backups do not work anymore. I have seen that entering a 'stop slave;' on mysql cli hangs forever, while in the background (on a second console, I see the replication going on, but the gtid is far away from the master. According to MaxScale, on the slave it is '0-1-8696229561 and on the master '0-1-8705275411' and not moving forward on the slave.
Slave 'show slave status': MariaDB [(none)]> show slave status\G *************************** 1. row *************************** Slave_IO_State: Waiting for master to send event Master_Host: 172.16.1.1 Master_User: replication_user Master_Port: 3306 Connect_Retry: 10 Master_Log_File: mysql-bin.005595 Read_Master_Log_Pos: 581894706 Relay_Log_File: relay-bin.000002 Relay_Log_Pos: 693 Relay_Master_Log_File: mysql-bin.005587 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: 967647646 Relay_Log_Space: 8205026277 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 Master_SSL_Verify_Server_Cert: No Last_IO_Errno: 0 Last_IO_Error: Last_SQL_Errno: 0 Last_SQL_Error: Replicate_Ignore_Server_Ids: Master_Server_Id: 1 Master_SSL_Crl: Master_SSL_Crlpath: Using_Gtid: Slave_Pos Gtid_IO_Pos: 0-1-8705427292 Replicate_Do_Domain_Ids: Replicate_Ignore_Domain_Ids: Parallel_Mode: optimistic 1 row in set (0.00 sec)
Master status is this: MariaDB [(none)]> show master status\G *************************** 1. row *************************** File: mysql-bin.005595 Position: 581594839 Binlog_Do_DB: Binlog_Ignore_DB: 1 row in set (0.01 sec)
If I try to stop the server it hangs also. Waited half an hour after I saw the backups hanging on the 'stop slave' command, then killed the server with kill -9. It restarted without complaining, but the hang is still occuring when doing a 'stop slave'. Can anybody help me diagnosing and possibly resolving this issue?
Server is a baremetal with battery backed raid10. OS is Centos 7 all updated. Thanks, Thomas
Forgot to attach the error log...it is since the last successfull start of the slave. The line after "2021-02-01 8:32:30" is when hat to kill the server with 'kill -9'.
2021-01-29 3:08:28 139988321904384 [Note] Slave SQL thread initialized, starting replication in log 'mysql-bin.005586' at position 621910335, relay log '/var/lib/mysql/relay-bin.000001' position: 4; GTID position '0-1-8694429449' 2021-01-29 3:08:28 139988858074880 [Note] Slave I/O thread: connected to master 'replication_user@172.16.1.1:3306',replication starts at GTID position '0-1-8694429449' 2021-01-29 6:03:01 139988341872384 [ERROR] SpotSystem.APInventory: Found row where the auto_increment column has the value 0 2021-02-01 8:32:30 139988355536640 [Note] /usr/sbin/mysqld: Normal shutdown 2021-02-01 8:32:30 139988355536640 [Note] Event Scheduler: Purging the queue. 0 events 2021-02-01 8:32:30 139988858074880 [Note] Slave I/O thread exiting, read up to log 'mysql-bin.005595', position 90701825; GTID position 0-1-8704989874 2021-02-01 8:45:13 140290042407168 [Note] InnoDB: Using mutexes to ref count buffer pool pages 2021-02-01 8:45:13 140290042407168 [Note] InnoDB: The InnoDB memory heap is disabled 2021-02-01 8:45:13 140290042407168 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins 2021-02-01 8:45:13 140290042407168 [Note] InnoDB: GCC builtin __atomic_thread_fence() is used for memory barrier 2021-02-01 8:45:13 140290042407168 [Note] InnoDB: Compressed tables use zlib 1.2.7 2021-02-01 8:45:13 140290042407168 [Note] InnoDB: Using Linux native AIO 2021-02-01 8:45:13 140290042407168 [Note] InnoDB: Using SSE crc32 instructions 2021-02-01 8:45:13 140290042407168 [Note] InnoDB: Initializing buffer pool, size = 96.0G 2021-02-01 8:45:16 140290042407168 [Note] InnoDB: Completed initialization of buffer pool 2021-02-01 8:45:17 140290042407168 [Note] InnoDB: Highest supported file format is Barracuda. 2021-02-01 8:45:17 140290042407168 [Note] InnoDB: The log sequence number 8320414590808 in ibdata file do not match the log sequence number 8433639723027 in the ib_logfiles! 2021-02-01 8:45:24 140290042407168 [Note] InnoDB: Restoring possible half-written data pages from the doublewrite buffer... InnoDB: 5 transaction(s) which must be rolled back or cleaned up InnoDB: in total 11 row operations to undo InnoDB: Trx id counter is 33839639552 InnoDB: Last MySQL binlog file position 0 399790365, file name /var/lib/mysql/mysql-bin.001280 2021-02-01 8:45:38 140290042407168 [Note] InnoDB: 128 rollback segment(s) are active. 2021-02-01 8:45:38 140177859147520 [Note] InnoDB: Starting in background the rollback of recovered transactions 2021-02-01 8:45:38 140177859147520 [Note] InnoDB: To roll back: 5 transactions, 11 rows 2021-02-01 8:45:38 140290042407168 [Note] InnoDB: Waiting for purge to start 2021-02-01 8:45:38 140177859147520 [Note] InnoDB: Rollback of trx with id 33839605832 completed 2021-02-01 8:45:38 140177859147520 [Note] InnoDB: Rollback of trx with id 33839605831 completed 2021-02-01 8:45:38 140177859147520 [Note] InnoDB: Rollback of trx with id 33839605828 completed 2021-02-01 8:45:38 140177859147520 [Note] InnoDB: Rollback of trx with id 33839605824 completed 2021-02-01 8:45:38 140177859147520 [Note] InnoDB: Rollback of trx with id 33839605823 completed 2021-02-01 8:45:38 140177859147520 [Note] InnoDB: Rollback of non-prepared transactions completed 2021-02-01 8:45:38 140290042407168 [Note] InnoDB: Percona XtraDB (http://www.percona.com) 5.6.49-89.0 started; log sequence number 8433639723027 2021-02-01 8:45:38 140290042407168 [Note] Plugin 'FEEDBACK' is disabled. 2021-02-01 8:45:38 140290042407168 [Note] Recovering after a crash using /var/lib/mysql/mysql-bin 2021-02-01 8:45:38 140290042407168 [Note] Starting crash recovery... 2021-02-01 8:45:38 140177372579584 [Note] InnoDB: Dumping buffer pool(s) not yet started 2021-02-01 8:45:38 140290042407168 [Note] Crash recovery finished. 2021-02-01 8:45:38 140290042407168 [Note] Server socket created on IP: '::'. 2021-02-01 8:45:38 140290042407168 [Warning] 'user' entry 'root@mysql-a.zcom.it' ignored in --skip-name-resolve mode. 2021-02-01 8:45:38 140290042407168 [Warning] 'proxies_priv' entry '@% root@mysql-a.zcom.it' ignored in --skip-name-resolve mode. 2021-02-01 8:45:40 140290041370368 [Note] Slave I/O thread: connected to master 'replication_user@172.16.1.1:3306',replication starts at GTID position '0-1-8696229561' 2021-02-01 8:45:40 140290041063168 [Note] Slave SQL thread initialized, starting replication in log 'mysql-bin.005586' at position 1073742303, relay log '/var/lib/mysql/relay-bin.000001' position: 4; GTID position '0-1-8696229561' 2021-02-01 8:45:40 140290042407168 [Note] /usr/sbin/mysqld: ready for connections. Version: '10.1.48-MariaDB' socket: '/var/lib/mysql/mysql.sock' port: 3306 MariaDB Server
Since 08:45:40 it is stuck in the console with the 'stop slave;' command....
Am 01.02.2021 um 09:36 schrieb Thomas:
Hello, we have upgraded our MySQL Master/Slave server vom 10.1.24 to 10.1.48 on 25.01. Backups worked as usual, but since friday (29.01.) our backups do not work anymore. I have seen that entering a 'stop slave;' on mysql cli hangs forever, while in the background (on a second console, I see the replication going on, but the gtid is far away from the master. According to MaxScale, on the slave it is '0-1-8696229561 and on the master '0-1-8705275411' and not moving forward on the slave.
Slave 'show slave status': MariaDB [(none)]> show slave status\G *************************** 1. row *************************** Slave_IO_State: Waiting for master to send event Master_Host: 172.16.1.1 Master_User: replication_user Master_Port: 3306 Connect_Retry: 10 Master_Log_File: mysql-bin.005595 Read_Master_Log_Pos: 581894706 Relay_Log_File: relay-bin.000002 Relay_Log_Pos: 693 Relay_Master_Log_File: mysql-bin.005587 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: 967647646 Relay_Log_Space: 8205026277 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 Master_SSL_Verify_Server_Cert: No Last_IO_Errno: 0 Last_IO_Error: Last_SQL_Errno: 0 Last_SQL_Error: Replicate_Ignore_Server_Ids: Master_Server_Id: 1 Master_SSL_Crl: Master_SSL_Crlpath: Using_Gtid: Slave_Pos Gtid_IO_Pos: 0-1-8705427292 Replicate_Do_Domain_Ids: Replicate_Ignore_Domain_Ids: Parallel_Mode: optimistic 1 row in set (0.00 sec)
Master status is this: MariaDB [(none)]> show master status\G *************************** 1. row *************************** File: mysql-bin.005595 Position: 581594839 Binlog_Do_DB: Binlog_Ignore_DB: 1 row in set (0.01 sec)
If I try to stop the server it hangs also. Waited half an hour after I saw the backups hanging on the 'stop slave' command, then killed the server with kill -9. It restarted without complaining, but the hang is still occuring when doing a 'stop slave'. Can anybody help me diagnosing and possibly resolving this issue?
Server is a baremetal with battery backed raid10. OS is Centos 7 all updated. Thanks, Thomas
_______________________________________________ Mailing list: https://launchpad.net/~maria-discuss Post to : maria-discuss@lists.launchpad.net Unsubscribe : https://launchpad.net/~maria-discuss More help : https://help.launchpad.net/ListHelp
the show relaylog events show this:
MariaDB [(none)]> SHOW RELAYLOG EVENTS; +------------------+-----+-------------+-----------+-------------+--------------------------------------------+ | Log_name | Pos | Event_type | Server_id | End_log_pos | Info | +------------------+-----+-------------+-----------+-------------+--------------------------------------------+ | relay-bin.000001 | 4 | Format_desc | 2 | 249 | Server ver: 10.1.48-MariaDB, Binlog ver: 4 | | relay-bin.000001 | 249 | Rotate | 2 | 292 | relay-bin.000002;pos=4 | +------------------+-----+-------------+-----------+-------------+--------------------------------------------+ 2 rows in set (0.00 sec)
it is in this state since this morning I checked it. I looked in the 'relay_log and I see on line 8 the following:
[root@mysql-b mysql]# cat relay-log.info /var/lib/mysql/relay-bin.000002 292 mysql-bin.005587 4 742303 3742303
ar/lib/mysql/relay-bin.000002 190873514 mysql-bin.001280 590663342 /var/lib/mysql/relay-bin.000002 190861291 mysql-bin.001280 590651119 /var/lib/mysql/relay-bin.000002 190861703 mysql-bin.001280 590651531 /var/lib/mysql/relay-bin.000002 188707924 mysql-bin.001280 588497752 /var/lib/mysql/relay-bin.000002 187694443 mysql-bin.001280 587484271 /var/lib/mysql/relay-bin.000002 186471248 mysql-bin.001280 586261076 /var/lib/mysql/relay-bin.000002 179955627 mysql-bin.001280 579745455 /var/lib/mysql/relay-bin.000002 179955627 mysql-bin.001280 579745455 /var/lib/mysql/relay-bin.000002 112346369 mysql-bin.001280 512136197
Why is there always the same relay-bin.000002? And line 8 is imho wrong 'ar/lib/mysql/relay-bin.000002'. Can I change this manually?
Am 01.02.2021 um 10:06 schrieb Thomas:
Forgot to attach the error log...it is since the last successfull start of the slave. The line after "2021-02-01 8:32:30" is when hat to kill the server with 'kill -9'.
2021-01-29 3:08:28 139988321904384 [Note] Slave SQL thread initialized, starting replication in log 'mysql-bin.005586' at position 621910335, relay log '/var/lib/mysql/relay-bin.000001' position: 4; GTID position '0-1-8694429449' 2021-01-29 3:08:28 139988858074880 [Note] Slave I/O thread: connected to master 'replication_user@172.16.1.1:3306',replication starts at GTID position '0-1-8694429449' 2021-01-29 6:03:01 139988341872384 [ERROR] SpotSystem.APInventory: Found row where the auto_increment column has the value 0 2021-02-01 8:32:30 139988355536640 [Note] /usr/sbin/mysqld: Normal shutdown 2021-02-01 8:32:30 139988355536640 [Note] Event Scheduler: Purging the queue. 0 events 2021-02-01 8:32:30 139988858074880 [Note] Slave I/O thread exiting, read up to log 'mysql-bin.005595', position 90701825; GTID position 0-1-8704989874 2021-02-01 8:45:13 140290042407168 [Note] InnoDB: Using mutexes to ref count buffer pool pages 2021-02-01 8:45:13 140290042407168 [Note] InnoDB: The InnoDB memory heap is disabled 2021-02-01 8:45:13 140290042407168 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins 2021-02-01 8:45:13 140290042407168 [Note] InnoDB: GCC builtin __atomic_thread_fence() is used for memory barrier 2021-02-01 8:45:13 140290042407168 [Note] InnoDB: Compressed tables use zlib 1.2.7 2021-02-01 8:45:13 140290042407168 [Note] InnoDB: Using Linux native AIO 2021-02-01 8:45:13 140290042407168 [Note] InnoDB: Using SSE crc32 instructions 2021-02-01 8:45:13 140290042407168 [Note] InnoDB: Initializing buffer pool, size = 96.0G 2021-02-01 8:45:16 140290042407168 [Note] InnoDB: Completed initialization of buffer pool 2021-02-01 8:45:17 140290042407168 [Note] InnoDB: Highest supported file format is Barracuda. 2021-02-01 8:45:17 140290042407168 [Note] InnoDB: The log sequence number 8320414590808 in ibdata file do not match the log sequence number 8433639723027 in the ib_logfiles! 2021-02-01 8:45:24 140290042407168 [Note] InnoDB: Restoring possible half-written data pages from the doublewrite buffer... InnoDB: 5 transaction(s) which must be rolled back or cleaned up InnoDB: in total 11 row operations to undo InnoDB: Trx id counter is 33839639552 InnoDB: Last MySQL binlog file position 0 399790365, file name /var/lib/mysql/mysql-bin.001280 2021-02-01 8:45:38 140290042407168 [Note] InnoDB: 128 rollback segment(s) are active. 2021-02-01 8:45:38 140177859147520 [Note] InnoDB: Starting in background the rollback of recovered transactions 2021-02-01 8:45:38 140177859147520 [Note] InnoDB: To roll back: 5 transactions, 11 rows 2021-02-01 8:45:38 140290042407168 [Note] InnoDB: Waiting for purge to start 2021-02-01 8:45:38 140177859147520 [Note] InnoDB: Rollback of trx with id 33839605832 completed 2021-02-01 8:45:38 140177859147520 [Note] InnoDB: Rollback of trx with id 33839605831 completed 2021-02-01 8:45:38 140177859147520 [Note] InnoDB: Rollback of trx with id 33839605828 completed 2021-02-01 8:45:38 140177859147520 [Note] InnoDB: Rollback of trx with id 33839605824 completed 2021-02-01 8:45:38 140177859147520 [Note] InnoDB: Rollback of trx with id 33839605823 completed 2021-02-01 8:45:38 140177859147520 [Note] InnoDB: Rollback of non-prepared transactions completed 2021-02-01 8:45:38 140290042407168 [Note] InnoDB: Percona XtraDB (http://www.percona.com) 5.6.49-89.0 started; log sequence number 8433639723027 2021-02-01 8:45:38 140290042407168 [Note] Plugin 'FEEDBACK' is disabled. 2021-02-01 8:45:38 140290042407168 [Note] Recovering after a crash using /var/lib/mysql/mysql-bin 2021-02-01 8:45:38 140290042407168 [Note] Starting crash recovery... 2021-02-01 8:45:38 140177372579584 [Note] InnoDB: Dumping buffer pool(s) not yet started 2021-02-01 8:45:38 140290042407168 [Note] Crash recovery finished. 2021-02-01 8:45:38 140290042407168 [Note] Server socket created on IP: '::'. 2021-02-01 8:45:38 140290042407168 [Warning] 'user' entry 'root@mysql-a.zcom.it' ignored in --skip-name-resolve mode. 2021-02-01 8:45:38 140290042407168 [Warning] 'proxies_priv' entry '@% root@mysql-a.zcom.it' ignored in --skip-name-resolve mode. 2021-02-01 8:45:40 140290041370368 [Note] Slave I/O thread: connected to master 'replication_user@172.16.1.1:3306',replication starts at GTID position '0-1-8696229561' 2021-02-01 8:45:40 140290041063168 [Note] Slave SQL thread initialized, starting replication in log 'mysql-bin.005586' at position 1073742303, relay log '/var/lib/mysql/relay-bin.000001' position: 4; GTID position '0-1-8696229561' 2021-02-01 8:45:40 140290042407168 [Note] /usr/sbin/mysqld: ready for connections. Version: '10.1.48-MariaDB' socket: '/var/lib/mysql/mysql.sock' port: 3306 MariaDB Server
Since 08:45:40 it is stuck in the console with the 'stop slave;' command....
Am 01.02.2021 um 09:36 schrieb Thomas:
Hello, we have upgraded our MySQL Master/Slave server vom 10.1.24 to 10.1.48 on 25.01. Backups worked as usual, but since friday (29.01.) our backups do not work anymore. I have seen that entering a 'stop slave;' on mysql cli hangs forever, while in the background (on a second console, I see the replication going on, but the gtid is far away from the master. According to MaxScale, on the slave it is '0-1-8696229561 and on the master '0-1-8705275411' and not moving forward on the slave.
Slave 'show slave status': MariaDB [(none)]> show slave status\G *************************** 1. row *************************** Slave_IO_State: Waiting for master to send event Master_Host: 172.16.1.1 Master_User: replication_user Master_Port: 3306 Connect_Retry: 10 Master_Log_File: mysql-bin.005595 Read_Master_Log_Pos: 581894706 Relay_Log_File: relay-bin.000002 Relay_Log_Pos: 693 Relay_Master_Log_File: mysql-bin.005587 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: 967647646 Relay_Log_Space: 8205026277 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 Master_SSL_Verify_Server_Cert: No Last_IO_Errno: 0 Last_IO_Error: Last_SQL_Errno: 0 Last_SQL_Error: Replicate_Ignore_Server_Ids: Master_Server_Id: 1 Master_SSL_Crl: Master_SSL_Crlpath: Using_Gtid: Slave_Pos Gtid_IO_Pos: 0-1-8705427292 Replicate_Do_Domain_Ids: Replicate_Ignore_Domain_Ids: Parallel_Mode: optimistic 1 row in set (0.00 sec)
Master status is this: MariaDB [(none)]> show master status\G *************************** 1. row *************************** File: mysql-bin.005595 Position: 581594839 Binlog_Do_DB: Binlog_Ignore_DB: 1 row in set (0.01 sec)
If I try to stop the server it hangs also. Waited half an hour after I saw the backups hanging on the 'stop slave' command, then killed the server with kill -9. It restarted without complaining, but the hang is still occuring when doing a 'stop slave'. Can anybody help me diagnosing and possibly resolving this issue?
Server is a baremetal with battery backed raid10. OS is Centos 7 all updated. Thanks, Thomas
_______________________________________________ Mailing list: https://launchpad.net/~maria-discuss Post to : maria-discuss@lists.launchpad.net Unsubscribe : https://launchpad.net/~maria-discuss More help : https://help.launchpad.net/ListHelp
_______________________________________________ Mailing list: https://launchpad.net/~maria-discuss Post to : maria-discuss@lists.launchpad.net Unsubscribe : https://launchpad.net/~maria-discuss More help : https://help.launchpad.net/ListHelp
Thomas thomas@plant.systems writes:
Hello,
Howdy, Tomas.
we have upgraded our MySQL Master/Slave server vom 10.1.24 to 10.1.48 on 25.01. Backups worked as usual, but since friday (29.01.) our backups do not work anymore. I have seen that entering a 'stop slave;' on mysql cli hangs forever, while in the background (on a second console, I see the replication going on, but the gtid is far away from the master. According to MaxScale, on the slave it is '0-1-8696229561
So select @@global.gtid_slave_pos = 0-1-8696229561 remains all the time since
2021-02-01 8:45:40 140290041063168 [Note] Slave SQL thread initialized, starting replication in log 'mysql-bin.005586' at position 1073742303, relay log '/var/lib/mysql/relay-bin.000001' position: 4; GTID position '0-1-8696229561'
(paste from a followup mail)? And the same to Exec_Master_Log_Pos: 967647646 that also has not moved? As you mention backup, could it have been running to block slave thread(s).. Could you please make few selects:
#--connection slave show processlist; show slave status; select @@global.gtid_slave_pos; select @@global.slave_parallel_threads; select @@global.slave_parallel_mode;
It may be interesting to see what are events starting from mysql-bin.005587:967647646 unless it gets clear from show-processist results.
I'll try to help.
Cheers,
Andrei
and on the master '0-1-8705275411' and not moving forward on the slave.
Slave 'show slave status': MariaDB [(none)]> show slave status\G *************************** 1. row *************************** Slave_IO_State: Waiting for master to send event Master_Host: 172.16.1.1 Master_User: replication_user Master_Port: 3306 Connect_Retry: 10 Master_Log_File: mysql-bin.005595 Read_Master_Log_Pos: 581894706 Relay_Log_File: relay-bin.000002 Relay_Log_Pos: 693 Relay_Master_Log_File: mysql-bin.005587 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: 967647646 Relay_Log_Space: 8205026277 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 Master_SSL_Verify_Server_Cert: No Last_IO_Errno: 0 Last_IO_Error: Last_SQL_Errno: 0 Last_SQL_Error: Replicate_Ignore_Server_Ids: Master_Server_Id: 1 Master_SSL_Crl: Master_SSL_Crlpath: Using_Gtid: Slave_Pos Gtid_IO_Pos: 0-1-8705427292 Replicate_Do_Domain_Ids: Replicate_Ignore_Domain_Ids: Parallel_Mode: optimistic 1 row in set (0.00 sec)
Master status is this: MariaDB [(none)]> show master status\G *************************** 1. row *************************** File: mysql-bin.005595 Position: 581594839 Binlog_Do_DB: Binlog_Ignore_DB: 1 row in set (0.01 sec)
If I try to stop the server it hangs also. Waited half an hour after I saw the backups hanging on the 'stop slave' command, then killed the server with kill -9. It restarted without complaining, but the hang is still occuring when doing a 'stop slave'. Can anybody help me diagnosing and possibly resolving this issue?
Hi,
thanks for the reply. yes, Exec_Master_Log_Pos: 967647646 stays always the same. I attaced a file with the data you requested. Seems there is a process stuck with "Waiting for table metadata lock ".
Am 01.02.2021 um 11:32 schrieb andrei.elkin@pp.inet.fi:
Thomas thomas@plant.systems writes:
Hello,
Howdy, Tomas.
we have upgraded our MySQL Master/Slave server vom 10.1.24 to 10.1.48 on 25.01. Backups worked as usual, but since friday (29.01.) our backups do not work anymore. I have seen that entering a 'stop slave;' on mysql cli hangs forever, while in the background (on a second console, I see the replication going on, but the gtid is far away from the master. According to MaxScale, on the slave it is '0-1-8696229561
So select @@global.gtid_slave_pos = 0-1-8696229561 remains all the time since
2021-02-01 8:45:40 140290041063168 [Note] Slave SQL thread initialized, starting replication in log 'mysql-bin.005586' at position 1073742303, relay log '/var/lib/mysql/relay-bin.000001' position: 4; GTID position '0-1-8696229561'
(paste from a followup mail)? And the same to Exec_Master_Log_Pos: 967647646 that also has not moved? As you mention backup, could it have been running to block slave thread(s).. Could you please make few selects:
#--connection slave show processlist; show slave status; select @@global.gtid_slave_pos; select @@global.slave_parallel_threads; select @@global.slave_parallel_mode;
It may be interesting to see what are events starting from mysql-bin.005587:967647646 unless it gets clear from show-processist results.
I'll try to help.
Cheers,
Andrei
and on the master '0-1-8705275411' and not moving forward on the slave.
Slave 'show slave status': MariaDB [(none)]> show slave status\G *************************** 1. row *************************** Slave_IO_State: Waiting for master to send event Master_Host: 172.16.1.1 Master_User: replication_user Master_Port: 3306 Connect_Retry: 10 Master_Log_File: mysql-bin.005595 Read_Master_Log_Pos: 581894706 Relay_Log_File: relay-bin.000002 Relay_Log_Pos: 693 Relay_Master_Log_File: mysql-bin.005587 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: 967647646 Relay_Log_Space: 8205026277 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 Master_SSL_Verify_Server_Cert: No Last_IO_Errno: 0 Last_IO_Error: Last_SQL_Errno: 0 Last_SQL_Error: Replicate_Ignore_Server_Ids: Master_Server_Id: 1 Master_SSL_Crl: Master_SSL_Crlpath: Using_Gtid: Slave_Pos Gtid_IO_Pos: 0-1-8705427292 Replicate_Do_Domain_Ids: Replicate_Ignore_Domain_Ids: Parallel_Mode: optimistic 1 row in set (0.00 sec)
Master status is this: MariaDB [(none)]> show master status\G *************************** 1. row *************************** File: mysql-bin.005595 Position: 581594839 Binlog_Do_DB: Binlog_Ignore_DB: 1 row in set (0.01 sec)
If I try to stop the server it hangs also. Waited half an hour after I saw the backups hanging on the 'stop slave' command, then killed the server with kill -9. It restarted without complaining, but the hang is still occuring when doing a 'stop slave'. Can anybody help me diagnosing and possibly resolving this issue?
Hello,
I changed to "slave-parallel-mode = conservative" from "optimistic" and now it is applying all the updates since friday. Hope this was the problem....I will write again when it finishes if all is ok.
Many thanks for your help.
Am 01.02.2021 um 11:49 schrieb Thomas:
Hi,
thanks for the reply. yes, Exec_Master_Log_Pos: 967647646 stays always the same. I attaced a file with the data you requested. Seems there is a process stuck with "Waiting for table metadata lock ".
Am 01.02.2021 um 11:32 schrieb andrei.elkin@pp.inet.fi:
Thomas thomas@plant.systems writes:
Hello,
Howdy, Tomas.
we have upgraded our MySQL Master/Slave server vom 10.1.24 to 10.1.48 on 25.01. Backups worked as usual, but since friday (29.01.) our backups do not work anymore. I have seen that entering a 'stop slave;' on mysql cli hangs forever, while in the background (on a second console, I see the replication going on, but the gtid is far away from the master. According to MaxScale, on the slave it is '0-1-8696229561
So select @@global.gtid_slave_pos = 0-1-8696229561 remains all the time since
2021-02-01 8:45:40 140290041063168 [Note] Slave SQL thread initialized, starting replication in log 'mysql-bin.005586' at position 1073742303, relay log '/var/lib/mysql/relay-bin.000001' position: 4; GTID position '0-1-8696229561'
(paste from a followup mail)? And the same to Exec_Master_Log_Pos: 967647646 that also has not moved? As you mention backup, could it have been running to block slave thread(s).. Could you please make few selects:
#--connection slave show processlist; show slave status; select @@global.gtid_slave_pos; select @@global.slave_parallel_threads; select @@global.slave_parallel_mode;
It may be interesting to see what are events starting from mysql-bin.005587:967647646 unless it gets clear from show-processist results.
I'll try to help.
Cheers,
Andrei
and on the master '0-1-8705275411' and not moving forward on the slave.
Slave 'show slave status': MariaDB [(none)]> show slave status\G *************************** 1. row *************************** Slave_IO_State: Waiting for master to send event Master_Host: 172.16.1.1 Master_User: replication_user Master_Port: 3306 Connect_Retry: 10 Master_Log_File: mysql-bin.005595 Read_Master_Log_Pos: 581894706 Relay_Log_File: relay-bin.000002 Relay_Log_Pos: 693 Relay_Master_Log_File: mysql-bin.005587 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: 967647646 Relay_Log_Space: 8205026277 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 Master_SSL_Verify_Server_Cert: No Last_IO_Errno: 0 Last_IO_Error: Last_SQL_Errno: 0 Last_SQL_Error: Replicate_Ignore_Server_Ids: Master_Server_Id: 1 Master_SSL_Crl: Master_SSL_Crlpath: Using_Gtid: Slave_Pos Gtid_IO_Pos: 0-1-8705427292 Replicate_Do_Domain_Ids: Replicate_Ignore_Domain_Ids: Parallel_Mode: optimistic 1 row in set (0.00 sec)
Master status is this: MariaDB [(none)]> show master status\G *************************** 1. row *************************** File: mysql-bin.005595 Position: 581594839 Binlog_Do_DB: Binlog_Ignore_DB: 1 row in set (0.01 sec)
If I try to stop the server it hangs also. Waited half an hour after I saw the backups hanging on the 'stop slave' command, then killed the server with kill -9. It restarted without complaining, but the hang is still occuring when doing a 'stop slave'. Can anybody help me diagnosing and possibly resolving this issue?
_______________________________________________ Mailing list: https://launchpad.net/~maria-discuss Post to : maria-discuss@lists.launchpad.net Unsubscribe : https://launchpad.net/~maria-discuss More help : https://help.launchpad.net/ListHelp
Thomas thomas@plant.systems writes:
Hello,
I changed to "slave-parallel-mode = conservative" from "optimistic" and now it is applying all the updates since friday. Hope this was the problem....I will write again when it finishes if all is ok.
Many thanks for your help.
And you too! Now having the processlist I see it's MDEV-17515, a patch at reviewing.
Cheers,
Andrei
Am 01.02.2021 um 11:49 schrieb Thomas:
Hi,
thanks for the reply. yes, Exec_Master_Log_Pos: 967647646 stays always the same. I attaced a file with the data you requested. Seems there is a process stuck with "Waiting for table metadata lock ".
Slave has finished applying the 'backlog' of all transactions and is running fine for now. Should I stop, for the time until the patch you mentioned is released, doing an optimize of the tables on the master server?
Am 01.02.2021 um 14:39 schrieb andrei.elkin@pp.inet.fi:
Thomas thomas@plant.systems writes:
Hello,
I changed to "slave-parallel-mode = conservative" from "optimistic" and now it is applying all the updates since friday. Hope this was the problem....I will write again when it finishes if all is ok.
Many thanks for your help.
And you too! Now having the processlist I see it's MDEV-17515, a patch at reviewing.
Cheers,
Andrei
Am 01.02.2021 um 11:49 schrieb Thomas:
Hi,
thanks for the reply. yes, Exec_Master_Log_Pos: 967647646 stays always the same. I attaced a file with the data you requested. Seems there is a process stuck with "Waiting for table metadata lock ".
participants (2)
-
andrei.elkin＠pp.inet.fi -
Thomas