Details
-
Bug
-
Status: Closed (View Workflow)
-
Major
-
Resolution: Cannot Reproduce
-
10.1
-
None
Description
http://buildbot.askmonty.org/buildbot/builders/kvm-fulltest-big/builds/1833/steps/mtr_nm/logs/stdio
rpl.rpl_non_direct_row_mixing_engines 'row,xtradb' w2 [ fail ]
|
Test ended at 2018-05-27 02:17:15
|
|
|
CURRENT_TEST: rpl.rpl_non_direct_row_mixing_engines
|
=== SHOW MASTER STATUS ===
|
---- 1. ----
|
File slave-bin.000001
|
Position 153157
|
Binlog_Do_DB
|
Binlog_Ignore_DB
|
==========================
|
|
|
=== SHOW SLAVE STATUS ===
|
---- 1. ----
|
Slave_IO_State Waiting for master to send event
|
Master_Host 127.0.0.1
|
Master_User root
|
Master_Port 16020
|
Connect_Retry 1
|
Master_Log_File master-bin.000001
|
Read_Master_Log_Pos 186436
|
Relay_Log_File slave-relay-bin.000002
|
Relay_Log_Pos 154086
|
Relay_Master_Log_File master-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 153797
|
Relay_Log_Space 187023
|
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 402
|
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 No
|
Gtid_IO_Pos
|
Replicate_Do_Domain_Ids
|
Replicate_Ignore_Domain_Ids
|
Parallel_Mode conservative
|
=========================
|
|
|
=== SHOW PROCESSLIST ===
|
---- 1. ----
|
Id 4
|
User root
|
Host localhost:45332
|
db test
|
Command Sleep
|
Time 1095
|
State
|
Info
|
Progress 0.000
|
---- 2. ----
|
Id 5
|
User root
|
Host localhost:45334
|
db test
|
Command Sleep
|
Time 1095
|
State
|
Info
|
Progress 0.000
|
---- 3. ----
|
Id 6
|
User system user
|
Host
|
db
|
Command Connect
|
Time 1095
|
State Waiting for master to send event
|
Info
|
Progress 0.000
|
---- 4. ----
|
Id 7
|
User system user
|
Host
|
db test
|
Command Connect
|
Time 401
|
State Unlocking tables
|
Info DROP TABLE IF EXISTS `tt_xx_7`,`nt_xx_7` /* generated by server */
|
Progress 0.000
|
---- 5. ----
|
Id 8
|
User root
|
Host localhost:45346
|
db test
|
Command Query
|
Time 0
|
State init
|
Info SHOW PROCESSLIST
|
Progress 0.000
|
---- 6. ----
|
Id 9
|
User root
|
Host localhost:45348
|
db test
|
Command Sleep
|
Time 1095
|
State
|
Info
|
Progress 0.000
|
========================
|
|
|
analyze: sync_with_master
|
mysqltest: In included file "./extra/rpl_tests/rpl_mixing_engines.test":
|
included from /mnt/buildbot/build/mariadb-10.1.34/mysql-test/suite/rpl/t/rpl_non_direct_row_mixing_engines.test at line 15:
|
At line 1803: sync_slave_with_master failed: 'select master_pos_wait('master-bin.000001', 186436, 300, '')' returned -1 indicating timeout after 300 seconds
|
|
|
The result from queries just before the failure was:
|
< snip >
|
-e-e-e-e-e-e-e-e-e-e-e- >> set-NT << -e-e-e-e-e-e-e-e-e-e-e-
|
-b-b-b-b-b-b-b-b-b-b-b- >> R << -b-b-b-b-b-b-b-b-b-b-b-
|
ROLLBACK;
|
Warnings:
|
Warning # Some non-transactional changed tables couldn't be rolled back
|
include/show_binlog_events.inc
|
-e-e-e-e-e-e-e-e-e-e-e- >> R << -e-e-e-e-e-e-e-e-e-e-e-
|
-b-b-b-b-b-b-b-b-b-b-b- >> B set-T set-NT R << -b-b-b-b-b-b-b-b-b-b-b-
|
include/show_binlog_events.inc
|
Log_name Pos Event_type Server_id End_log_pos Info
|
master-bin.000001 # Gtid # # BEGIN GTID #-#-#
|
master-bin.000001 # Table_map # # table_id: # (test.nt_3)
|
master-bin.000001 # Table_map # # table_id: # (test.nt_3)
|
master-bin.000001 # Write_rows_v1 # # table_id: # flags: STMT_END_F
|
master-bin.000001 # Query # # COMMIT
|
-e-e-e-e-e-e-e-e-e-e-e- >> B set-T set-NT R << -e-e-e-e-e-e-e-e-e-e-e-
|
|
|
###################################################################################
|
# CHECK CONSISTENCY
|
###################################################################################
|
|
|
More results from queries before failure can be found in /mnt/buildbot/build/mariadb-10.1.34/mysql-test/var/2/log/rpl_non_direct_row_mixing_engines.log
|
|
|
|
|
== /mnt/buildbot/build/mariadb-10.1.34/mysql-test/var/2/tmp/analyze-sync_with_master-mysqld.1.err ==
|
|
|
############################## default ##############################
|
|
|
**** SHOW WARNINGS on default ****
|
SHOW WARNINGS;
|
Level Code Message
|
|
|
**** SELECT replication-related variables on default ****
|
SELECT NOW(), @@SERVER_ID;
|
NOW() @@SERVER_ID
|
2018-05-27 02:17:14 1
|
|
|
**** SHOW SLAVE STATUS on default ****
|
SHOW SLAVE STATUS;
|
|
|
**** SHOW MASTER STATUS on default ****
|
SHOW MASTER STATUS;
|
File master-bin.000001
|
Position 186436
|
Binlog_Do_DB
|
Binlog_Ignore_DB
|
|
|
**** SHOW SLAVE HOSTS on default ****
|
SHOW SLAVE HOSTS;
|
Server_id 2
|
Host 127.0.0.1
|
Port 16021
|
Master_id 1
|
|
|
**** SHOW PROCESSLIST on default ****
|
SHOW PROCESSLIST;
|
Id User Host db Command Time State Info Progress
|
7 root localhost:40082 NULL Binlog Dump 1100 Master has sent all binlog to slave; waiting for binlog to be updated NULL 0.000
|
1739 root localhost NULL Query 0 init SHOW PROCESSLIST 0.000
|
|
|
**** SHOW BINARY LOGS on default ****
|
SHOW BINARY LOGS;
|
Log_name File_size
|
master-bin.000001 186436
|
|
|
**** SHOW BINLOG EVENTS on default ****
|
binlog_name = 'master-bin.000001'
|
SHOW BINLOG EVENTS IN 'master-bin.000001';
|
Log_name Pos Event_type Server_id End_log_pos Info
|
master-bin.000001 4 Format_desc 1 249 Server ver: 10.1.34-MariaDB, Binlog ver: 4
|
master-bin.000001 249 Gtid_list 1 274 []
|
master-bin.000001 274 Binlog_checkpoint 1 314 master-bin.000001
|
master-bin.000001 314 Gtid 1 352 BEGIN GTID 0-1-1
|
master-bin.000001 352 Table_map 1 409 table_id: 30 (mtr.test_suppressions)
|
master-bin.000001 409 Write_rows_v1 1 537 table_id: 30 flags: STMT_END_F
|
master-bin.000001 537 Query 1 605 COMMIT
|
<...>
|
master-bin.000001 186311 Write_rows_v1 1 186367 table_id: 33 flags: STMT_END_F
|
master-bin.000001 186367 Query 1 186436 COMMIT
|
|
|
**** SHOW RELAYLOG EVENTS on default ****
|
relaylog_name = 'No such row'
|
SHOW RELAYLOG EVENTS IN 'No such row';
|
Log_name Pos Event_type Server_id End_log_pos Info
|
|
|
== /mnt/buildbot/build/mariadb-10.1.34/mysql-test/var/2/tmp/analyze-sync_with_master-mysqld.2.err ==
|
|
|
############################## default ##############################
|
|
|
**** SHOW WARNINGS on default ****
|
SHOW WARNINGS;
|
Level Code Message
|
|
|
**** SELECT replication-related variables on default ****
|
SELECT NOW(), @@SERVER_ID;
|
NOW() @@SERVER_ID
|
2018-05-27 02:17:14 2
|
|
|
**** SHOW SLAVE STATUS on default ****
|
SHOW SLAVE STATUS;
|
Slave_IO_State Waiting for master to send event
|
Master_Host 127.0.0.1
|
Master_User root
|
Master_Port 16020
|
Connect_Retry 1
|
Master_Log_File master-bin.000001
|
Read_Master_Log_Pos 186436
|
Relay_Log_File slave-relay-bin.000002
|
Relay_Log_Pos 154086
|
Relay_Master_Log_File master-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 153797
|
Relay_Log_Space 187023
|
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 406
|
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 No
|
Gtid_IO_Pos
|
Replicate_Do_Domain_Ids
|
Replicate_Ignore_Domain_Ids
|
Parallel_Mode conservative
|
|
|
**** SHOW MASTER STATUS on default ****
|
SHOW MASTER STATUS;
|
File slave-bin.000001
|
Position 153157
|
Binlog_Do_DB
|
Binlog_Ignore_DB
|
|
|
**** SHOW SLAVE HOSTS on default ****
|
SHOW SLAVE HOSTS;
|
|
|
**** SHOW PROCESSLIST on default ****
|
SHOW PROCESSLIST;
|
Id User Host db Command Time State Info Progress
|
6 system user NULL Connect 1100 Waiting for master to send event NULL 0.000
|
7 system user test Connect 406 Unlocking tables DROP TABLE IF EXISTS `tt_xx_7`,`nt_xx_7` /* generated by server */ 0.000
|
10 root localhost NULL Query 0 init SHOW PROCESSLIST 0.000
|
|
|
**** SHOW BINARY LOGS on default ****
|
SHOW BINARY LOGS;
|
Log_name File_size
|
slave-bin.000001 153157
|
|
|
<...>
|
|
|
|
|
- saving '/mnt/buildbot/build/mariadb-10.1.34/mysql-test/var/2/log/rpl.rpl_non_direct_row_mixing_engines-row,xtradb/' to '/mnt/buildbot/build/mariadb-10.1.34/mysql-test/var/log/rpl.rpl_non_direct_row_mixing_engines-row,xtradb/'
|
worker[2] > Restart - not started
|
worker[2] > Restart - not started
|
***Warnings generated in error logs during shutdown after running tests: rpl.rpl_non_direct_row_mixing_engines
|
|
|
InnoDB: Error: Waited for 5 secs for hash index ref_count (1) to drop to 0.
|
InnoDB: Error: Waited for 10 secs for hash index ref_count (1) to drop to 0.
|
<...>
|
InnoDB: Error: Waited for 235 secs for hash index ref_count (1) to drop to 0.
|
InnoDB: Warning: semaphore wait:
|
InnoDB: Error: Waited for 240 secs for hash index ref_count (1) to drop to 0.
|
<...>
|
|
|
InnoDB: Error: Waited for 395 secs for hash index ref_count (1) to drop to 0.
|