# binlog positions "off" a bit after restore **URL:** \ **Category:** Percona XtraBackup\ **Created:** [March 25, 2015, 10:22am UTC](https://forums.percona.com/t/binlog-positions-off-a-bit-after-restore/4123 "2015-03-25T10:22:28Z")\ **Posts on this page:** 2\ **Page:** 1
**Author:** ![wdeviers](https://avatars.discourse-cdn.com/v4/letter/w/8797f3/32.png) [@wdeviers](https://forums.percona.com/u/wdeviers)\ **Post date:** [March 25, 2015, 10:22am UTC](https://forums.percona.com/t/binlog-positions-off-a-bit-after-restore/4123/1 "2015-03-25T10:22:28Z")
I have a few shards in an application that are approaching 600-800G on-disk, but aren’t heavily used. I’m spinning up new off-site backup & reporting copies of all shards and let four streaming xtrabackup runs go last night. I have a script that I use frequently to clone out new slaves. Two of the shards, with active customer bases, started right up as normal (150-200G). The two shards with larger data sizes appear to have slightly wrong (behind) master coordinates in xtrabackup\_slave\_info. So, when I do a streaming backup from an existing slave, at the end I get: CHANGE MASTER TO MASTER\_LOG\_FILE=‘mysql-bin.002238’, MASTER\_LOG\_POS=263779110 overnight, the master moved through to | mysql-bin.002239 | 30261034 | So it passes a quick sanity check. Built a CHANGE MASTER with the correct ip/user/etc, fire it off, and start replication. Duplicate key error. Oops! I verified from the error log that the expected slave statement was issued: Slave SQL thread initialized, starting replication in log ‘mysql-bin.002238’ at position 263779110, relay log ‘/mysql/binlog/mysqld-relay-bin.000001’ position: 4. I get: Last\_SQL\_Error: Error ‘Duplicate entry ‘68407820’ for key ‘PRIMARY’’ on query… This is against a Rails sessions table. mysql\> select id, created\_at from sessions where id = ‘68407821’; ±---------±--------------------+ | id | created\_at | ±---------±--------------------+ | 68407821 | 2015-03-24 03:54:15 | ±---------±--------------------+ Using mysqlbinlog, I found that insert into the original binlogs. It seems to be halfway through a transaction for thread 841292: #150325 2:37:43 server id 130161118 end\_log\_pos 263780113 CRC32 0xa869770f Query thread\_id=841292 exec\_time=0 error\_code=0 SET TIMESTAMP=1427265463/_!_/; INSERT INTO `sessions` (— redacted — ) /_!_/; Thus, the xtrabackup\_slave\_info position should have been _at least_ the next one: #150325 2:37:43 server id 130161118 end\_log\_pos 263780693 CRC32 0x5b59698f Query thread\_id=841292 exec\_time=0 error\_code=0 but as noted this appears to be splitting a transaction. So, the entire transaction for thread 841292 was committed to disk (I verified on the restore that the data is correct for the entire transaction) AND data from the next few transactions is present. Info: Source Slave: :~$ dpkg -l|grep percona ii libperconaserverclient18.1 5.6.19-67.0-618.wheezy amd64 Percona Server database client library ii libperconaserverclient18.1-dev 5.6.19-67.0-618.wheezy amd64 Percona Server database development files ii percona-server-client-5.6 5.6.19-67.0-618.wheezy amd64 Percona Server database client binaries ii percona-server-common-5.6 5.6.19-67.0-618.wheezy amd64 Percona Server database common files (e.g. /etc/mysql/my.cnf) ii percona-server-server 5.6.19-67.0-618.wheezy amd64 Percona Server database server ii percona-server-server-5.6 5.6.19-67.0-618.wheezy amd64 Percona Server database server binaries ii percona-xtrabackup 2.2.9-5067-1.wheezy amd64 Open source backup tool for InnoDB and XtraDB Destination: ii libperconaserverclient18.1 5.6.22-71.0-726.wheezy amd64 Percona Server database client library ii libperconaserverclient18.1-dev 5.6.22-71.0-726.wheezy amd64 Percona Server database development files ii percona-server-client-5.6 5.6.22-71.0-726.wheezy amd64 Percona Server database client binaries ii percona-server-common-5.6 5.6.22-71.0-726.wheezy amd64 Percona Server database common files (e.g. /etc/mysql/my.cnf) ii percona-server-server 5.6.22-71.0-726.wheezy amd64 Percona Server database server ii percona-server-server-5.6 5.6.22-71.0-726.wheezy amd64 Percona Server database server binaries ii percona-xtrabackup 2.2.9-5067-1.wheezy amd64 Open source backup tool for InnoDB and XtraDB I feel like I’m missing something obvious here, like a failed roll-back or something. If it hadn’t happened on 2/4 of the servers overnight, I probably wouldn’t bother posting. What have I done wrong/misunderstood? Thanks! Wes ---
**Author:** ![wagnerbianchi](https://sea1.discourse-cdn.com/flex019/user_avatar/forums.percona.com/wagnerbianchi/32/802_2.png) [@wagnerbianchi](https://forums.percona.com/u/wagnerbianchi)\ **Post date:** [April 4, 2015, 9:18am UTC](https://forums.percona.com/t/binlog-positions-off-a-bit-after-restore/4123/2 "2015-04-04T09:18:14Z")
What caught up my attention here was the position added to the xtrabackup\_slave\_info file. it seems that the wrong position caused the harm and when you start mysql with that backupset, it started replicating from a wrong position. So, what’s the command line you’re using to xtrabackup databases/shards? Are you using multi-threaded slaves?