← Back to team overview

percona-discussion team mailing list archive

[Bug 342540] Re: apply-log hangs on partial backup

 

I think hang may also happen here:

        if (recv_sys->apply_batch_on) {

                mutex_exit(&(recv_sys->mutex));

                os_thread_sleep(500000);

                goto loop;
        }

here is bt with more debug info:

(gdb) bt
#0  0x00000030e42901d5 in __nanosleep_nocancel () from /lib64/tls/libc.so.6
#1  0x00000030e42c3058 in usleep () from /lib64/tls/libc.so.6
#2  0x0000000000501168 in os_thread_sleep (tm=548682064480) at os0thread.c:271
#3  0x00000000004b2c45 in recv_apply_hashed_log_recs (allow_ibuf=0) at log0recv.c:1441
#4  0x00000000004b4a85 in recv_scan_log_recs (apply_automatically=1, available_memory=100663296, store_to_hash=1,
    buf=0x2a9c2a4200 "\221?E%\002", len=65536, start_lsn={high = 1315, low = 3163179008},
    contiguous_lsn=0x7fbffff160, group_scanned_lsn=0x7fbffff170) at log0recv.c:2538
#5  0x00000000004b4bda in recv_group_scan_log_recs (group=0x2a956604b8, contiguous_lsn=0x7fbffff160,
    group_scanned_lsn=0x7fbffff170) at log0recv.c:2577
#6  0x00000000004b55d1 in recv_recovery_from_checkpoint_start (type=78656949, limit_lsn=
      {high = 4294967295, low = 4294967295}, min_flushed_lsn={high = 1132, low = 2546717136}, max_flushed_lsn=
      {high = 1132, low = 2546717136}) at log0recv.c:2819
#7  0x000000000040c2d3 in innobase_start_or_create_for_mysql () at srv0start.c:1446
#8  0x00000000004039d9 in innodb_init () at xtrabackup.c:1187
#9  0x00000000004063c2 in xtrabackup_prepare_func () at xtrabackup.c:2636
#10 0x000000000040681c in main (argc=0, argv=0x67dc48) at xtrabackup.c:2833
(gdb) p recv_sys->apply_batch_on
$1 = 1
(gdb) p recv_sys->n_addrs
$2 = 4

-- 
apply-log hangs on partial backup
https://bugs.launchpad.net/bugs/342540
You received this bug notification because you are a member of Percona
developers, which is the registrant for Percona-XtraBackup.

Status in Open source backup tool for InnoDB and XtraDB: Confirmed

Bug description:
I did backup  as
./innobackupex-1.5.1 --include=art53.* ./  --stream=tar > /mnt/data/tmp/dat.tar  


I unpacked dat.tar 
and 
do
 ./innobackupex-1.5.1 --apply-log /mnt/data/tmp/dat/

there bunch of errors like:

090313 16:25:30  InnoDB: Error: table 'test/test_innodb'
InnoDB: in InnoDB data dictionary has tablespace id 1699,
InnoDB: but tablespace with that id or name does not exist. Have
InnoDB: you deleted or moved .ibd files?
InnoDB: This may also be a table created with CREATE TEMPORARY TABLE
InnoDB: whose .ibd and .frm files MySQL automatically removed, but the
InnoDB: table still exists in the InnoDB internal data dictionary.
InnoDB: Please refer to
InnoDB: http://dev.mysql.com/doc/refman/5.0/en/innodb-troubleshooting.html
InnoDB: for how to resolve the issue.
090313 16:25:30  InnoDB: Starting an apply batch of log records to the database...
InnoDB: Progress in percents: 0 1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 57 58 59 60 61 62 63 64 65 66 67 68 69 70 71 72 73 74 75 76 77 78 79 80 81 82 83 84 85 86 87 88 89 90 91 92 93 94 95 96 97 98 99
InnoDB: Apply batch completed
InnoDB: Last MySQL binlog file position 0 437810557, file name ./db02-bin.001225
InnoDB: Starting in background the rollback of uncommitted transactions
090313 16:25:35  InnoDB: Rolling back trx with id 4 9421214, 12 rows to undo
090313 16:25:36  InnoDB: Started; log sequence number 1171 2823684590
090313 16:25:36  InnoDB: error: space object of table art60/link_out60,
InnoDB: space id 1453 did not exist in memory. Retrying an open.
090313 16:25:36  InnoDB: Operating system error number 2 in a file operation.
InnoDB: The error means the system cannot find the path specified.
090313 16:25:36  InnoDB: Error: trying to open a table, but could not
InnoDB: open the tablespace file './art60/link_out60.ibd'!
InnoDB: Have you moved InnoDB .ibd files around without using the
InnoDB: commands DISCARD TABLESPACE and IMPORT TABLESPACE?
InnoDB: It is also possible that this is a temporary table #sql...,
InnoDB: and MySQL removed the .ibd file for this.
InnoDB: Please refer to
InnoDB: http://dev.mysql.com/doc/refman/5.0/en/innodb-troubleshooting.html
InnoDB: for how to resolve the issue.

[notice (again)]
  If you use binary log and don't use any hack of group commit,
  the binary log position seems to be:
InnoDB: Last MySQL binlog file position 0 437810557, file name ./db02-bin.001225

090313 16:25:36  InnoDB: Starting shutdown...

InnoDB: Rolling back of trx id 4 9421214 completed
090313 16:25:36  InnoDB: Rollback of non-prepared transactions completed

but on last operation is seem hang (I waited few hours).

After Ctrl-C I got:

innobackupex: Error: 
innobackupex: ibbackup failed at ./innobackupex-1.5.1 line 427.



References