[MDEV-2390] LP:616236 - Aria assertion "!pinned_page->changed || undo_lsn != ((LSN)0) || !info->s->now_transactional Created: 2010-08-11  Updated: 2015-02-02  Resolved: 2012-10-04

Status: Closed
Project: MariaDB Server
Component/s: None
Affects Version/s: None
Fix Version/s: None

Type: Bug Priority: Major
Reporter: Philip Stoev (Inactive) Assignee: Michael Widenius
Resolution: Fixed Votes: 0
Labels: Launchpad

Attachments: XML File LPexportBug616236.xml     Zip Archive LPexportBug616236_var-bug616236.zip     Zip Archive LPexportBug616236_var-bug616236.zip    

 Description   

When executing a DML workload with multiple indexes, aria asserted as follows:

#2 0x00000000006729f7 in handle_segfault (sig=6) at mysqld.cc:2728
#3 <signal handler called>
#4 0x000000307b6329c5 in raise (sig=6)
at ../nptl/sysdeps/unix/sysv/linux/raise.c:64
#5 0x000000307b6341a5 in abort () at abort.c:92
#6 0x000000307b62b945 in __assert_fail (
assertion=0xd763b8 "!pinned_page->changed || undo_lsn != ((LSN)0) || !info->s->now_transactional", file=<value optimized out>, line=68,
function=<value optimized out>) at assert.c:81
#7 0x00000000009823cb in _ma_unpin_all_pages (info=0x7f910004ec68,
undo_lsn=0) at ma_key_recover.c:67
#8 0x0000000000996620 in _ma_unpin_all_pages_and_finalize_row (
info=0x7f910004ec68, undo_lsn=0) at ma_key_recover.h:102
#9 0x000000000099f3cd in _ma_update_block_record2 (info=0x7f910004ec68,
record_pos=1545, oldrec=0x7f91000413f0 "\367\237\377",
record=0x7f910003ffb0 "\367\233\377", undo_lsn=1) at ma_blockrec.c:3713
#10 0x000000000099f9a6 in _ma_update_block_record (info=0x7f910004ec68,
record_pos=1545, orig_rec=0x7f91000413f0 "\367\237\377",
new_rec=0x7f910003ffb0 "\367\233\377") at ma_blockrec.c:3850
#11 0x00000000009ae79d in maria_update (info=0x7f910004ec68,
oldrec=0x7f91000413f0 "\367\237\377",
newrec=0x7f910003ffb0 "\367\233\377") at ma_update.c:160
#12 0x000000000096a103 in ha_maria::update_row (this=0x7f9100012230,
old_data=0x7f91000413f0 "\367\237\377",
new_data=0x7f910003ffb0 "\367\233\377") at ha_maria.cc:2113
#13 0x00000000007cee75 in handler::ha_update_row (this=0x7f9100012230,
old_data=0x7f91000413f0 "\367\237\377",
new_data=0x7f910003ffb0 "\367\233\377") at handler.cc:4869
#14 0x00000000007d7eba in ha_partition::update_row (this=0x7f91000114e0,
old_data=0x7f91000413f0 "\367\237\377",
new_data=0x7f910003ffb0 "\367\233\377") at ha_partition.cc:3162
#15 0x00000000007cee75 in handler::ha_update_row (this=0x7f91000114e0,
old_data=0x7f91000413f0 "\367\237\377",
new_data=0x7f910003ffb0 "\367\233\377") at handler.cc:4869
#16 0x0000000000742a62 in mysql_update (thd=0x3ab8b18,
table_list=0x7f911c014ec8, fields=..., values=..., conds=0x7f911c0159d0,
order_num=0, order=0x0, limit=18446744073709551511,
handle_duplicates=DUP_ERROR, ignore=false) at sql_update.cc:652
#17 0x000000000068849e in mysql_execute_command (thd=0x3ab8b18)
at sql_parse.cc:3120
#18 0x000000000069151e in mysql_parse (thd=0x3ab8b18,
inBuf=0x7f911c014bf0 "UPDATE `table100_maria_key_pk_parts_2_int_autoinc` SET `col_varchar_255_utf8_key` = REPEAT( _LATIN1 0x176 , 190 ) WHERE `col_varchar_255_ucs2_key` <> REPEAT( _UCS2 0x55 , 50 )", length=175,
found_semicolon=0x7f912bffec88) at sql_parse.cc:6055
#19 0x00000000006834e2 in dispatch_command (command=COM_QUERY, thd=0x3ab8b18,
packet=0x3b581e9 "UPDATE `table100_maria_key_pk_parts_2_int_autoinc` SET `col_varchar_255_utf8_key` = REPEAT( _LATIN1 0x176 , 190 ) WHERE `col_varchar_255_ucs2_key` <> REPEAT( _UCS2 0x55 , 50 ) ", packet_length=176)
at sql_parse.cc:1204
#20 0x00000000006828a8 in do_command (thd=0x3ab8b18) at sql_parse.cc:898
#21 0x000000000067f898 in handle_one_connection (arg=0x3ab8b18)
at sql_connect.cc:1154
#22 0x000000307ba07761 in start_thread (arg=0x7f912bfff710)
at pthread_create.c:301
#23 0x000000307b6e150d in clone ()

rqg command line:

/home/buildbot/randgen/runall.pl \
--basedir=. \
--vardir=../../vardir-maria_many_indexes \
--grammar=/home/buildbot/randgen/conf/engines/many_indexes.yy \
--gendata=/home/buildbot/randgen/conf/engines/many_indexes.zz \
--rows=10000 \
--reporter=Backtrace,ErrorLog,Recovery,Shutdown \
--duration=240 \
--queries=1M \
--engine=Maria \
--rows=10000 \
-mysqld=-maria-checkpoint-interval=0 \
-mysqld=-log-output=file \
--seed=time

 Comments   
Comment by Philip Stoev (Inactive) [ 2010-08-11 ]

Re: Aria assertion "!pinned_page->changed || undo_lsn != ((LSN)0) || !info->s->now_transactional
Core binary, vardir, etc

bzr version-info:

revision-id: monty@mysql.com-20100810220446-jzy713163fjegn30
date: 2010-08-11 01:04:46 +0300
build-date: 2010-08-11 11:30:03 +0300
revno: 2846
branch-nick: 5.2

Comment by Philip Stoev (Inactive) [ 2010-08-11 ]

Core binary, vardir, etc

bzr version-info:

revision-id: <email address hidden>
date: 2010-08-11 01:04:46 +0300
build-date: 2010-08-11 11:30:03 +0300
revno: 2846
branch-nick: 5.2

core binary vardir , etc
LPexportBug616236_var-bug616236.zip

Comment by Philip Stoev (Inactive) [ 2010-08-11 ]

Re: Aria assertion "!pinned_page->changed || undo_lsn != ((LSN)0) || !info->s->now_transactional
This RQG command line reproduces this crash within 220 seconds

perl runall.pl -basedir=/home/philips/bzr/maria-5.1 --vardir=/home/philips/vardir-recovery$i --grammar=conf/engines/many_indexes.yy --gendata=conf/engines/many_indexes.zz --rows=10000 --reporter=Backtrace,ErrorLog,Recovery,Shutdown --duration=240 --queries=1M --engine=Maria --rows=10000 --mysqld=maria-checkpoint-interval=0 --mysqld=-log-output=file --seed=time

Comment by Philip Stoev (Inactive) [ 2010-08-11 ]

Re: Aria assertion "!pinned_page->changed || undo_lsn != ((LSN)0) || !info->s->now_transactional
This assertion is also seen on recovery, with the following backtrace:

#8 0x00897de8 in __assert_fail () from /lib/libc.so.6
#9 0x08531ca3 in _ma_unpin_all_pages (info=0x97cd528, undo_lsn=0) at ma_key_recover.c:67
#10 0x08544bd4 in _ma_unpin_all_pages_and_finalize_row (info=0x97cd528, undo_lsn=0) at ma_key_recover.h:102
#11 0x0854cbbb in _ma_update_at_original_place (info=0x97cd528, page=16, rownr=12, length_on_head_page=502, extent_count=0,
extent_info=0x97c1b43 "\001\377\356\377\375", '\003' <repeats 76 times>, oldrec=0x9837da0 "n\377\375", '\b' <repeats 197 times>...,
record=0x98391df "\356\377\375", '\b' <repeats 197 times>..., undo_lsn=4334155267) at ma_blockrec.c:3840
#12 0x085550f1 in _ma_apply_undo_row_update (info=0x97cd528, undo_lsn=4334155267, header=0x97c1b48 '\003' <repeats 76 times>, header_length=15)
at ma_blockrec.c:7144
#13 0x0859e799 in exec_UNDO_LOGREC_UNDO_ROW_UPDATE (rec=0xbfa1e888, trn=0x97b5b78) at ma_recovery.c:2230
#14 0x0859fe23 in run_undo_phase (uncommitted=0) at ma_recovery.c:2805
#15 0x0859a517 in maria_apply_log (from_lsn=4294975495, end_lsn=0, apply=MARIA_LOG_APPLY, trace_file=0x9763e38, should_run_undo_phase=1 '\001',
skip_DDLs_arg=1 '\001', take_checkpoints=1 '\001', warnings_count=0xbfa1eff4) at ma_recovery.c:394
#16 0x0859a070 in maria_recovery_from_log () at ma_recovery.c:221
#17 0x0851e0e5 in ha_maria_init (p=0x975f0c8) at ha_maria.cc:3259
#18 0x08397599 in ha_initialize_handlerton (plugin=0x97457f8) at handler.cc:430
#19 0x084526a7 in plugin_initialize (plugin=0x97457f8) at sql_plugin.cc:1039
#20 0x08452ec9 in plugin_init (argc=0x8a4b8d8, argv=0x9712870, flags=0) at sql_plugin.cc:1267
#21 0x0826be7b in init_server_components () at mysqld.cc:4131
#22 0x0826c937 in main (argc=14, argv=0xbfa1f5e4) at mysqld.cc:4603

Comment by Philip Stoev (Inactive) [ 2010-08-11 ]

This assertion is also seen on recovery, with the following backtrace:

#8 0x00897de8 in __assert_fail () from /lib/libc.so.6
#9 0x08531ca3 in _ma_unpin_all_pages (info=0x97cd528, undo_lsn=0) at ma_key_recover.c:67
#10 0x08544bd4 in _ma_unpin_all_pages_and_finalize_row (info=0x97cd528, undo_lsn=0) at ma_key_recover.h:102
#11 0x0854cbbb in _ma_update_at_original_place (info=0x97cd528, page=16, rownr=12, length_on_head_page=502, extent_count=0,
extent_info=0x97c1b43 "\001\377\356\377\375", '\003' <repeats 76 times>, oldrec=0x9837da0 "n\377\375", '\b' <repeats 197 times>...,
record=0x98391df "\356\377\375", '\b' <repeats 197 times>..., undo_lsn=4334155267) at ma_blockrec.c:3840
#12 0x085550f1 in _ma_apply_undo_row_update (info=0x97cd528, undo_lsn=4334155267, header=0x97c1b48 '\003' <repeats 76 times>, header_length=15)
at ma_blockrec.c:7144
#13 0x0859e799 in exec_UNDO_LOGREC_UNDO_ROW_UPDATE (rec=0xbfa1e888, trn=0x97b5b78) at ma_recovery.c:2230
#14 0x0859fe23 in run_undo_phase (uncommitted=0) at ma_recovery.c:2805
#15 0x0859a517 in maria_apply_log (from_lsn=4294975495, end_lsn=0, apply=MARIA_LOG_APPLY, trace_file=0x9763e38, should_run_undo_phase=1 '\001',
skip_DDLs_arg=1 '\001', take_checkpoints=1 '\001', warnings_count=0xbfa1eff4) at ma_recovery.c:394
#16 0x0859a070 in maria_recovery_from_log () at ma_recovery.c:221
#17 0x0851e0e5 in ha_maria_init (p=0x975f0c8) at ha_maria.cc:3259
#18 0x08397599 in ha_initialize_handlerton (plugin=0x97457f8) at handler.cc:430
#19 0x084526a7 in plugin_initialize (plugin=0x97457f8) at sql_plugin.cc:1039
#20 0x08452ec9 in plugin_init (argc=0x8a4b8d8, argv=0x9712870, flags=0) at sql_plugin.cc:1267
#21 0x0826be7b in init_server_components () at mysqld.cc:4131
#22 0x0826c937 in main (argc=14, argv=0xbfa1f5e4) at mysqld.cc:4603

recovery core, binary, datadir, etc.
LPexportBug616236_var-bug616236.zip

Comment by Michael Widenius [ 2010-08-21 ]

Re: Aria assertion "!pinned_page->changed || undo_lsn != ((LSN)0) || !info->s->now_transactional
This was fixed by my previous commit into 5.1.
I didn't include the bug number in the push as I found and fixed the bug independently and didn't know about this bug report.

Comment by Philip Stoev (Inactive) [ 2010-08-25 ]

Re: Aria assertion "!pinned_page->changed || undo_lsn != ((LSN)0) || !info->s->now_transactional
I can confirm this is fixed.

Comment by Rasmus Johansson (Inactive) [ 2010-09-09 ]

Launchpad bug id: 616236

Generated at Thu Feb 08 06:41:31 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.