How can you close or flush a binlog file on a remote server

Question

I am replicating my binlog files to a secondary server using the mysqlbinlog --stop-never --read-from-remote-server flags. If the primary database server is compromised I want to replay the binlogs on the remote server, but I'm having trouble with the "current" binlog.

When using mysqlbinlog to convert it to SQL I always get an error like:

ERROR: Error in Log_event::read_log_event(): 'read error', data_len: 2682, event _type: 2 ERROR: Could not read entry at offset 4426095: Error in log format or read error

I'm assuming that this issue is related to the fact that this binlog file hasn't been closed or flushed on the main database server. I do not have this problem on the file after running flush logs on the main database server.

So, my question is this: If the main database server is compromised and I'm unable to run flush logs, only having access to the binlog files that were replicated to a remote server. How can I clean up, close or flush that binlog that was open at the time of a DB outage event?

Answer 1

Flushing the log on the master solves your problem pretty much by accident. When the master log file rotates, mysqlbinlog closes the current file and opens the next one, which implicitly flushes any buffered data.

You can't trigger mysqlbinlog to flush its log on demand the way you can an actual server, but I've found a way to trigger it to maintain the file in an always flushed state, which seems to be a viable way to improve your results.

When Oracle added the --raw option to mysqlbinlog, which, in conjunction with --read-from-remote-server and --stop-never can be used to capture a real-time backup of the master's binlogs, they overlooked at least a couple of seemingly-obvious things.

In light of the documented purpose of the feature...

The --raw option can be used to make a backup of a server's binary log. With the --stop-never option, the backup is “live” because mysqlbinlog stays connected to the server.

https://dev.mysql.com/doc/refman/5.6/en/mysqlbinlog.html#option_mysqlbinlog_raw

...it seems like a distinct oversight that mysqlbinlog does not bother to flush its output stream after each write.

Maybe that's why they put “live” in quotes. :)

My testing confirms that mysqlbinlog, as shipped, leaves dangling data in its buffer that could have been flushed, but this seems like a fairly straightforward problem to fix.

For example, this little change in mysql-5.6.27/client/mysqlbinlog.cc at line 2477:

2477c2477
<         if (my_fwrite(result_file, net->read_pos + 1 , len - 1, MYF(MY_NABP)))
---
>         if (my_fwrite(result_file, net->read_pos + 1 , len - 1, MYF(MY_NABP)) || fflush(result_file))

This change results in the size of the file created by mysqlbinlog continually matching the size returned by SHOW MASTER STATUS;, rather than always seeming to be a few bytes behind. I've always known of this slight lag, but never looked into it in depth. Of course, continually flushing the buffer is going to come with a cost, but this seems like a non-negotiable necessity for "backup" purposes. Note that this is only a flush of the user space buffers, it's not an fsync() or similar, so I don't think it's going to be that different in performance terms... and in any event, it's not going to impact the master.

The logical || is used because my_fwrite() returns 0 on success, so we short-circuit and don't try to flush if that fails, and we error out if either operation fails, since fflush() also returns 0 on success.

This change should significantly improve the behavior you see.

Of course, it's still always possible for you to end up with an incomplete log, since it's still an open file and still being written to... but when testing this fix in a low traffic environment, hot-copying the file results in a usable binlog for me -- while, otherwise, in the same environment, the file end is almost always incomplete when using the stock binary.

For different versions (of 5.6+ only -- this feature wasn't implemented at all before 5.6) the line in the source may be different but it should still be pretty easy to spot, and not far from the line numbers indicated here.

Facebook's fork of MySQL 5.6 features a similar but more sophisticated fix, and a new option --flush-result-file that causes the flushing to be a little less aggressive, but configurable. However, I found it unnecessarily difficult to compile in its current form, so I developed the little patch above.

---

As long as you're patching mysqlbinlog, you might find another small tweak useful for solving another design oversight. The mysqlbinlog utility in the official distribution lacks support for the --compress command line option (although Percona had the good sense to add it to theirs.)

But, it's also easy enough to enable compression. I just came up with the fix above for this question, but I've been using the fix, below, for quite some time now, since -- again -- it has always seemed to me like an obviously missing feature.

From the 5.6.27 source, it looks like this:

1948c1948
<   if (!mysql_real_connect(mysql, host, user, pass, 0, port, sock, 0))
---
>   if (!mysql_real_connect(mysql, host, user, pass, 0, port, sock, CLIENT_COMPRESS))

This change doesn't enable support for passing the --compress command line option -- it just turns on the client compression protocol on the connection to the master, for any master that supports it (which they essentially all do), thereby reducing the amount of network bandwidth needed to transport the logs -- sometimes by a factor of 10:1 or higher, depending on the specific payload. It does not change the contents of the generated files -- it just enables compression of the data traversing the network. On the wire, this has the same effect from the master's perspective as enabling slave_compressed_protocol on the slave server. (The documentation is ambiguous, but this setting has no effect on the master unless the master is also a slave of another server.)