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

InnoDB: Assertion failure in thread <nr> in file os0file.c line 2625

Bug #1177244 reported by George Ormond Lorch III
6
This bug affects 1 person
Affects Status Importance Assigned to Milestone
Percona XtraBackup moved to https://jira.percona.com/projects/PXB
Incomplete
Undecided
Unassigned

Bug Description

Running RQG in a loop against PS 5.5 with XB 2.1 using the Percona Test Bench. While performing incremental backup:

InnoDB Backup Utility v1.5.1-xtrabackup; Copyright 2003, 2009 Innobase Oy
and Percona Ireland Ltd 2009-2012. All Rights Reserved.

This software is published under
the GNU GENERAL PUBLIC LICENSE Version 2, June 1991.

130506 19:24:35 innobackupex: Connecting to MySQL server with DSN 'dbi:mysql:;mysql_read_default_file=/data/dev/cpb/test-3/mysql.1/my.cnf;mysql_read_default_group=xtrabackup' (using password: NO).
130506 19:24:35 innobackupex: Connected to MySQL server
IMPORTANT: Please check that the backup run completes successfully.
           At the end of a successful backup run innobackupex
           prints "completed OK!".

innobackupex: Using mysql server version 5.5.30

innobackupex: Created backup directory /data/dev/cpb/test-3/backup-1.5

130506 19:24:35 innobackupex: Starting ibbackup with command: xtrabackup_55 --defaults-file="/data/dev/cpb/test-3/mysql.1/my.cnf" --defaults-group="mysqld" --backup --suspend-at-end --target-dir=/data/dev/cpb/test-3/backup-1.5 --tmpdir=/data/dev/cpb/test-3 --incremental-basedir='/data/dev/cpb/test-3/backup-1.4'
innobackupex: Waiting for ibbackup (pid=10889) to suspend
innobackupex: Suspend file '/data/dev/cpb/test-3/backup-1.5/xtrabackup_suspended_2'

xtrabackup_55 version 2.1.0beta1 for Percona Server 5.5.16 Linux (x86_64) (revision id: undefined)
incremental backup from 836432349 is enabled.
xtrabackup: uses posix_fadvise().
xtrabackup: cd to /data/dev/cpb/test-3/mysql.1/data
xtrabackup: Target instance is assumed as followings.
xtrabackup: innodb_data_home_dir = ./
xtrabackup: innodb_data_file_path = ibdata1:10M:autoextend
xtrabackup: innodb_log_group_home_dir = ./
xtrabackup: innodb_log_files_in_group = 2
xtrabackup: innodb_log_file_size = 536870912
130506 19:24:35 InnoDB: Warning: allocated tablespace 193, old maximum was 9
>> log scanned up to (840309922)
xtrabackup: using the changed page bitmap
[01] Copying ./ibdata1 to /data/dev/cpb/test-3/backup-1.5/ibdata1.delta
[01] ...done
[01] Copying ./rqg1/table500_innodb_default_int_autoinc.ibd to /data/dev/cpb/test-3/backup-1.5/rqg1/table500_innodb_default_int_autoinc.ibd.delta
[01] ...done
[01] Copying ./rqg1/table100_innodb_default_int_autoinc.ibd to /data/dev/cpb/test-3/backup-1.5/rqg1/table100_innodb_default_int_autoinc.ibd.delta
[01] ...done
>> log scanned up to (840324603)
[01] Copying ./rqg1/table500_innodb_dynamic.ibd to /data/dev/cpb/test-3/backup-1.5/rqg1/table500_innodb_dynamic.ibd.delta
[01] ...done
[01] Copying ./rqg1/#sql-20dd_19.ibd to /data/dev/cpb/test-3/backup-1.5/rqg1/#sql-20dd_19.ibd.delta
[01] ...done
[01] Copying ./rqg1/table500_innodb_compressed_int.ibd to /data/dev/cpb/test-3/backup-1.5/rqg1/table500_innodb_compressed_int.ibd.delta
[01] ...done
[01] Copying ./rqg1/table500_innodb_default_int.ibd to /data/dev/cpb/test-3/backup-1.5/rqg1/table500_innodb_default_int.ibd.delta
[01] ...done
[01] Copying ./rqg1/f.ibd to /data/dev/cpb/test-3/backup-1.5/rqg1/f.ibd.delta
[01] ...done
[01] Copying ./rqg1/table500_innodb_dynamic_int.ibd to /data/dev/cpb/test-3/backup-1.5/rqg1/table500_innodb_dynamic_int.ibd.delta
InnoDB: Error: tried to read 1048576 bytes at offset 0 0.
InnoDB: Was only able to read 491520.
InnoDB: Fatal error: cannot read from file. OS error number 17.
130506 19:24:38 InnoDB: Assertion failure in thread 140516780906240 in file os0file.c line 2625
InnoDB: We intentionally generate a memory trap.
InnoDB: Submit a detailed bug report to http://bugs.mysql.com.
InnoDB: If you get repeated assertion failures or crashes, even
InnoDB: immediately after the mysqld startup, there may be
InnoDB: corruption in the InnoDB tablespace. Please refer to
InnoDB: http://dev.mysql.com/doc/refman/5.5/en/forcing-innodb-recovery.html
InnoDB: about forcing recovery.
innobackupex: Error: ibbackup child process has died at /data/bin/xb-2.1/innobackupex line 386.
DBD::mysql::db selectrow_array failed: MySQL server has gone away at /data/bin/xb-2.1/innobackupex line 1322.

Revision history for this message
George Ormond Lorch III (gl-az) wrote :

my.cnf:
[client]
port=10000
socket=/data/dev/cpb/test-3/mysql.1/mysql.sock
[mysqld]
basedir=/data/bin/ps-5.5
datadir=/data/dev/cpb/test-3/mysql.1/data
tmpdir=/data/dev/cpb/test-3/mysql.1/tmp
port=10000
socket=/data/dev/cpb/test-3/mysql.1/mysql.sock
pid-file=/data/dev/cpb/test-3/mysql.1/mysql.pid
console
user=root
server-id=1
innodb_buffer_pool_size=1G
innodb_file_format=antelope
innodb_file_per_table=1
innodb_log_file_size=512M
innodb_track_changed_pages=TRUE

Changed in percona-xtrabackup:
status: New → Incomplete
Revision history for this message
George Ormond Lorch III (gl-az) wrote :
Download full text (12.3 KiB)

Backtrace:

Thread 13 (Thread 0x7fcca4a79700 (LWP 10896)):
#0 0x000000391b00b43c in pthread_cond_wait@@GLIBC_2.3.2 () from /lib64/libpthread.so.0
#1 0x00000000004af679 in os_cond_wait (event=0x216f9b0, reset_sig_count=1) at /home/glorch/dev/ps-5.5/xb-2.1/Percona-Server-5.5/storage/innobase/os/os0sync.c:207
#2 os_event_wait_low (event=0x216f9b0, reset_sig_count=1) at /home/glorch/dev/ps-5.5/xb-2.1/Percona-Server-5.5/storage/innobase/os/os0sync.c:609
#3 0x00000000004add69 in os_aio_simulated_handle (global_segment=5, message1=0x7fcca4a78e68, message2=0x7fcca4a78e60, type=0x7fcca4a78e58, space_id=0x7fcca4a78e50) at /home/glorch/dev/ps-5.5/xb-2.1/Percona-Server-5.5/storage/innobase/os/os0file.c:5097
#4 0x00000000004748d4 in fil_aio_wait (segment=5) at /home/glorch/dev/ps-5.5/xb-2.1/Percona-Server-5.5/storage/innobase/fil/fil0fil.c:5701
#5 0x0000000000409b78 in io_handler_thread (arg=<value optimized out>) at xtrabackup.cc:2276
#6 0x000000391b007851 in start_thread () from /lib64/libpthread.so.0
#7 0x000000391a8e811d in clone () from /lib64/libc.so.6

Thread 12 (Thread 0x7fcc9f5fe700 (LWP 10898)):
#0 0x000000391b00b43c in pthread_cond_wait@@GLIBC_2.3.2 () from /lib64/libpthread.so.0
#1 0x00000000004af679 in os_cond_wait (event=0x216fab0, reset_sig_count=1) at /home/glorch/dev/ps-5.5/xb-2.1/Percona-Server-5.5/storage/innobase/os/os0sync.c:207
#2 os_event_wait_low (event=0x216fab0, reset_sig_count=1) at /home/glorch/dev/ps-5.5/xb-2.1/Percona-Server-5.5/storage/innobase/os/os0sync.c:609
#3 0x00000000004add69 in os_aio_simulated_handle (global_segment=7, message1=0x7fcc9f5fde68, message2=0x7fcc9f5fde60, type=0x7fcc9f5fde58, space_id=0x7fcc9f5fde50) at /home/glorch/dev/ps-5.5/xb-2.1/Percona-Server-5.5/storage/innobase/os/os0file.c:5097
#4 0x00000000004748d4 in fil_aio_wait (segment=7) at /home/glorch/dev/ps-5.5/xb-2.1/Percona-Server-5.5/storage/innobase/fil/fil0fil.c:5701
#5 0x0000000000409b78 in io_handler_thread (arg=<value optimized out>) at xtrabackup.cc:2276
#6 0x000000391b007851 in start_thread () from /lib64/libpthread.so.0
#7 0x000000391a8e811d in clone () from /lib64/libc.so.6

Thread 11 (Thread 0x7fcca7e6c700 (LWP 10891)):
#0 0x000000391b00b43c in pthread_cond_wait@@GLIBC_2.3.2 () from /lib64/libpthread.so.0
#1 0x00000000004af679 in os_cond_wait (event=0x216f730, reset_sig_count=1) at /home/glorch/dev/ps-5.5/xb-2.1/Percona-Server-5.5/storage/innobase/os/os0sync.c:207
#2 os_event_wait_low (event=0x216f730, reset_sig_count=1) at /home/glorch/dev/ps-5.5/xb-2.1/Percona-Server-5.5/storage/innobase/os/os0sync.c:609
#3 0x00000000004add69 in os_aio_simulated_handle (global_segment=0, message1=0x7fcca7e6be68, message2=0x7fcca7e6be60, type=0x7fcca7e6be58, space_id=0x7fcca7e6be50) at /home/glorch/dev/ps-5.5/xb-2.1/Percona-Server-5.5/storage/innobase/os/os0file.c:5097
#4 0x00000000004748d4 in fil_aio_wait (segment=0) at /home/glorch/dev/ps-5.5/xb-2.1/Percona-Server-5.5/storage/innobase/fil/fil0fil.c:5701
#5 0x0000000000409b78 in io_handler_thread (arg=<value optimized out>) at xtrabackup.cc:2276
#6 0x000000391b007851 in start_thread () from /lib64/libpthread.so.0
#7 0x000000391a8e811d in clone () from /lib64/libc.so.6

Thread 10 (...

Revision history for this message
Alexey Kopytov (akopytov) wrote :

I think this should be fixed with the patch for bug #1079700. Marking as a duplicate for now, please reopen if can also be observed with that fix applied.

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.