Bug #34582 FLUSH LOGS does not close and reopen the binlog index file
Submitted: 15 Feb 2008 10:35 Modified: 19 Dec 2009 8:44
Reporter: Kristian Koehntopp Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Server: Replication Severity:S2 (Serious)
Version:5.0.46-enterprise-gpl-log OS:Any
Assigned to: Luis Soares
Triage: Triaged: D2 (Serious) / R2 (Low) / E2 (Low)

[15 Feb 2008 10:35] Kristian Koehntopp
Description:
On a server sysadmins had deleted binlog files manually instead of having the DBAs using PURGE MASTER LOGS. To fix the broken binlog.index, the binlog file was deleted and recreated using "ls -1 ./binlog.0*" > binlog.index. This did not work, even FLUSH LOGS did not rewrite the binlog index.

Strace reveals 

- the slow log is closed and reopened

[pid 22058] close(3)                    = 0
[pid 22058] open("./linux-slow.log", O_WRONLY|O_CREAT|O_APPEND|O_LARGEFILE, 0660) = 3

- the binlog is closed and reopened

[pid 22058] write(12, "\203j\265G\4\f\r\0\0+\0\0\0\215\0\0\0\0\0\4\0\0\0\0\0\0\0linux"..., 43) = 43
[pid 22058] pwrite64(12, "\0", 1, 21)   = 1
[pid 22058] fdatasync(12)               = 0
[pid 22058] close(12)                   = 0
[pid 22058] open("./linux-bin.000139", O_WRONLY|O_CREAT|O_LARGEFILE, 0660) = 12

- but the binlog.index is not

[pid 22058] _llseek(4, 57, [57], SEEK_SET) = 0
[pid 22058] write(4, "./linux-bin.000139\n", 19) = 19
[pid 22058] fdatasync(4)                = 0
[pid 22058] _llseek(4, 0, [0], SEEK_SET) = 0
[pid 22058] read(4, "./linux-bin.000136\n./linux-bin.0"..., 76) = 76

How to repeat:
Start a server with log-bin.
Delete the binlog.index file.
Recreate it.
PURGE MASTER LOGS a bit.
FLUSH LOGS.

See how the binlog.index file is never rewritten.

Suggested fix:
Make the server use a close and open on the binlog.index file, instead of the SEEK_SET to position 0 on the current filehandle 4.
[11 May 2009 19:33] Morgan Tocker
This bug is really annoying.  It's preventing me from doing online binary log relocation when disks fill up etc, but you don't want to purge the binary logs yet.

What I would like to do is:

mv mysql-bin.index mysql-bin.index-old
cp mysql-bin.index-old mysql-bin.index
(edit mysql-bin.index as required)
mysql -e 'FLUSH LOGS';
[21 Jul 2009 17:35] Bugs System
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/79118

3024 Luis Soares	2009-07-21
      BUG#34582: FLUSH LOGS does not close and reopen the binlog index
      file
      
      Issuing 'FLUSH LOGS' does not close and reopen indexfile.
      Instead a SEEK_SET is performed.
      
      This patch makes index file to be closed and reopened whenever a
      rotation happens (FLUSH LOGS is issued or binary log exceeds 
      maximum configured size).
     @ mysql-test/suite/binlog/r/binlog_delete_and_flush_index.result
        Result file.
     @ mysql-test/suite/binlog/t/binlog_delete_and_flush_index.test
        Test case.
     @ sql/log.cc
        Added LOG_CLOSE_INDEX flag when calling MYSQL_BIN_LOG::close
        from within MYSQL_BIN_LOG::new_file_impl (which should just be
        called whenever a rotation is to happen - FLUSH LOGS issued or
        binlog size exceeds the maximum configured).
[20 Oct 2009 8:39] Bugs System
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/87430

3183 Luis Soares	2009-10-20
      BUG#34582: FLUSH LOGS does not close and reopen the binlog index
      file
            
      Issuing 'FLUSH LOGS' does not close and reopen indexfile.
      Instead a SEEK_SET is performed.
            
      This patch makes index file to be closed and reopened whenever a
      rotation happens (FLUSH LOGS is issued or binary log exceeds 
      maximum configured size).
     @ mysql-test/suite/binlog/r/binlog_delete_and_flush_index.result
        Result file.
     @ mysql-test/suite/binlog/t/binlog_delete_and_flush_index.test
        Test case.
     @ sql/log.cc
        Added LOG_CLOSE_INDEX flag when calling MYSQL_BIN_LOG::close
        from within MYSQL_BIN_LOG::new_file_impl (which should just be
        called whenever a rotation is to happen - FLUSH LOGS issued or
        binlog size exceeds the maximum configured).
[23 Oct 2009 0:04] Bugs System
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/87865

3190 Luis Soares	2009-10-23 [merge]
      BUG#34582: mysql-5.1-bugteam-bug-branch --> mysql-5.1-bugteam-latest
      (automerge)
[23 Oct 2009 0:10] Bugs System
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/87867

3683 Luis Soares	2009-10-23 [merge]
      BUG#34582: mysql-5.1-bugteam (latest) --> mysql-pe (latest)
      (automerge)
[23 Oct 2009 0:14] Luis Soares
Queued in mysql-5.1-bugteam and mysql-pe.
[4 Nov 2009 9:23] Bugs System
Pushed into 5.1.41 (revid:joro@sun.com-20091104092152-qz96bzlf2o1japwc) (version source revid:kristofer.pettersson@sun.com-20091103162305-08l4gkeuif2ozsoj) (merge vers: 5.1.41) (pib:13)
[4 Nov 2009 17:51] Jon Stephens
Documented in the 5.1.41 changelog as follows:

      FLUSH LOGS did not actually close and reopen the binary log index file.

Closed.
[11 Nov 2009 6:48] Bugs System
Pushed into 6.0.14-alpha (revid:alik@sun.com-20091110093407-rw5g8dys2baqkt67) (version source revid:alik@sun.com-20091109080109-7dxapd5y5pxlu08w) (merge vers: 6.0.14-alpha) (pib:13)
[11 Nov 2009 6:55] Bugs System
Pushed into 5.5.0-beta (revid:alik@sun.com-20091109115615-nuohp02h8mdrz8m2) (version source revid:alik@sun.com-20091105092041-sp6eyod7sdlfuj3b) (merge vers: 5.5.0-beta) (pib:13)
[18 Dec 2009 10:35] Bugs System
Pushed into 5.1.41-ndb-7.1.0 (revid:jonas@mysql.com-20091218102229-64tk47xonu3dv6r6) (version source revid:jonas@mysql.com-20091218095730-26gwjidfsdw45dto) (merge vers: 5.1.41-ndb-7.1.0) (pib:15)
[18 Dec 2009 10:51] Bugs System
Pushed into 5.1.41-ndb-6.2.19 (revid:jonas@mysql.com-20091218100224-vtzr0fahhsuhjsmt) (version source revid:jonas@mysql.com-20091217101452-qwzyaig50w74xmye) (merge vers: 5.1.41-ndb-6.2.19) (pib:15)
[18 Dec 2009 11:06] Bugs System
Pushed into 5.1.41-ndb-6.3.31 (revid:jonas@mysql.com-20091218100616-75d9tek96o6ob6k0) (version source revid:jonas@mysql.com-20091217154335-290no45qdins5bwo) (merge vers: 5.1.41-ndb-6.3.31) (pib:15)
[18 Dec 2009 11:20] Bugs System
Pushed into 5.1.41-ndb-7.0.11 (revid:jonas@mysql.com-20091218101303-ga32mrnr15jsa606) (version source revid:jonas@mysql.com-20091218064304-ezreonykd9f4kelk) (merge vers: 5.1.41-ndb-7.0.11) (pib:15)
[19 Dec 2009 8:44] Jon Stephens
Also noted in the 5.5.0 and 6.0.14 changelogs. Closed.