Percona Server with XtraDB

Failing assertion: log_bmp_sys->parse_buf_end == log_bmp_sys->parse_buf in log0online.c line 1038

Reported by Roel Van de Paar on 2013-01-29
12
This bug affects 1 person
Affects Status Importance Assigned to Milestone
Percona Server
Status tracked in 5.6
5.1
High
Laurynas Biveinis
5.5
High
Laurynas Biveinis
5.6
High
Laurynas Biveinis

Bug Description

 InnoDB: Error: the age of the oldest untracked record exceeds the log group capacity!
130128 4:42:20 InnoDB: Assertion failure in thread 140293018244864 in file log0online.c line 1038
InnoDB: Failing assertion: log_bmp_sys->parse_buf_end == log_bmp_sys->parse_buf

But, there are many other errors in the log. Including:

130128 4:16:25 InnoDB: Database was not shut down normally!

While this is a clean MTR/RQG startup.

Start command (mainly for options reference):

[roel@macpro1 892115]$ cat cmd1058
ps -ef | grep 'cmdrun_1058' | grep -v grep | awk '{print $2}' | xargs sudo kill -9
rm -Rf /ssd/892115/cmdrun_1058
mkdir /ssd/892115/cmdrun_1058
cd /ssd/randgen
bash -c "set -o pipefail; perl runall.pl --queries=100000000 --seed=20163 --duration=180 --querytimeout=60 --short_column_names --sqltrace --reporter=Shutdown,Backtrace,QueryTimeout,ErrorLog,ErrorLogAlarm --mysqld=--log-output=none --mysqld=--sql_mode=ONLY_FULL_GROUP_BY --grammar=conf/percona_qa/percona_qa.yy --gendata
=conf/percona_qa/percona_qa.zz --basedir=/ssd/Percona-Server-5.5.28-rel29.3-416.Linux.x86_64 --threads=25 --notnull --validator=Transformer --mysqld=--innodb_track_changed_pages=1 --mysqld=--innodb_log_file_size=1048576 --mysqld=--innodb_log_files_in_group=2 --mysqld=--innodb_log_buffer_size=1048576 --mysqld=--innodb_log_block_size=512 --mysqld=--innodb_fast_shutdown=2 --mysqld=--innodb_adaptive_flushing_method=native --mysqld=--innodb_use_global_flush_log_at_trx_commit=0 --mysqld=--userstat --mysqld=--innodb_file_per_table=1 --mtr-build-thread=794 --mask=26889 --vardir1=/ssd/892115/cmdrun_1058 > /ssd/892115/cmdrun1058.log 2>&1"

Assert happens in Percona-Server-5.5.28-rel29.3-416.Linux.x86_64 optimized build.

+bt
#0 0x00007f98980d669c in pthread_kill () from /lib64/libpthread.so.0
#1 0x000000000068832e in handle_fatal_signal (sig=6) at /ssd/QA-16274-5.5/Percona-Server-5.5.28-rel29.3/sql/signal_handler.cc:249
#2 <signal handler called>
#3 0x00007f98972a18a5 in raise () from /lib64/libc.so.6
#4 0x00007f98972a3085 in abort () from /lib64/libc.so.6
#5 0x00000000008de092 in log_online_follow_log_group (contiguous_lsn=957953024, group=0x351dab8) at /ssd/QA-16274-5.5/Percona-Server-5.5.28-rel29.3/storage/innobase/log/log0online.c:1038
#6 log_online_follow_redo_log () at /ssd/QA-16274-5.5/Percona-Server-5.5.28-rel29.3/storage/innobase/log/log0online.c:1178
#7 0x0000000000813555 in srv_redo_log_follow_thread (arg=<optimized out>) at /ssd/QA-16274-5.5/Percona-Server-5.5.28-rel29.3/storage/innobase/srv/srv0srv.c:3080
#8 0x00007f98980d1851 in start_thread () from /lib64/libpthread.so.0
#9 0x00007f989735711d in clone () from /lib64/libc.so.6

Roel Van de Paar (roel11) wrote :

The error log showed a BLOB larger than the log capacity, which probably caused this down the road.

Roel - can you get the SQL of this run?

Roel Van de Paar (roel11) wrote :

Laurynas, I can get the SQL, but since it's 25 threaded it will highly likely not reproduce easily. Are you simply interested in reviewing what was executed?

tags: added: bitmap
Roel Van de Paar (roel11) wrote :

Adding the following to this bug after discussion with Laurynas;

InnoDB: Error: the age of the oldest untracked record exceeds the log group capacity!
130127 14:18:22 InnoDB: ERROR: the age of the last checkpoint is 1894472,
InnoDB: which exceeds the log group capacity 1883751.
InnoDB: If you are using big BLOB or TEXT rows, you must set the
InnoDB: combined size of log files at least 10 times bigger than the
InnoDB: largest such row.
InnoDB: Error: the age of the oldest untracked record exceeds the log group capacity!
InnoDB: Error: the age of the oldest untracked record exceeds the log group capacity!

This might be due to missing actual overwritten log parse detection, which is (cancelled) work in progress at - https://bazaar.launchpad.net/~vlad-lesin/percona-server/i_s-innodb-log-tracking-status/revision/459

Roel, no need for further analysis of this bug for now.

Roel Van de Paar (roel11) wrote :

FYGI, present also in QA-16724-5.5-2 tree at revid Percona-Server-5.5.28-rel29.3-422-debug.Linux.x86_64

130203 18:55:04 InnoDB: Assertion failure in thread 139644531517184 in file log0online.c line 1065
InnoDB: Failing assertion: log_bmp_sys->parse_buf_end == log_bmp_sys->parse_buf

Attaching interesting mysqld error log and stacks.

Roel Van de Paar (roel11) wrote :
Roel Van de Paar (roel11) wrote :
tags: added: xtradb
Roel Van de Paar (roel11) wrote :

Still seen: bug 1233506

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

Duplicates of this bug

Other bug subscribers