[MDEV-8595] replication from mysql-5.5.37 master to 10.0.21 slave corrupted on slave restart Created: 2015-08-10  Updated: 2015-08-12  Resolved: 2015-08-12

Status: Closed
Project: MariaDB Server
Component/s: Replication
Affects Version/s: 10.0.21
Fix Version/s: N/A

Type: Bug Priority: Major
Reporter: Daniel Black Assignee: Unassigned
Resolution: Not a Bug Votes: 0
Labels: parallelslave, replication

Attachments: File mariadb.cnf    

 Description   

Relay log corruption caused by the following sequence of events:

Replication can follow a MySQL-5.5 master however gets its position lost on restart.

I stopped replication on db2 as data was out of sync.

db2 was reloaded with mysqldump --single-transaction --master-data -h

{masterIP}

ibis | mysql ibis

slave IO thread was started after verifying the --master-data reset the position correctly (verified as master was in a flush tables with read lock; show master status; at the time).

12:05:53 data was loaded and SQL thread started

skip-replication was added to configuration file to prevent an automatic replication restart (was in a rush and couldn't find the right option - invalid was good enough)

00:13:13 VM was shutdown cleanly and cloned at the block level.

A new VM was created with the cloned block devices. The cloned VM was started as ip-10-0-0-22 which was firewall blocked from connecting to the master.

Where mysqld is aborted due to the invalid option --skip-replication
Aug 10 03:41:30 ip-10-0-0-22 mysqld: 150810 3:41:30 ) the log sequence number on start 115145231803, didn't match the log sequence number on stop 115145231813.

ug  9 09:02:01 db2 mysqld: 150809  9:02:01 [Note] Master: ''  Master_info_file: 'master.info'  Relay_info_file: '/srv/mysqllog/mysqld-relay-bin.index'
 
Aug  9 09:02:01 db2 mysqld: 150809  9:02:01 [Note] Failed to delete file '/srv/mysqllog/394'
 
Aug  9 09:02:01 db2 mysqld: 150809  9:02:01 [Note] Failed to delete file '/srv/mysqllog/mysql-bin.008135'
 
Aug  9 09:02:01 db2 mysqld: 150809  9:02:01 [Note] Failed to delete file '/srv/mysqllog/107'
 
Aug  9 09:02:01 db2 mysqld: 150809  9:02:01 [Note] Failed to delete file '/srv/mysqllog/y-bin.000198'
 
Aug  9 09:02:01 db2 mysqld: 150809  9:02:01 [Note] Failed to delete file '/srv/mysqllog/mysqld-relay-bin.000201'
 
Aug  9 09:02:01 db2 mysqld: 150809  9:02:01 [Note] 'CHANGE MASTER TO executed'. Previous state master_host='172.31.2.235', master_port='3306', master_log_file='mys
 
ql-bin.008135', master_log_pos='265578579'. New state master_host='172.31.2.235', master_port='3306', master_log_file='mysql-bin.008194', master_log_pos='107'.
 
Aug  9 09:05:21 db2 mysqld: 150809  9:05:21 [Note] Slave I/O thread: connected to master 'repl@172.31.2.235:3306',replication started in log 'mysql-bin.008194' at 
position 107
 
Aug  9 09:05:21 db2 mysqld: 150809  9:05:21 [Warning] Slave I/O: Notifying master by SET @master_binlog_checksum= @@global.binlog_checksum failed with error: Unknown system variable 'binlog_checksum', Internal MariaDB error code: 1193
 
Aug  9 12:05:53 db2 mysqld: 150809 12:05:53 [Note] Slave SQL thread initialized, starting replication in log 'mysql-bin.008194' at position 107, relay log '/srv/mysqllog/mysqld-relay-bin.000199' position: 4
 
Aug  9 12:07:13 db2 mysqld: 150809 12:07:13 [ERROR] Error reading packet from server: Lost connection to MySQL server during query ( server_errno=2013)
 
Aug  9 12:07:13 db2 mysqld: 150809 12:07:13 [Note] Slave I/O thread: Failed reading log event, reconnecting to retry, log 'mysql-bin.008195' at position 2594145
 
Aug  9 12:07:13 db2 mysqld: 150809 12:07:13 [Warning] Slave I/O: Notifying master by SET @master_binlog_checksum= @@global.binlog_checksum failed with error: Unknown system variable 'binlog_checksum', Internal MariaDB error code: 1193
 
Aug  9 20:39:41 db2 mysqld: 150809 20:39:41 [Warning] Aborted connection 156 to db: 'unconnected' user: 'root' host: 'localhost' (Unknown error)
 
Aug 10 00:13:13 db2 mysqld: 150810  0:13:13 [Note] Error reading relay log event: slave SQL thread was killed
 
Aug 10 00:13:13 db2 mysqld: 150810  0:13:13 [ERROR] Error reading packet from server: Lost connection to MySQL server during query ( server_errno=2013)
 
Aug 10 00:13:13 db2 mysqld: 150810  0:13:13 [Note] Slave I/O thread killed while reading event
 
Aug 10 00:13:13 db2 mysqld: 150810  0:13:13 [Note] Slave I/O thread exiting, read up to log 'mysql-bin.008203', position 186156953
 
Aug 10 00:13:30 db2 mysqld: 150810  0:13:30 [Note] Slave SQL thread initialized, starting replication in log 'mysql-bin.008203' at position 186156953, relay log '/
 
srv/mysqllog/mysqld-relay-bin.000238' position: 79418467
 
Aug 10 00:15:30 db2 mysqld: 150810  0:15:30 [Note] /usr/sbin/mysqld: Normal shutdown
 
Aug 10 00:15:30 db2 mysqld: 
Aug 10 00:15:30 db2 mysqld: 150810  0:15:30 [Note] Event Scheduler: Purging the queue. 0 events
 
Aug 10 00:15:30 db2 mysqld: 150810  0:15:30 [Note] Error reading relay log event: slave SQL thread was killed
 
Aug 10 00:15:30 db2 mysqld: 150810  0:15:30 [Note] InnoDB: FTS optimize thread exiting.
 
Aug 10 00:15:30 db2 mysqld: 150810  0:15:30 [Note] InnoDB: Starting shutdown...
 
Aug 10 00:15:30 db2 mysqld: 2015-08-10 00:15:30 7ff8457f8700 InnoDB: Dumping buffer pool(s) to .//ib_buffer_pool
 
Aug 10 00:15:30 db2 mysqld: 2015-08-10 00:15:30 7ff8457f8700 InnoDB: Buffer pool(s) dump completed at 150810  0:15:30
 
Aug 10 00:15:32 db2 mysqld: 150810  0:15:32 [Note] InnoDB: Shutdown completed; log sequence number 115145231803
 
Aug 10 00:15:32 db2 mysqld: 150810  0:15:32 [Note] /usr/sbin/mysqld: Shutdown complete
 
Aug 10 00:15:32 db2 mysqld: 
Aug 10 00:15:32 db2 mysqld_safe: mysqld from pid file /var/run/mysqld/mysqld.pid ended
 
Aug 10 03:41:24 ip-10-0-0-22 mysqld_safe: Starting mysqld daemon with databases from /srv/mysqldata
 
Aug 10 03:41:24 ip-10-0-0-22 mysqld: 150810  3:41:24 [Note] /usr/sbin/mysqld (mysqld 10.0.21-MariaDB-1~trusty-log) starting as process 1549 ...
 
Aug 10 03:41:25 ip-10-0-0-22 mysqld: 150810  3:41:25 [Note] InnoDB: Using mutexes to ref count buffer pool pages
 
Aug 10 03:41:25 ip-10-0-0-22 mysqld: 150810  3:41:25 [Note] InnoDB: The InnoDB memory heap is disabled
 
Aug 10 03:41:25 ip-10-0-0-22 mysqld: 150810  3:41:25 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
 
Aug 10 03:41:25 ip-10-0-0-22 mysqld: 150810  3:41:25 [Note] InnoDB: Memory barrier is not used
 
Aug 10 03:41:25 ip-10-0-0-22 mysqld: 150810  3:41:25 [Note] InnoDB: Compressed tables use zlib 1.2.8
 
Aug 10 03:41:25 ip-10-0-0-22 mysqld: 150810  3:41:25 [Note] InnoDB: Using Linux native AIO
 
Aug 10 03:41:25 ip-10-0-0-22 mysqld: 150810  3:41:25 [Note] InnoDB: Using CPU crc32 instructions
 
Aug 10 03:41:25 ip-10-0-0-22 mysqld: 150810  3:41:25 [Note] InnoDB: Initializing buffer pool, size = 4.4G
 
Aug 10 03:41:25 ip-10-0-0-22 mysqld: 150810  3:41:25 [Note] InnoDB: Completed initialization of buffer pool
 
Aug 10 03:41:25 ip-10-0-0-22 mysqld: 150810  3:41:25 [Note] InnoDB: Highest supported file format is Barracuda.
 
Aug 10 03:41:30 ip-10-0-0-22 mysqld: 150810  3:41:30 [Note] InnoDB: 128 rollback segment(s) are active.
 
Aug 10 03:41:30 ip-10-0-0-22 mysqld: 150810  3:41:30 [Note] InnoDB: Waiting for purge to start
 
Aug 10 03:41:30 ip-10-0-0-22 mysqld: 150810  3:41:30 [Note] InnoDB:  Percona XtraDB (http://www.percona.com) 5.6.25-73.1 started; log sequence number 115145231803
 
Aug 10 03:41:30 ip-10-0-0-22 mysqld: 2015-08-10 03:41:30 7f416f7ff700 InnoDB: Loading buffer pool(s) from .//ib_buffer_pool
 
Aug 10 03:41:30 ip-10-0-0-22 mysqld: 150810  3:41:30 [Note] Plugin 'FEEDBACK' is disabled. 
Aug 10 03:41:30 ip-10-0-0-22 mysqld: 150810  3:41:30 [ERROR] /usr/sbin/mysqld: unknown option '--skip-replication'
 
Aug 10 03:41:30 ip-10-0-0-22 mysqld: 150810  3:41:30 [ERROR] Aborting
 
Aug 10 03:41:30 ip-10-0-0-22 mysqld: 
Aug 10 03:41:30 ip-10-0-0-22 mysqld: 150810  3:41:30 [Note] InnoDB: FTS optimize thread exiting.
 
Aug 10 03:41:30 ip-10-0-0-22 mysqld: 150810  3:41:30 [Note] InnoDB: Starting shutdown...
 
Aug 10 03:41:30 ip-10-0-0-22 mysqld: 2015-08-10 03:41:30 7f416f7ff700 InnoDB: Buffer pool(s) load completed at 150810  3:41:30 (.//ib_buffer_pool was empty)
 
Aug 10 03:41:30 ip-10-0-0-22 mysqld: 2015-08-10 03:41:30 7f416f7ff700 InnoDB: Dumping buffer pool(s) to .//ib_buffer_pool
 
Aug 10 03:41:31 ip-10-0-0-22 mysqld: 2015-08-10 03:41:30 7f416f7ff700 InnoDB: Buffer pool(s) dump completed at 150810  3:41:30
 
Aug 10 03:41:53 ip-10-0-0-22 /etc/init.d/mysql[2514]: error: 'Can't connect to local MySQL server through socket '/var/run/mysqld/mysqld.sock' (2 "No such file or directory")'
 
Aug 10 03:41:53 ip-10-0-0-22 /etc/init.d/mysql[2514]: Check that mysqld is running and that the socket: '/var/run/mysqld/mysqld.sock' exists!
 
Aug 10 03:42:10 ip-10-0-0-22 mysqld: 150810  3:42:10 [Note] InnoDB: Shutdown completed; log sequence number 115145231813
 
Aug 10 03:42:10 ip-10-0-0-22 mysqld: 150810  3:42:10 [Note] /usr/sbin/mysqld: Shutdown complete
 
Aug 10 03:42:10 ip-10-0-0-22 mysqld: 
Aug 10 03:42:10 ip-10-0-0-22 mysqld_safe: mysqld from pid file /var/run/mysqld/mysqld.pid ended
 
Aug 10 03:52:02 ip-10-0-0-22 mysqld_safe: Starting mysqld daemon with databases from /srv/mysqldata
 
Aug 10 03:52:02 ip-10-0-0-22 mysqld: 150810  3:52:02 [Note] /usr/sbin/mysqld (mysqld 10.0.21-MariaDB-1~trusty-log) starting as process 4795 ...
 
Aug 10 03:52:02 ip-10-0-0-22 mysqld: 150810  3:52:02 [Note] InnoDB: Using mutexes to ref count buffer pool pages
 
Aug 10 03:52:02 ip-10-0-0-22 mysqld: 150810  3:52:02 [Note] InnoDB: The InnoDB memory heap is disabled
 
Aug 10 03:52:02 ip-10-0-0-22 mysqld: 150810  3:52:02 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
 
Aug 10 03:52:02 ip-10-0-0-22 mysqld: 150810  3:52:02 [Note] InnoDB: Memory barrier is not used
 
Aug 10 03:52:02 ip-10-0-0-22 mysqld: 150810  3:52:02 [Note] InnoDB: Compressed tables use zlib 1.2.8
 
Aug 10 03:52:02 ip-10-0-0-22 mysqld: 150810  3:52:02 [Note] InnoDB: Using Linux native AIO
 
Aug 10 03:52:02 ip-10-0-0-22 mysqld: 150810  3:52:02 [Note] InnoDB: Using CPU crc32 instructions
 
Aug 10 03:52:02 ip-10-0-0-22 mysqld: 150810  3:52:02 [Note] InnoDB: Initializing buffer pool, size = 4.4G
 
Aug 10 03:52:03 ip-10-0-0-22 mysqld: 150810  3:52:03 [Note] InnoDB: Completed initialization of buffer pool
 
Aug 10 03:52:03 ip-10-0-0-22 mysqld: 150810  3:52:03 [Note] InnoDB: Highest supported file format is Barracuda.
 
Aug 10 03:52:03 ip-10-0-0-22 mysqld: 150810  3:52:03 [Note] InnoDB: 128 rollback segment(s) are active.
 
Aug 10 03:52:03 ip-10-0-0-22 mysqld: 150810  3:52:03 [Note] InnoDB: Waiting for purge to start
 
Aug 10 03:52:03 ip-10-0-0-22 mysqld: 150810  3:52:03 [Note] InnoDB:  Percona XtraDB (http://www.percona.com) 5.6.25-73.1 started; log sequence number 115145231813
 
Aug 10 03:52:03 ip-10-0-0-22 mysqld: 2015-08-10 03:52:03 7f26277f8700 InnoDB: Loading buffer pool(s) from .//ib_buffer_pool
 
Aug 10 03:52:03 ip-10-0-0-22 mysqld: 150810  3:52:03 [Note] Plugin 'FEEDBACK' is disabled.
 
Aug 10 03:52:03 ip-10-0-0-22 mysqld: 2015-08-10 03:52:03 7f26277f8700 InnoDB: Buffer pool(s) load completed at 150810  3:52:03
 
Aug 10 03:52:04 ip-10-0-0-22 mysqld: 150810  3:52:04 [Note] Server socket created on IP: '::'.
 
Aug 10 03:52:04 ip-10-0-0-22 mysqld: 150810  3:52:04 [Note] Event Scheduler: Loaded 0 events
 
Aug 10 03:52:04 ip-10-0-0-22 mysqld: 150810  3:52:04 [Note] Reading of all Master_info entries succeded
 
Aug 10 03:52:04 ip-10-0-0-22 mysqld: 150810  3:52:04 [Note] Added new Master_info '' to hash table
 
Aug 10 03:52:04 ip-10-0-0-22 mysqld: 150810  3:52:04 [ERROR] Slave I/O: error connecting to master 'repl@172.31.2.235:3306' - retry-time: 10  retries: 86400  message: Can't connect to MySQL server on '172.31.2.235' (111 "Connection refused"), Internal MariaDB error code: 2003
 
Aug 10 03:52:04 ip-10-0-0-22 mysqld: 150810  3:52:04 [Note] /usr/sbin/mysqld: ready for connections.
 
Aug 10 03:52:04 ip-10-0-0-22 mysqld: Version: '10.0.21-MariaDB-1~trusty-log'  socket: '/var/run/mysqld/mysqld.sock'  port: 3306  mariadb.org binary distribution
 
Aug 10 03:52:04 ip-10-0-0-22 mysqld: 150810  3:52:04 [Note] Slave SQL thread initialized, starting replication in log '000238' at position 0, relay log '/srv/mysqllog/mysqld-relay-bin.000237' position: 0
 
Aug 10 03:52:35 ip-10-0-0-22 mysqld: 150810  3:52:35 [ERROR] Slave SQL: Error 'Duplicate entry '1186237' for key 'PRIMARY'' on query. Default database: 'ibis'. Query: 'INSERT INTO workflow_node_history (nid, old_sid, sid, uid, stamp, comment) VALUES ('1452121', '2', '6', '2972', '1439162139', 'Article status updated by user')', Internal MariaDB error code: 1062
 
Aug 10 03:52:35 ip-10-0-0-22 mysqld: 150810  3:52:35 [Warning] Slave: Duplicate entry '1186237' for key 'PRIMARY' Error_code: 1062
 
Aug 10 03:52:35 ip-10-0-0-22 mysqld: 150810  3:52:35 [ERROR] Error running query, slave SQL thread aborted. Fix the problem, and restart the slave SQL thread with "SLAVE START". We stopped at log 'mysql-bin.008203' position 94017
 

cat /srv/mysqldata//master.info
 
33
 
mysql-bin.008203
 
186156953
 
172.31.2.235
 
repl
 
d5lXXXXXXXXX
 
3306
 
10
 
0
 
 
 
 
 
 
 
 
 
 
 
0
 
1800.000
 
 
 
0
 
 
 
0
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
 
using_gtid=0
 

 ls -la /srv/mysqllog/*relay*
 
-rw-rw---- 1 mysql mysql       295 Aug  4 03:12 /srv/mysqllog/mariadb-relay.000003
 
-rw-rw---- 1 mysql mysql 104880198 Aug  4 08:15 /srv/mysqllog/mariadb-relay.000016
 
-rw-rw---- 1 mysql mysql  33374113 Aug  4 08:28 /srv/mysqllog/mariadb-relay.000017
 
-rw-rw---- 1 mysql mysql       267 Aug  5 01:28 /srv/mysqllog/mariadb-relay.000018
 
-rw-rw---- 1 mysql mysql       267 Aug  5 01:29 /srv/mysqllog/mariadb-relay.000019
 
-rw-rw---- 1 mysql mysql       267 Aug  5 01:33 /srv/mysqllog/mariadb-relay.000020
 
-rw-rw---- 1 mysql mysql       175 Aug  5 01:33 /srv/mysqllog/mariadb-relay.index
 
-rw-rw---- 1 mysql mysql  95814324 Aug  4 03:08 /srv/mysqllog/mysqld-relay-bin.000195
 
-rw-rw---- 1 mysql mysql       267 Aug  6 01:18 /srv/mysqllog/mysqld-relay-bin.000196
 
-rw-rw---- 1 mysql mysql       298 Aug  7 06:41 /srv/mysqllog/mysqld-relay-bin.000197
 
-rw-rw---- 1 mysql mysql       298 Aug  8 07:00 /srv/mysqllog/mysqld-relay-bin.000198
 
-rw-rw---- 1 mysql mysql 106739179 Aug  9 23:50 /srv/mysqllog/mysqld-relay-bin.000237
 
-rw-rw---- 1 mysql mysql  79418486 Aug 10 00:15 /srv/mysqllog/mysqld-relay-bin.000238
 
-rw-rw---- 1 mysql mysql       248 Aug 10 03:52 /srv/mysqllog/mysqld-relay-bin.000239
 
-rw-rw---- 1 mysql mysql       114 Aug 10 03:52 /srv/mysqllog/mysqld-relay-bin.index
 
-rw-r----- 1 root  root         63 Aug  4 03:12 /srv/mysqllog/relay-log.info
 
# cat /srv/mysqllog/mysqld-relay-bin.index
 
/srv/mysqllog/mysqld-relay-bin.000237
 
94304
 
mysql-bin.008203
 
94017
 
n.000238
 
/srv/mysqllog/mysqld-relay-bin.000239
 

-rw-rw---- 1 mysql mysql 105577283 Aug  9 23:37 mariadb-bin.000436
 
-rw-rw---- 1 mysql mysql 102346092 Aug 10 00:15 mariadb-bin.000437
 
-rw-rw---- 1 mysql mysql     94164 Aug 10 03:52 mariadb-bin.000438
 
-rw-rw---- 1 mysql mysql     14454 Aug 10 03:52 mariadb-bin.index
 
 
 
 
 
 mysqlbinlog mariadb-bin.000438 - only show events from server id 1 (master)
 

 egrep -v '^(#|$)' /etc/mysql/my.cnf  
[client]
 
port            = 3306
 
socket          = /var/run/mysqld/mysqld.sock
 
[mysqld_safe]
 
socket          = /var/run/mysqld/mysqld.sock
 
nice            = 0
 
[mysqld]        
user            = mysql
 
pid-file        = /var/run/mysqld/mysqld.pid
 
socket          = /var/run/mysqld/mysqld.sock
 
port            = 3306
 
basedir         = /usr
 
tmpdir          = /tmp
 
lc_messages_dir = /usr/share/mysql
 
lc_messages     = en_US
 
skip-external-locking
 
[mysqldump]
 
quick
 
quote-names
 
max_allowed_packet      = 16M
 
[mysql]
 
[isamchk]
 
key_buffer              = 16M
 
!includedir /etc/mysql/conf.d/
 

cat /etc/mysql/conf.d/localhost.cnf
 
 
 
[mysqld]
 
 
 
auto-increment-offset   = 2
 
server-id       = 20
 
report-host     = db1
 
 
 
replicate_ignore_db=ibis_staging

/etc/mysql/conf.d/mariadb.cnf attached.

| workflow_node_history | CREATE TABLE `workflow_node_history` (
 
  `hid` int(11) NOT NULL AUTO_INCREMENT,
 
  `nid` int(10) unsigned NOT NULL DEFAULT '0',
 
  `old_sid` int(10) unsigned NOT NULL DEFAULT '0',
 
  `sid` int(10) unsigned NOT NULL DEFAULT '0',
 
  `uid` int(10) unsigned NOT NULL DEFAULT '0',
 
  `stamp` int(10) unsigned NOT NULL DEFAULT '0',
 
  `comment` longtext COLLATE utf8mb4_unicode_ci,
 
  PRIMARY KEY (`hid`),
 
  KEY `nid` (`nid`,`sid`)
 
) ENGINE=InnoDB AUTO_INCREMENT=1186851 DEFAULT CHARSET=utf8mb4 COLLATE=utf8mb4_unicode_ci |
 

# mysqlbinlog mariadb-bin.000438 | grep -C 3 workflow_node_history
 
# mysqlbinlog mariadb-bin.000437  | grep -C 3 workflow_node_history
 
....
 
 
 
#150810  0:12:51 server id 1  end_log_pos 101804662     Xid = 928777
 
--
 
# at 101804728
 
#150810  0:12:51 server id 1  end_log_pos 101804950     Query   thread_id=96588 exec_time=4294967291    error_code=0
 
SET TIMESTAMP=1439165571/*!*/;
 
INSERT INTO workflow_node_history (nid, old_sid, sid, uid, stamp, comment) VALUES ('1455363', '2', '5', '2972', '1439165570', 'Article status updated by user')
 
/*!*/;
 
# at 101804950
 
#150810  0:12:51 server id 1  end_log_pos 101804977     Xid = 928779
 
--
 
# at 101805043
 
#150810  0:12:51 server id 1  end_log_pos 101805265     Query   thread_id=96589 exec_time=4294967291    error_code=0
 
SET TIMESTAMP=1439165571/*!*/;
 
INSERT INTO workflow_node_history (nid, old_sid, sid, uid, stamp, comment) VALUES ('1455361', '2', '5', '2972', '1439165570', 'Article status updated by user')
 
/*!*/;
 
# at 101805265
 
#150810  0:12:51 server id 1  end_log_pos 101805292     Xid = 928781
 
--
 
# at 101953898
 
#150810  0:12:52 server id 1  end_log_pos 101954120     Query   thread_id=96590 exec_time=4294967292    error_code=0
 
SET TIMESTAMP=1439165572/*!*/;
 
INSERT INTO workflow_node_history (nid, old_sid, sid, uid, stamp, comment) VALUES ('1455324', '2', '6', '2972', '1439165572', 'Article status updated by user')
 
/*!*/;
 
# at 101954120
 
#150810  0:12:52 server id 1  end_log_pos 101954147     Xid = 929151
 
--
 
# at 102128862
 
#150810  0:13:08 server id 1  end_log_pos 102129084     Query   thread_id=96602 exec_time=4294967292    error_code=0
 
SET TIMESTAMP=1439165588/*!*/;
 
INSERT INTO workflow_node_history (nid, old_sid, sid, uid, stamp, comment) VALUES ('1455404', '6', '5', '2972', '1439165588', 'Article status updated by user')
 
/*!*/;
 
# at 102129084
 
#150810  0:13:08 server id 1  end_log_pos 102129111     Xid = 929315
 
--
 
# at 102129177
 
#150810  0:13:08 server id 1  end_log_pos 102129399     Query   thread_id=96601 exec_time=4294967292    error_code=0
 
SET TIMESTAMP=1439165588/*!*/;
 
INSERT INTO workflow_node_history (nid, old_sid, sid, uid, stamp, comment) VALUES ('1455437', '6', '5', '2972', '1439165588', 'Article status updated by user')
 
/*!*/;
 
# at 102129399
 
#150810  0:13:08 server id 1  end_log_pos 102129426     Xid = 929317
 
--
 
# at 102130306
 
#150810  0:13:08 server id 1  end_log_pos 102130528     Query   thread_id=96600 exec_time=4294967292    error_code=0
 
SET TIMESTAMP=1439165588/*!*/;
 
INSERT INTO workflow_node_history (nid, old_sid, sid, uid, stamp, comment) VALUES ('1455476', '6', '5', '2972', '1439165588', 'Article status updated by user')
 
/*!*/;
 
# at 102130528
 
#150810  0:13:08 server id 1  end_log_pos 102130555     Xid = 929327



 Comments   
Comment by Elena Stepanova [ 2015-08-11 ]

danblack,

the log sequence number on start 115145231803, didn't match the log sequence number on stop 115145231813.

Is it just a side note, or is it meant to signify corruption?
From what I've seen, the sequence number always progresses at least +10, regardless any replication, regardless whether there was any InnoDB data, even if the server fails to start due to a wrong option.

Comment by Daniel Black [ 2015-08-11 ]

bq Is it just a side note, or is it meant to signify corruption?

Just something I thought was odd because I'd never noticed it before. Its irrelevant then.

Comment by Elena Stepanova [ 2015-08-11 ]

danblack,
Given your observation in MDEV-8596 about relay_log_info_file vs relay_log_index, and since this issue has the same configuration, I expect that the mess could be caused by the same. Especially since your description starts with the matter-of-fact comment "Replication can follow a MySQL-5.5 master however gets its position lost on restart.". Does it always happen for you, or does it only concerns this instance with relay log indexes mixed up?

Comment by Daniel Black [ 2015-08-12 ]

yep, probably the same cause as MDEV-8596 . Think I moved the relay files and added the incorrect setting to cause this. Feel free to close.

Generated at Thu Feb 08 07:28:20 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.