You've deleted your database. The database. Well, not delete per se, just unintentionally rolled it back to an almost year old backup. The specifics of how you managed such a tragically foolish thing aren't important (though it involved a very cute toddler and command line history). Unfortunately the deed is been done, and now you're left with the fallout. It's OK though. I've been there too, and I'm here to help. Actually, I've been there and the binlog was there to help. I'm just here to let you know about it. What even is a binlog, you ask? Keep reading dear traveller. Details 👇🏾
The binlog is the binary log. As I understand it, it is a file that describes database changes as a series of events. A main goal of the binary log is to allow replication to another database. An important consequence of the binary log's existence is that it makes certain kinds of data recovery possible. This particular recovery method will be available to MariaDB and MySQL users. This information is in a binary format and not visible via a text editor, but there is the mysqlbinlog command that allows you to get at this data.
So here is the scenario I found myself in. I had migrated a database from one server to another at an earlier point in time. The database was backed up using the mysqldump command, sent to the new server, and imported using the mysql command. Successive database changes would create new binlog entries which would get added to the binlog index1.
Some sample binlog entries are shown below.
4.5K /var/db/mysql/mysql-bin.000067
4.5K /var/db/mysql/mysql-bin.000068
4.5K /var/db/mysql/mysql-bin.000069
4.5K /var/db/mysql/mysql-bin.000070
4.5K /var/db/mysql/mysal-bin.000071
4.5K /var/db/mysql/mysql-bin.000072
4.5K /var/db/mysql/mysql-bin.000073
4.5K /var/db/mysql/mysql-bin.index
So a year or so passes after this database import occurs, and I decide its time to do another backup, but botch it. Binlogs generated during this time shown below:
user@dbserver:~ $ du -sh /var/db/mysql/*
231M databasic
4.5K aria_log.00000001
512B aria_log_control
4.5K ib_buffer_pool
20M ib_logfile0
20M ib_logfile1
4.7M ibdata1
77K ibtmp1
512B multi-master.info
878K mysql
4.5K mysql-bin.000001
25K mysql-bin.000002
17K mysql-bin.000003
4.5K mysql-bin.000004
49K mysql-bin.000005
8.5K mysql-bin.000006
93K mysql-bin.000007
573K mysql-bin.000008
4.5K mysql-bin.000009
4.5K mysql-bin.000010
4.5K mysql-bin.000011
353K mysql-bin.000012
85K mysql-bin.000013
4.5K mysql-bin.000014
4.5K mysql-bin.000015
4.5K mysql-bin.000016
4.5K mysql-bin.000017
4.5K mysql-bin.000018
4.5K mysql-bin.000019
4.5K mysql-bin.000020
4.5K mysql-bin.000021
122M mysql-bin.000022
4.5K mysql-bin.000023
4.5K mysql-bin.000024
mysql-bin.000022 (binlog 22, 122M) is where the initial database import happened, and every binlog entry larger than 4.5K is where a database change of note was recorded in the binary log. I know this because the date of the database dump I accidentally imported roughly matches the creation time of binlog 22. The remaining binary logs are shown below:
13M mysql-bin.000025
15M mysql-bin.000026
129K mysql-bin.000027
4.5K mysql-bin.000028
4.5K mysql-bin.000029
4.5K mysql-bin.000030
4.5K mysql-bin.000031
1.2M mysql-bin.000032
177K mysql-bin.000033
77M mysql-bin.000034
56M mysql-bin.000035
50M mysql-bin.000036
94M mysql-bin.000037
47M mysql-bin.000038
50M mysql-bin.000039
10M mysql-bin.000040
138M mysql-bin.000041
118M mysql-bin.000042
97M mysql-bin.000043
70M mysql-bin.000044
85M mysql-bin.000045
81M mysql-bin.000046
60M mysql-bin.000047
45M mysql-bin.000048
10M mysql-bin.000049
231M mysql-bin.000050
4.5K mysql-bin.index
binlog 50 is where I goofed.
This meant I had a database created, a database dump imported, and binary logs of all the transactions of that initial import, and all transactions after it (up to and including my fateful import that reset things).
Now I'm no database guru or mariadb/mysql expert but once I learned about the binlog's existence, it was like gold to this man in the desert. Based on my understanding, I could (in theory) go through successive binlogs and recreate the database up to a certain point. Armed with a hypothesis I set out to test it. I've outlined the steps I took below.
-
Take backup of existing state. (Yes, it's too late but it can't hurt).
-
Log in to database
mysql -u root -p
-
Check if binlog is enabled with
SHOW variables like '%bin%';log_binshould be set to 'ON'.
MariaDB [(none)]> show variables like '%bin%'; +-----------------------------------------+-------------------------------+ | Variable_name | Value | +-----------------------------------------+-------------------------------+ | bind_address | xxx.xxx.x.xn | | binlog_annotate_row_events | ON | | binlog_cache_size | 32768 | | binlog_checksum | CRC32 | | binlog_commit_wait_count | 0 | | binlog_commit_wait_usec | 100000 | | binlog_direct_non_transactional_updates | OFF | | binlog_file_cache_size | 16384 | | binlog_format | MIXED | | binlog_optimize_thread_scheduling | ON | | binlog_row_image | FULL | | binlog_stmt_cache_size | 32768 | | encrypt_binlog | OFF | | gtid_binlog_pos | 0-1-3193671 | | gtid_binlog_state | 0-1-3193671 | | innodb_locks_unsafe_for_binlog | OFF | | log_bin | ON | | log_bin_basename | /var/db/mysql/mysql-bin | | log_bin_compress | OFF | | log_bin_compress_min_len | 256 | | log_bin_index | /var/db/mysql/mysql-bin.index | | log_bin_trust_function_creators | OFF | | max_binlog_cache_size | 18446744073709547520 | | max_binlog_size | 1073741824 | | max_binlog_stmt_cache_size | 18446744073709547520 | | read_binlog_speed_limit | 0 | | sql_log_bin | ON | | sync_binlog | 0 | | wsrep_forced_binlog_format | NONE | +-----------------------------------------+-------------------------------+ 29 rows in set (0.010 sec) -
Delete existing database
DROP DATABASE databasic;
-
Create new database
CREATE DATABASE databasic CHARACTER SET utf8 COLLATE utf8_general_ci;
-
Log out of the database
Next came the tricky part. I'd determined that mysql-bin.000022 was where I needed to start but I wanted to start from the very start of the dump from a year ago. You don't actually know where the binlog entries start though, until you check. There's a --start-position flag to mysqlbinlog that allows you to pass a position.
To know what position to start at, you view the binlog and scroll through looking for the beginning transaction. Since there were a lot of database transactions I needed to pipe the output to a pager like more.
e.g. mysqlbinlog -d databasic mysql-bin.000022 | more.
After a long bit of searching I found the start position and started rebuilding the database with the following steps:
-
Pipe output of
mysqlbinlogtomysqlfor your database of choice.mysqlbinlog -d databasic mysql-bin.000022 --start-position=2904 | mysql -u root -p databasic mysqlbinlog -d databasic mysql-bin.000023 | mysql -u root -p databasic mysqlbinlog -d databasic mysql-bin.000024 | mysql -u root -p databasic ... mysqlbinlog -d databasic mysql-bin.000047 | mysql -u root -p databasic -
If any of the commands fail (as they did for me) because some database columns already existed, view that binlog, find the transaction that its complaining about and note the position. Then start the import into the database at the transaction after that one. 2
Now there's a better way to do this sort of thing. It's to back up your data and I don't even have an excuse for not backing it up automatically because I've written a script that does this (and verifies that the backup is good using docker). I just didn't set it up 😬.
The binlog index is a file which allows mariab/mysql to know what the next created binlog number should be.
This worked well for me until binlog 47. I started getting more errors so I called it a day and went to bed. Losing a two days of data was far more acceptable than a year. I'm no database guru as I said, so there may be an even better way to do this. If you know one, feel free to share using the contact page or mastodon.