Percona XtraBackup moved to https://jira.percona.com/projects/PXB

Crash on prepare partial backup with 5.6-based xtrabackup

Bug #1340717 reported by Sergei Glushchenko
22
This bug affects 4 people
Affects Status Importance Assigned to Milestone
Percona XtraBackup moved to https://jira.percona.com/projects/PXB
Fix Released
High
Sergei Glushchenko
Percona XtraBackup moved to https://jira.percona.com/projects/PXB 2.2.4
2.0
Invalid
Undecided
Unassigned
2.1
Fix Released
High
Sergei Glushchenko
Percona XtraBackup moved to https://jira.percona.com/projects/PXB future-2.1-releases
2.2
Fix Released
High
Sergei Glushchenko
Percona XtraBackup moved to https://jira.percona.com/projects/PXB 2.2.4

Bug Description

Xtrabackup crashes when trying to remove absent table from InnoDB data
dictionary.

2014-07-04 18:11:07 7ffff7fe9720 InnoDB: Operating system error number 2 in a file operation.
InnoDB: The error means the system cannot find the path specified.
InnoDB: If you are installing InnoDB, remember that you must create
InnoDB: directories yourself, InnoDB does not create them.
InnoDB: Could not find a valid tablespace file for 'raptor/verify_queue'. See http://dev.mysql.com/doc/refman/5.6/en/innodb-troubleshooting-datadict.html for how to resolve the issue.
InnoDB: It will be removed from the data dictionary.
QUERY PLAN FOR A SELECT NODE
Asc. search; sets row s-locks;
Table index "CLUST_IND" of table "SYS_TABLES"; exact m. 1, match 1, end conds 1
QUERY PLAN FOR A SELECT NODE
Asc. search; sets row s-locks;
Table index "CLUST_IND" of table "SYS_TABLES"; exact m. 1, match 1, end conds 1
2014-07-04 18:11:07 7ffff7fe9720 InnoDB: Error: page 14372 log sequence number 799059998470
InnoDB: is in the future! Current system log sequence number 798405234718.
InnoDB: Your database may be corrupt or you may have copied the InnoDB
InnoDB: tablespace but not the InnoDB log files. See
InnoDB: http://dev.mysql.com/doc/refman/5.6/en/forcing-innodb-recovery.html
InnoDB: for more information.
QUERY PLAN FOR A SELECT NODE
Asc. search; sets row s-locks;
Table index "FOR_IND" of table "SYS_FOREIGN"; exact m. 1, match 1, end conds 1
QUERY PLAN FOR A SELECT NODE
Asc. search; sets row s-locks;
Table index "ID_IND" of table "SYS_FOREIGN_COLS"; exact m. 1, match 1, end conds 1
QUERY PLAN FOR A SELECT NODE
Asc. search; sets row s-locks;
Table index "ID_IND" of table "SYS_FOREIGN"; exact m. 1, match 1, end conds 1
QUERY PLAN FOR A SELECT NODE
Asc. search; sets row s-locks;
Table index "CLUST_IND" of table "SYS_INDEXES"; exact m. 1, match 1, end conds 1
QUERY PLAN FOR A SELECT NODE
Asc. search; sets row s-locks;
Table index "CLUST_IND" of table "SYS_FIELDS"; exact m. 1, match 1, end conds 1
QUERY PLAN FOR A SELECT NODE
Asc. search; sets row s-locks;
Table index "CLUST_IND" of table "SYS_INDEXES"; exact m. 2, match 2, end conds 2
QUERY PLAN FOR A SELECT NODE
Asc. search; sets row s-locks;
Table index "CLUST_IND" of table "SYS_COLUMNS"; exact m. 1, match 1, end conds 1
QUERY PLAN FOR A SELECT NODE
Asc. search; sets row s-locks;
Table index "ID_IND" of table "SYS_TABLES"; exact m. 1, match 1, end conds 1
^C
Program received signal SIGINT, Interrupt.
pthread_cond_wait@@GLIBC_2.3.2 () at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:162
162 ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S: No such file or directory.
        in ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S
(gdb) bt
#0 pthread_cond_wait@@GLIBC_2.3.2 () at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:162
#1 0x0000000000489217 in os_cond_wait (cond=0x15e81a0, fast_mutex=0x15e8160)
    at /home/vagrant/percona-xtrabackup-2.1.8/mysql-5.6/storage/innobase/os/os0sync.cc:214
#2 0x0000000000489791 in os_event_wait_low (event=0x15e8160, reset_sig_count=1)
    at /home/vagrant/percona-xtrabackup-2.1.8/mysql-5.6/storage/innobase/os/os0sync.cc:610
#3 0x000000000050eed8 in sync_array_wait_event (arr=0x15d16b0, index=0)
    at /home/vagrant/percona-xtrabackup-2.1.8/mysql-5.6/storage/innobase/sync/sync0arr.cc:425
#4 0x0000000000548fc6 in rw_lock_s_lock_spin (lock=0x7fffef4c0290, pass=0,
    file_name=0xd91bd8 "/home/vagrant/percona-xtrabackup-2.1.8/mysql-5.6/storage/innobase/include/trx0undo.ic", line=191)
    at /home/vagrant/percona-xtrabackup-2.1.8/mysql-5.6/storage/innobase/sync/sync0rw.cc:427
#5 0x00000000004b75a6 in rw_lock_s_lock_func (lock=0x7fffef4c0290, pass=0,
    file_name=0xd91bd8 "/home/vagrant/percona-xtrabackup-2.1.8/mysql-5.6/storage/innobase/include/trx0undo.ic", line=191)
    at /home/vagrant/percona-xtrabackup-2.1.8/mysql-5.6/storage/innobase/include/sync0rw.ic:364
#6 0x00000000004b7c93 in pfs_rw_lock_s_lock_func (lock=0x7fffef4c0290, pass=0,
    file_name=0xd91bd8 "/home/vagrant/percona-xtrabackup-2.1.8/mysql-5.6/storage/innobase/include/trx0undo.ic", line=191)
    at /home/vagrant/percona-xtrabackup-2.1.8/mysql-5.6/storage/innobase/include/sync0rw.ic:685
#7 0x00000000004c0f27 in buf_page_get_gen (space=0, zip_size=0, offset=478, rw_latch=1, guess=0x0, mode=10,
    file=0xd91bd8 "/home/vagrant/percona-xtrabackup-2.1.8/mysql-5.6/storage/innobase/include/trx0undo.ic", line=191,
    mtr=0x7fffffff63a0) at /home/vagrant/percona-xtrabackup-2.1.8/mysql-5.6/storage/innobase/buf/buf0buf.cc:2899
#8 0x00000000009ef35e in trx_undo_page_get_s_latched (space=0, zip_size=0, page_no=478, mtr=0x7fffffff63a0)
    at /home/vagrant/percona-xtrabackup-2.1.8/mysql-5.6/storage/innobase/include/trx0undo.ic:190
#9 0x00000000009f2787 in trx_undo_get_undo_rec_low (roll_ptr=31328829, heap=0x1989690)
    at /home/vagrant/percona-xtrabackup-2.1.8/mysql-5.6/storage/innobase/trx/trx0rec.cc:1427
#10 0x00000000009f2846 in trx_undo_get_undo_rec (roll_ptr=31328829, trx_id=724112384, undo_rec=0x7fffffff69b0, heap=0x1989690)
    at /home/vagrant/percona-xtrabackup-2.1.8/mysql-5.6/storage/innobase/trx/trx0rec.cc:1461
#11 0x00000000009f2a3e in trx_undo_prev_version_build (index_rec=0x7fffefec249d "raptor/verify_queue_ibfk_1",
    index_mtr=0x7fffffff6b00, rec=0x7fffefec249d "raptor/verify_queue_ibfk_1", index=0x1985be8, offsets=0x1989278,
    heap=0x1989690, old_vers=0x7fffffff6a60)
    at /home/vagrant/percona-xtrabackup-2.1.8/mysql-5.6/storage/innobase/trx/trx0rec.cc:1537
#12 0x0000000000a0b632 in row_vers_impl_x_locked_low (clust_rec=0x7fffefec249d "raptor/verify_queue_ibfk_1",
    clust_index=0x1985be8,
    rec=0x7fffefeb93f9 "raptor/verify_queueraptor/verify_queue_ibfk_1fkd_files_queue_ibfk_1+\022 \002\220\005",
    index=0x19866c8, offsets=0x7fffffff7690, mtr=0x7fffffff6b00)
    at /home/vagrant/percona-xtrabackup-2.1.8/mysql-5.6/storage/innobase/row/row0vers.cc:132
#13 0x0000000000a0b9fa in row_vers_impl_x_locked (
    rec=0x7fffefeb93f9 "raptor/verify_queueraptor/verify_queue_ibfk_1fkd_files_queue_ibfk_1+\022 \002\220\005",
    index=0x19866c8, offsets=0x7fffffff7690)
    at /home/vagrant/percona-xtrabackup-2.1.8/mysql-5.6/storage/innobase/row/row0vers.cc:295
#14 0x000000000050054c in lock_sec_rec_some_has_impl (
    rec=0x7fffefeb93f9 "raptor/verify_queueraptor/verify_queue_ibfk_1fkd_files_queue_ibfk_1+\022 \002\220\005",
    index=0x19866c8, offsets=0x7fffffff7690)
    at /home/vagrant/percona-xtrabackup-2.1.8/mysql-5.6/storage/innobase/lock/lock0lock.cc:1685
---Type <return> to continue, or q <return> to quit---
#15 0x000000000050afa8 in lock_rec_convert_impl_to_expl (block=0x7fffef4f4c40,
    rec=0x7fffefeb93f9 "raptor/verify_queueraptor/verify_queue_ibfk_1fkd_files_queue_ibfk_1+\022 \002\220\005",
    index=0x19866c8, offsets=0x7fffffff7690)
    at /home/vagrant/percona-xtrabackup-2.1.8/mysql-5.6/storage/innobase/lock/lock0lock.cc:6040
#16 0x000000000050b980 in lock_sec_rec_read_check_and_lock (flags=0, block=0x7fffef4f4c40,
    rec=0x7fffefeb93f9 "raptor/verify_queueraptor/verify_queue_ibfk_1fkd_files_queue_ibfk_1+\022 \002\220\005",
    index=0x19866c8, offsets=0x7fffffff7690, mode=LOCK_S, gap_mode=0, thr=0x1981238)
    at /home/vagrant/percona-xtrabackup-2.1.8/mysql-5.6/storage/innobase/lock/lock0lock.cc:6287
#17 0x00000000009c9ad0 in sel_set_rec_lock (block=0x7fffef4f4c40,
    rec=0x7fffefeb93f9 "raptor/verify_queueraptor/verify_queue_ibfk_1fkd_files_queue_ibfk_1+\022 \002\220\005",
    index=0x19866c8, offsets=0x7fffffff7690, mode=2, type=0, thr=0x1981238)
    at /home/vagrant/percona-xtrabackup-2.1.8/mysql-5.6/storage/innobase/row/row0sel.cc:1015
#18 0x00000000009ca99c in row_sel (node=0x1976998, thr=0x1981238)
    at /home/vagrant/percona-xtrabackup-2.1.8/mysql-5.6/storage/innobase/row/row0sel.cc:1597
#19 0x00000000009cb7e9 in row_sel_step (thr=0x1981238)
    at /home/vagrant/percona-xtrabackup-2.1.8/mysql-5.6/storage/innobase/row/row0sel.cc:2120
#20 0x000000000061116b in que_thr_step (thr=0x1981238)
    at /home/vagrant/percona-xtrabackup-2.1.8/mysql-5.6/storage/innobase/que/que0que.cc:1083
#21 0x00000000006114aa in que_run_threads_low (thr=0x1981238)
    at /home/vagrant/percona-xtrabackup-2.1.8/mysql-5.6/storage/innobase/que/que0que.cc:1167
#22 0x0000000000611674 in que_run_threads (thr=0x1981238)
    at /home/vagrant/percona-xtrabackup-2.1.8/mysql-5.6/storage/innobase/que/que0que.cc:1208
#23 0x00000000006118da in que_eval_sql (info=0x1972658,
    sql=0xccb430 "PROCEDURE DROP_TABLE_PROC () IS\nsys_foreign_id CHAR;\ntable_id CHAR;\nindex_id CHAR;\nforeign_id CHAR;\nfound INT;\nBEGIN\nSELECT ID INTO table_id\nFROM SYS_TABLES\nWHERE NAME = :table_name\nLOCK IN SHARE MODE"...,
    reserve_dict_mutex=0, trx=0x1971298)
    at /home/vagrant/percona-xtrabackup-2.1.8/mysql-5.6/storage/innobase/que/que0que.cc:1285
#24 0x000000000059fe62 in fil_remove_invalid_table_from_data_dict (name=0x19687f0 "raptor/verify_queue")
    at /home/vagrant/percona-xtrabackup-2.1.8/mysql-5.6/storage/innobase/fil/fil0fil.cc:3681
#25 0x00000000005a0327 in fil_open_single_table_tablespace (validate=true, fix_dict=false, id=395481, flags=0,
    tablename=0x19687f0 "raptor/verify_queue", path_in=0x0)
    at /home/vagrant/percona-xtrabackup-2.1.8/mysql-5.6/storage/innobase/fil/fil0fil.cc:3902
#26 0x00000000004930a1 in dict_load_table (name=0x19687f0 "raptor/verify_queue", cached=1,
    ignore_err=DICT_ERR_IGNORE_RECOVER_LOCK)
    at /home/vagrant/percona-xtrabackup-2.1.8/mysql-5.6/storage/innobase/dict/dict0load.cc:2384
#27 0x000000000049377d in dict_load_table_on_id (table_id=396062, ignore_err=DICT_ERR_IGNORE_RECOVER_LOCK)
    at /home/vagrant/percona-xtrabackup-2.1.8/mysql-5.6/storage/innobase/dict/dict0load.cc:2604
#28 0x00000000005aa24a in dict_table_open_on_id_low (table_id=396062, ignore_err=DICT_ERR_IGNORE_RECOVER_LOCK)
    at /home/vagrant/percona-xtrabackup-2.1.8/mysql-5.6/storage/innobase/include/dict0priv.ic:92
#29 0x00000000005ab477 in dict_table_open_on_id (table_id=396062, dict_locked=0, table_op=DICT_TABLE_OP_LOAD_TABLESPACE)
    at /home/vagrant/percona-xtrabackup-2.1.8/mysql-5.6/storage/innobase/dict/dict0dict.cc:804
#30 0x000000000061d99f in trx_resurrect_table_locks (trx=0x19673c8, undo=0x193dd28)
---Type <return> to continue, or q <return> to quit---
    at /home/vagrant/percona-xtrabackup-2.1.8/mysql-5.6/storage/innobase/trx/trx0trx.cc:473
#31 0x000000000061e17e in trx_lists_init_at_db_start ()
    at /home/vagrant/percona-xtrabackup-2.1.8/mysql-5.6/storage/innobase/trx/trx0trx.cc:733
#32 0x0000000000665c8b in trx_sys_init_at_db_start ()
    at /home/vagrant/percona-xtrabackup-2.1.8/mysql-5.6/storage/innobase/trx/trx0sys.cc:538
#33 0x0000000000687430 in innobase_start_or_create_for_mysql ()
    at /home/vagrant/percona-xtrabackup-2.1.8/mysql-5.6/storage/innobase/srv/srv0start.cc:2382
#34 0x0000000000450bb8 in innodb_init () at xtrabackup.cc:1438
#35 0x00000000004584dc in xtrabackup_prepare_func () at xtrabackup.cc:5455
#36 0x0000000000459979 in main (argc=0, argv=0x15d02d8) at xtrabackup.cc:6035
(gdb)

Tags: i44002 i44398

Related branches

lp:~sergei.glushchenko/percona-xtrabackup/2.1-ST43302-xb-bug1340717
Alexey Kopytov (community): Approve
Diff: 425 lines (+81/-43)
2 files modified
patches/innodb56.patch (+46/-43)
test/t/bug1340717.sh (+35/-0)
lp:~sergei.glushchenko/percona-xtrabackup/2.2-ST43302-xb-bug1340717
Alexey Kopytov (community): Approve
Diff: 71 lines (+40/-2)
2 files modified
storage/innobase/fil/fil0fil.cc (+5/-2)
storage/innobase/xtrabackup/test/t/bug1340717.sh (+35/-0)
Revision history for this message
Sergei Glushchenko (sergei.glushchenko) wrote :

Xtrabackup crashed while tried to delete unused tables. purge_sys if not initialized. Seems to be specific to innodb56. Related parts of code:
trx_sys_init_at_db_start invoked before trx_purge_sys_create:
comment from srv0start.cc:
ib_bh = trx_sys_init_at_db_start();
n_recovered_trx = UT_LIST_GET_LEN(trx_sys->rw_trx_list);
/* The purge system needs to create the purge view and
therefore requires that the trx_sys is inited. */
trx_purge_sys_create(srv_n_purge_threads, ib_bh);
At the same time trx_lists_init_at_db_start invokes trx_resurrect_table_locks, which has been introduced in MySQL 5.6 (revno: 5045). Purpose of trx_resurrect_table_locks to be discovered.

no longer affects: percona-xtrabackup/1.6
no longer affects: percona-xtrabackup/2.0
Valerii Kravchuk (valerii-kravchuk)
tags: added: i44002
Valerii Kravchuk (valerii-kravchuk)
tags: added: i44398
Valerii Kravchuk (valerii-kravchuk)
tags: added: i44478
tags: removed: i44478
Revision history for this message
Shahriyar Rzayev (rzayev-sehriyar) wrote :

Percona now uses JIRA for bug reports so this bug report is migrated to: https://jira.percona.com/browse/PXB-410

To post a comment you must log in.
This report contains Public information  
Everyone can see this information.
Subscribing...

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.