toku_recover_fassociate: Assertion `r==0' failed (errno=2)

MySQL & MariaDB Percona Server for MySQL 5.7
1

We’re attempting to transfer our db from one server to another using the tokudb hot backup plugin. Our database is primarily tokudb, with system tables being left as Innodb. I’m able to start up the new server with tokudb and toku hot backup in place. When I go to change the data dir to use the data from the old server I get this error. /mnt/workspace/percona-server-5.7-debian-binary/label_exp/debian-jessie-64bit/percona-server-5.7-5.7.16-10/storage/tokudb/PerconaFT/ft/logger/recover.cc:471 toku_recover_fassociate: Assertion `r==0’ failed (errno=2)
: No such file or directory

The back process we have is this:
Login into server 1
set the toku_backup_dir to our cloud storage drive
once that’s finished unmount our csd

Go to server 2
mount csd
stop mysql
rsync -avP from csd to new mysql dir
update my.cnf file to use the new mysql dir, which is the old servers data
start mysql

Any ideas what could be causing the error?

The output looks like this:

mysqld_safe Transparent huge pages are already set to: never.
mysqld_safe Starting mysqld daemon with databases from /var/local/mysql
[Warning] TIMESTAMP with implicit DEFAULT value is deprecated. Please use --explicit_defaults_for_timestamp server option (see documentation for more details).
[Warning] ‘NO_AUTO_CREATE_USER’ sql mode was not set.
[Note] /usr/sbin/mysqld (mysqld 5.7.16-10) starting as process 5204 …
[Note] InnoDB: PUNCH HOLE support available
[Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
[Note] InnoDB: Uses event mutexes
[Note] InnoDB: GCC builtin __atomic_thread_fence() is used for memory barrier
[Note] InnoDB: Compressed tables use zlib 1.2.8
[Note] InnoDB: Using Linux native AIO
[Note] InnoDB: Number of pools: 1
[Note] InnoDB: Using CPU crc32 instructions
[Note] InnoDB: Initializing buffer pool, total size = 8G, instances = 8, chunk size = 128M
[Note] InnoDB: Completed initialization of buffer pool
[Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().
[Note] InnoDB: Recovering partial pages from the parallel doublewrite buffer at /var/local/mysql/xb_doublewrite
[Note] InnoDB: Highest supported file format is Barracuda.
[Note] InnoDB: Log scan progressed past the checkpoint lsn 39748453726411
[Note] InnoDB: Doing recovery: scanned up to log sequence number 39748453726420
[Note] InnoDB: Doing recovery: scanned up to log sequence number 39748453726420
[Note] InnoDB: Database was not shutdown normally!
[Note] InnoDB: Starting crash recovery.
[Note] InnoDB: Created parallel doublewrite buffer at /var/local/mysql/xb_doublewrite, size 31457280 bytes
[Note] InnoDB: Last MySQL binlog file position 0 29185505, file name mysql-bin.011878
[Note] InnoDB: Removed temporary tablespace data file: “ibtmp1”
[Note] InnoDB: Creating shared tablespace for temporary tables
[Note] InnoDB: Setting file ‘./ibtmp1’ size to 12 MB. Physically writing the file full; Please wait …
[Note] InnoDB: File ‘./ibtmp1’ size is now 12 MB.
[Note] InnoDB: 96 redo rollback segment(s) found. 96 redo rollback segment(s) are active.
[Note] InnoDB: 32 non-redo rollback segment(s) are active.
[Note] InnoDB: Waiting for purge to start
[Note] InnoDB: Percona XtraDB (http://www.percona.com) 5.7.16-10 started; log sequence number 39748453726420
[Note] InnoDB: Loading buffer pool(s) from /var/local/mysql/ib_buffer_pool
[Note] Plugin ‘FEDERATED’ is disabled.
[Note] InnoDB: Buffer pool(s) load completed at 161222 16:42:04
PerconaFT recovery starting in env /var/local/mysql/
PerconaFT recovery scanning backward from 315924479769
PerconaFT recovery bw_begin_checkpoint at 315924370568 timestamp 1482366079344546 (bw_newer)
PerconaFT recovery bw_end_checkpoint at 315924043645 timestamp 1482366064849133 xid 315923076503 (bw_newer)
PerconaFT recovery bw_begin_checkpoint at 315923076503 timestamp 1482366019344284 (bw_between)
PerconaFT recovery turning around at begin checkpoint 315923076503 time 45504849
PerconaFT recovery starts scanning forward to 315924479769 from 315923076503 left 1403266 (fw_between)
/mnt/workspace/percona-server-5.7-debian-binary/label_exp/debian-jessie-64bit/percona-server-5.7-5.7.16-10/storage/tokudb/PerconaFT/ft/logger/recover.cc:471 toku_recover_fassociate: Assertion `r==0’ failed (errno=2)
: No such file or directory
Backtrace: (Note: toku_do_assert=0x0x7f3fa0d45630)
/usr/lib/mysql/plugin/ha_tokudb.so(_Z19db_env_do_backtraceP8_IO_FILE+0x1b)[0x7f3fa0d6ffbb]
/usr/lib/mysql/plugin/ha_tokudb.so(+0x13d0e3)[0x7f3fa0d700e3]
/usr/lib/mysql/plugin/ha_tokudb.so(+0x11262e)[0x7f3fa0d4562e]
/usr/lib/mysql/plugin/ha_tokudb.so(_Z14tokuft_recoverP13__toku_db_envPFvS0_P7tokutxnEPFvS0_P10cachetableEP10tokuloggerPKcSC_PFiP9__toku_dbPK10__toku_dbtSH_EPFiSE_SH_SH_SH_PFvSH_PvESK_EPFiSE_SE_P9DBT_ARRAYSQ_SH_SH_EPFiSE_SE_SQ_SH_SH_Em+0x267b)[0x7f3fa0d6441b]
/usr/lib/mysql/plugin/ha_tokudb.so(+0x88c57)[0x7f3fa0cbbc57]
/usr/lib/mysql/plugin/ha_tokudb.so(+0x63d61)[0x7f3fa0c96d61]
/usr/sbin/mysqld(_Z24ha_initialize_handlertonP13st_plugin_int+0x51)[0x7f67c1]
/usr/sbin/mysqld[0xc7fbb6]
/usr/sbin/mysqld[0xc8552f]
/usr/sbin/mysqld(_Z11plugin_initPiPPci+0x7b7)[0xc874b7]
/usr/sbin/mysqld[0x78fa4c]
/usr/sbin/mysqld(_Z11mysqld_mainiPPc+0x7f7)[0x791027]
/lib/x86_64-linux-gnu/libc.so.6(__libc_start_main+0xf5)[0x7f41eb38ab45]
/usr/sbin/mysqld[0x787664]
Engine status function not available
Memory usage:
Arena 0:
system bytes = 0
in use bytes = 0
Total (incl. mmap):
system bytes = 0
in use bytes = 0
max mmap regions = 0
max mmap bytes = 0
16:42:10 UTC - mysqld got signal 6 ;
This could be because you hit a bug. It is also possible that this binary
or one of the libraries it was linked against is corrupt, improperly built,
or misconfigured. This error can also be caused by malfunctioning hardware.
Attempting to collect some information that could help diagnose the problem.
As this is a crash and something is definitely wrong, the information
collection process might fail.
Please help us make Percona Server better by reporting any
bugs at [url]System Dashboard - Percona JIRA

key_buffer_size=67108864
read_buffer_size=131072
max_used_connections=0
max_threads=129
thread_count=0
connection_count=0
It is possible that mysqld could use up to
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 116499 K bytes of memory
Hope that’s ok; if not, decrease some variables in the equation.

Thread pointer: 0x0
Attempting backtrace. You can use the following information to find out
where mysqld died. If you see no messages after this, something went
terribly wrong…
stack_bottom = 0 thread_stack 0x30000
/usr/sbin/mysqld(my_print_stacktrace+0x2c)[0xe832dc]
/usr/sbin/mysqld(handle_fatal_signal+0x479)[0x797679]
/lib/x86_64-linux-gnu/libpthread.so.0(+0xf8d0)[0x7f41ed4188d0]
/lib/x86_64-linux-gnu/libc.so.6(gsignal+0x37)[0x7f41eb39e067]
/lib/x86_64-linux-gnu/libc.so.6(abort+0x148)[0x7f41eb39f448]
/usr/lib/mysql/plugin/ha_tokudb.so(+0x13d0e8)[0x7f3fa0d700e8]
/usr/lib/mysql/plugin/ha_tokudb.so(+0x11262e)[0x7f3fa0d4562e]
/usr/lib/mysql/plugin/ha_tokudb.so(_Z14tokuft_recoverP13__toku_db_envPFvS0_P7tokutxnEPFvS0_P10cachetableEP10tokuloggerPKcSC_PFiP9__toku_dbPK10__toku_dbtSH_EPFiSE_SH_SH_SH_PFvSH_PvESK_EPFiSE_SE_P9DBT_ARRAYSQ_SH_SH_EPFiSE_SE_SQ_SH_SH_Em+0x267b)[0x7f3fa0d6441b]
/usr/lib/mysql/plugin/ha_tokudb.so(+0x88c57)[0x7f3fa0cbbc57]
/usr/lib/mysql/plugin/ha_tokudb.so(+0x63d61)[0x7f3fa0c96d61]
/usr/sbin/mysqld(_Z24ha_initialize_handlertonP13st_plugin_int+0x51)[0x7f67c1]
/usr/sbin/mysqld[0xc7fbb6]
/usr/sbin/mysqld[0xc8552f]
/usr/sbin/mysqld(_Z11plugin_initPiPPci+0x7b7)[0xc874b7]
/usr/sbin/mysqld[0x78fa4c]
/usr/sbin/mysqld(_Z11mysqld_mainiPPc+0x7f7)[0x791027]
/lib/x86_64-linux-gnu/libc.so.6(__libc_start_main+0xf5)[0x7f41eb38ab45]
/usr/sbin/mysqld[0x787664]
You may download the Percona Server operations manual by visiting
[url]http://www.percona.com/software/percona-server/[/url]. You may find information
in the manual which will help you identify the cause of the crash.

2

This error is indicating that the recovery process can not locate a data file where it expects it. Moving PerconaFT/TokuDB files around is a little tricky. Please see the recent blog series on this topic at [url]https://www.percona.com/blog/2016/09/27/tokudb-and-perconaft-database-file-management-part-1-of-2/[/url] and [url]https://www.percona.com/blog/2016/10/24/tokudb-and-perconaft-data-files-database-file-management-part-2-of-2/[/url]

3

I looked over both of the articles, and neither mention using Toku HotBackup. Is Toku HotBackup no longer being supported? I was able to successfully use it for other databases. For this one it didn’t work, and it’s our largest database. Our other databases are less then 200 GB each. This database sits around 1TB and has a lot of volatility during the backup process. We thought that it was the volatility that caused the problem, so we quarantined the server and performed the hot backup with the same problem arising. We’re resorting to doing an rsync of the mysql dir to transfer it to another server and scheduling down time in order to do so, but it would have been more ideal to be able to use Toku Hotbackup to perform the initial data transfer and then slave the second server to catch up with the data that was changed.

4

The articles were not about HotBackup, but about TokuDB file placement. HotBackup is still supported. It is a very simple utility that does one single thing. It is not a complete, end-to-end backup solution. You must script around it and use it as only a part of the overall backup process.

The result of a HotBackup is the same as if you were to kill -9 your mysqld then make a copy of your data directories. The resulting backup is in a ‘crashed’ state and must perform recovery. TokuDB/PerconaFT is extremely pedantic about where its data files are located relative to one another once they have been created. This error is indicating that either your PerconaFT recovery logs do not match the data set or that the data files are not in the location that it expects them.

The restoration process of a hot backup is to completely replace all of the mysql data and TokuDB data with the backup, i.e. copy it into an unititialized/un-run/cleared server instance.

As far as volatility and being able to take a proper backup, the only requirements are that InnoDB is not using native asynchronous I/O (if you are also taking InnoDB backups) and that TokuDB is operating in full durability mode (tokudb_commit_sync=1) during the backup. There is no need to alter your operation during a backup, hence the name HotBackup. If your application allows a lock or down time then consider a logical backup instead (mysqldump). It is more portable and easier to manage.

Further analysis can not really be done without you sharing your my,cnf from src and dest servers and exact process of starting and stopping server instances, changes to my.cnfs and commands used to initialize servers, copy backups around, etc…