Update 2019-11-02: Yep, I iz dumb! I was apparently working with a snapshot that itself contained a set of crashed tables. So yeah… Btrfs snapshots of MariaDB data directories are just fine backups if you make sure the databases are themselves valid. You can check this for arbitrary snapshots like this:
# cd /var/lib/mysql
# btrfs sub snap Snapshots/sveahadb/sveahadb@auto-2019-08-01-0745_6m/ copy
# /usr/bin/mysqld_safe --defaults-file=/etc/mysql/my.cnf --pid-file=/var/run/mysqld/mysqltestd.pid --socket=/var/run/mysqld/mysqldtest.sock --datadir=/var/lib/mysql/copy --log-error=/var/log/mysql/test.log --user=mysql --bind-address=127.0.0.1 --log-bin=mysqld-bin --port 3307 --skip-slave-start
# mysqlcheck -h localhost -P 3307 --all-databases
So the original mess is below:
I was thinking of renaming this article to “Wait, I iz dumb” but I’m not sure exactly where the boundaries of my dumbness lie so I’ll have to postpone that. First things first: my colleagues at work showed me that it is indeed possible to just run a MySQL instance from a snapshot of files in /var/lib/mysql. What I was missing was that the data needed for a specific database isn’t just kept in /var/lib/mysql/dbname but also in /var/lib/mysql/mysql, /var/lib/mysql/performance_schema and the /var/lib/mysql/ib*-files.
“Oh, silly me!” I said and went home and copied over the entire /var/lib/mysql /Snapshots/snapname folder contents to my dbvm testbed. And… same problem! Google provided me with some clues that the fact that the files come from a replicated setup could cause problems and should be deleted: https://dba.stackexchange.com/questions/111616/innodb-error-table-mysql-innodb-table-stats-not-found/111617
But wait, what about those innodb_* files? They seem like they would be important. What happens if I rsync a snapshot from the DB master? Hmm, same. Well the replication files have different names but the innodb-tables still have to be deleted. Wait, they’re just stats? Well nuts to them then!
But this lead to a new interesting problem, presumably because this snapshot was made from the master which isn’t just committing transactions to disk based on a log – like a slave does – but also decides if and how a transaction can be committed:
InnoDB: Transaction 17653441 was in the XA prepared state.
InnoDB: 1 transaction(s) which must be rolled back or cleaned up
InnoDB: in total 0 row operations to undo
InnoDB: Trx id counter is 17654272
2019-09-06 21:29:19 140285946666112 [Note] InnoDB: 128 rollback segment(s) are active.
2019-09-06 21:29:19 140285380126464 [Note] InnoDB: Starting in background the rollback of recovered transactions
2019-09-06 21:29:19 140285380126464 [Note] InnoDB: Rollback of non-prepared transactions completed
2019-09-06 21:29:19 140285946666112 [Note] InnoDB: Waiting for purge to start
2019-09-06 21:29:19 140285946666112 [Note] InnoDB: Percona XtraDB (http://www.percona.com) 5.6.44-86.0 started; log sequence number 21897778133
2019-09-06 21:29:19 140285275272960 [Note] InnoDB: Dumping buffer pool(s) not yet started
2019-09-06 21:29:19 140285946666112 [Note] Plugin ‘FEEDBACK’ is disabled.
2019-09-06 21:29:19 7f96de049c80 InnoDB: Starting recovery for XA transactions…
2019-09-06 21:29:19 7f96de049c80 InnoDB: Transaction 17653441 in prepared state after recovery
2019-09-06 21:29:19 7f96de049c80 InnoDB: Transaction contains changes to 1 rows
2019-09-06 21:29:19 7f96de049c80 InnoDB: 1 transactions in prepared state after recovery
2019-09-06 21:29:19 140285946666112 [Note] Found 1 prepared transaction(s) in InnoDB
2019-09-06 21:29:19 140285946666112 [ERROR] Found 1 prepared transactions! It means that mysqld was not shut down properly last time and critical recovery information (
last binlog or tc.log file) was manually deleted after a crash. You have to start mysqld with –tc-heuristic-recover switch to commit or rollback pending transactions.
2019-09-06 21:29:19 140285946666112 [ERROR] Aborting
Fair enough… Though I’m curious why this never happens at work. I guess R1Soft might do something different from what a Btrfs snapshot does? Well, I guess it’s kind of obvious that it’s a different technology than a CoW file system but beyond that I think R1Soft might make sure it only stores logs that need no recovery/replay. Strange if that’s the case given how they don’t mind saving completely broken tables in backups… Anyway, let’s just do this the proscribed way:
mysqld_safe --defaults-file=/etc/mysql/my.cnf --basedir=/usr --datadir=/var/lib/mysql/sveatest3/
--user=mysql --bind-address=127.0.0.1 --tc-heuristic-recover=COMMIT
190906 21:30:58 mysqld_safe Logging to syslog.
190906 21:30:58 mysqld_safe Starting mysqld daemon with databases from /var/lib/mysql/sveatest3/
I then stopped the instance and restarted the systemd service. mysqlcheck then verified that all tables were OK. Maybe this approach is more “lossy” than using innodb_force_recovery but it seems like I have asked MySQL to make fewer exceptions this way.
- Ignore replication because this is recovery on a single node.
- Ignore the innodb table statistics.
- Commit any unfinished transactions.
Below tells the story of my first adventures into restoring data from a Btrfs snapshot, not knowing that ibdata and ib_logfile were kind of important:
I’ve been using my Btrfs snapshot-script to take snapshots of my MariaDB databases. This serves merely as what I call Oops-protection. “DROP DATABASE bacula;” kind of sucks after all. But to my dismay data is not stored on disk in a consistent state. This turns out to be an error in my expectations rather than an error on the part of MariaDB. The tables are in a sense stored in a consistent state but ongoing transactions are also stored on disk. So trying to start a database up from files copied from a Btrfs snapshot leads to MariaDB worrying about all the ongoing stuff that it was supposed to do:
2019-07-26 21:07:59 140629359316096 [Note] InnoDB: Starting crash recovery from checkpoint LSN=1795910239 2019-07-26 21:07:59 140629359316096 [ERROR] InnoDB: Attempted to open a previously opened tablespace. Previous tablespace mysql/innodb_table_stats uses space ID: 1 at filepath: ./mysql/i Innodb_table_stats.ibd. Cannot open tablespace zabbix/acknowledges which uses space ID: 1 at filepath: ./zabbix/acknowledges.ibd 2019-07-26 21:07:59 7fe6d301cc80 InnoDB: Operating system error number 2 in a file operation. The error means the system cannot find the path specified. If you are installing InnoDB, remember that you must create directories yourself, InnoDB does not create them. Error: could not open single-table tablespace file ./zabbix/acknowledges.ibd We do not continue the crash recovery, because the table may become corrupt if we cannot apply the log records in the InnoDB log to it. To fix the problem and start mysqld: 1) If there is a permission problem in the file and mysqld cannot open the file, you should modify the permissions. 2) If the table is not needed, or you can restore it from a backup, then you can remove the .ibd file, and InnoDB will do a normal crash recovery and ignore that table. 3) If the file system or the disk is broken, and you cannot remove the .ibd file, you can set innodb_force_recovery > 0 in my.cnf and force InnoDB to continue crash recovery here
So adding the following to MariaDB’s configuration allows us to start up in recovery mode:
[mysqld] innodb_force_recovery=1
Both the mysql and zabbix databases are seriously broken:
root@dbvm:/var/lib/mysql/sveatest# mysqlcheck -A ... mysql.func OK mysql.gtid_slave_pos Error : Table 'mysql.gtid_slave_pos' doesn't exist in engine status : Operation failed mysql.help_category OK mysql.help_keyword OK mysql.help_relation OK mysql.help_topic OK mysql.host OK mysql.index_stats OK mysql.innodb_index_stats Error : Table 'mysql.innodb_index_stats' doesn't exist in engine status : Operation failed mysql.innodb_table_stats Error : Table 'mysql.innodb_table_stats' doesn't exist in engine status : Operation failed mysql.plugin OK mysql.proc OK ... zabbix.history Warning : InnoDB: Index 'history_1' contains 3058508 entries, should be 3058449. error : Corrupt zabbix.history_log OK mysqlcheck: Got error: 2013: Lost connection to MySQL server during query when executing 'CHECK TABLE … '
But we can actually dump the data from zabbix which is the one that is interesting here.
mysqldump zabbix > zabbix.sql
Since the mysql-table isn’t interesting here I can just move it out from the MariaDB data directory and install a blank one:
root@dbvm:/var/lib/mysql/sveatest# mysql_install_db Installing MariaDB/MySQL system tables in '/var/lib/mysql/sveatest' … 2019-07-26 21:33:16 140100875676800 [Note] /usr/sbin/mysqld (mysqld 10.1.40-MariaDB-0ubuntu0.18.04.1) starting as process 14528 … OK Filling help tables… 2019-07-26 21:33:20 139659493420160 [Note] /usr/sbin/mysqld (mysqld 10.1.40-MariaDB-0ubuntu0.18.04.1) starting as process 14558 … OK Creating OpenGIS required SP-s… 2019-07-26 21:33:23 140389584972928 [Note] /usr/sbin/mysqld (mysqld 10.1.40-MariaDB-0ubuntu0.18.04.1) starting as process 14587 … OK
After dropping the broken zabbix database and disabling innodb_force_recovery the raw SQL can be imported:
mysql -u root zabbix < zabbix.sql
And we run mysqlcheck -A again:
zabbix.history_log OK zabbix.history_str OK zabbix.history_text OK mysqlcheck: Got error: 2013: Lost connection to MySQL server during query when executing 'CHECK TABLE … '
Wait… What? So it starts without objection but can’t pass a mysqlcheck? I’ll drop the database and import again.
MariaDB [(none)]> DROP DATABASE zabbix; ERROR 2013 (HY000): Lost connection to MySQL server during query
Oh, for the love of… Fine. Let’s go nuclear then.
root@dbvm:/var/lib/mysql/sveatest# systemctl stop mysql root@dbvm:/var/lib/mysql/sveatest# rm -rf zabbix root@dbvm:/var/lib/mysql/sveatest# systemctl start mysql # Log in and create empty database zabbix root@dbvm:/var/lib/mysql/sveatest# mysql zabbix < /root/zabbix.sql
Now what? Table operations not LOCKED with…? What?! So the import won’t work now. What if I drop the database and recreate it and rerun the import?
root@dbvm:/var/lib/mysql/sveatest# mysql zabbix < /root/zabbix.sql root@dbvm:/var/lib/mysql/sveatest# mysqlcheck -A bacula.BaseFiles OK bacula.CDImages OK bacula.Client OK ... zabbix.users_groups OK zabbix.usrgrp OK zabbix.valuemaps OK zabbix.widget OK zabbix.widget_field OK
Phew, now it worked. Well, this was just a dry run but if importing an SQL-dump doesn’t get you back to where you need to be that would be bad news.
So the points here are:
- Filesystem snapshots of MariaDB/MySQL data directories do not give you a database snapshot that you can just run.
- “Recovering” from what is essentially what you would be left if the server crashed can be done but it’s not as easy as running mysqlrepair and then things just work.
- Backups of databases should be made using database engine-aware software like mysqldump or fancy stuff like xtrabackup or the MariaDB-version of that tool: mariabackup.