Bug #34632 Falcon assertion in Table::checkUniqueRecordVersion line 2441
Submitted: 18 Feb 2008 6:37 Modified: 8 Jan 2009 9:48
Reporter: Philip Stoev Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Server: Falcon storage engine Severity:S3 (Non-critical)
Version:6.0.4 OS:Any
Assigned to: Kevin Lewis CPU Architecture:Any

[18 Feb 2008 6:37] Philip Stoev
Description:
When running the iuds2 systems test with triggers disabled, the server asserted like this after a few hours:

#0  0x0000003ba880b132 in pthread_kill () from /lib64/libpthread.so.0
#1  0x0000000000650e12 in handle_segfault (sig=4) at mysqld.cc:2313
#2  <signal handler called>
#3  0x0000003ba880dd4d in raise () from /lib64/libpthread.so.0
#4  0x0000000000854f1c in Error::debugBreak () at Error.cpp:92
#5  0x0000000000854e30 in Error::error (string=0x0) at Error.cpp:69
#6  0x0000000000854f06 in Error::assertionFailed (fileName=0xcae <Address 0xcae out of bounds>, line=20143) at Error.cpp:76
#7  0x0000000000828f92 in Table::checkUniqueRecordVersion (this=0x2aaaaaff5b88, recordNumber=20143, index=0x2aaaaaff6208, transaction=0x2aaab4db6d28,
    record=0x2aaab231d820, sync=0x473df560) at Table.cpp:2441
#8  0x0000000000828e09 in Table::checkUniqueIndex (this=0x2aaaaaff5b88, index=0x2aaaaaff6208, transaction=0x2aaab4db6d28, record=0x2aaab231d820,
    sync=0x473df560) at Table.cpp:2381
#9  0x0000000000828d30 in Table::checkUniqueIndexes (this=0x2aaaaaff5b88, transaction=0x2aaab4db6d28, record=0x2aaab231d820, sync=0x473df560)
    at Table.cpp:2355
#10 0x000000000082a166 in Table::update (this=0x2aaaaaff5b88, transaction=0x2aaab4db6d28, orgRecord=0x473df560, stream=0x2aaaab89bf50) at Table.cpp:3046
#11 0x000000000081a82d in StorageDatabase::updateRow (this=0xcae, storageConnection=0x4eaf, table=0x2aaaaaff5b88, oldRecord=0xc1b7388, stream=0x2aaaab89bf50)
    at StorageDatabase.cpp:637
#12 0x000000000081e7f9 in StorageTable::updateRow (this=0x2aaaab8969c8, recordNumber=20143) at StorageTable.cpp:145
#13 0x0000000000810041 in StorageInterface::update_row (this=0x2aaab0f30c80, oldData=0x4eaf <Address 0x4eaf out of bounds>, newData=0x2aaab0f30f20 "О©ҐО©ҐH")
    at ha_falcon.cpp:1090
#14 0x000000000073aed5 in handler::ha_update_row (this=0x2aaab0f30c80, old_data=0x2aaab0f30f48 "О©Ґ=B", new_data=0x2aaab0f30f20 "О©ҐО©ҐH") at handler.cc:4621
#15 0x00000000006dc8c7 in mysql_update (thd=0xa785580, table_list=0xaa990e0, fields=@0xa787070, values=@0xa787470, conds=0x94857b0, order_num=155737560,
    order=0x0, limit=18446744073709551615, handle_duplicates=DUP_ERROR, ignore=false) at sql_update.cc:637
#16 0x000000000065e134 in mysql_execute_command (thd=0xa785580) at sql_parse.cc:2544
#17 0x000000000066317e in mysql_parse (thd=0xa785580,
    inBuf=0xaa98dd0 "UPDATE systest1.tb1_eng1 target\nSET i1 = (SELECT new_i1 FROM systest1.t1_tmp source WHERE source.i1 = target.i1),\nf1 = @connection_id,\nf2 = @operation,\nf3 = ROUND(i1/@max_val,3),\nf4 = @my_now\nWHERE i1"..., length=282, found_semicolon=0x473e0590) at sql_parse.cc:5410
#18 0x000000000065b895 in dispatch_command (command=COM_QUERY, thd=0xa785580, packet=0xaa98eea "", packet_length=282) at sql_parse.cc:948
#19 0x000000000065b092 in do_command (thd=0xa785580) at sql_parse.cc:697
#20 0x0000000000659e4f in handle_one_connection (arg=0xcae) at sql_connect.cc:1146
#21 0x0000003ba88062f7 in start_thread () from /lib64/libpthread.so.0
#22 0x0000003ba80ce85d in clone () from /lib64/libc.so.6

How to repeat:
Run iuds2.tst systems test with Falcon and set WITH_TRIGGERS=0 in iuds2.tst.

Core files will be provided shortly.

Suggested fix:
It appears to me that this function requires extra attention -- past bug reports show that we have hit several different assertions in it over time.
[20 Feb 2008 20:31] Kevin Lewis
Philip, Please re-verify with the current build. not using GCC 3.2.3
[21 Feb 2008 10:01] Philip Stoev
This assertion happened again less than ten minutes after test started with the debug binary compiled with GCC: (GNU) 4.1.0 (SUSE Linux).
[21 Feb 2008 16:18] Philip Stoev
Here is a new stack trace which leads to the same assertion. I saved the core in dl360-g5-a.mysql.com:/data1/6.0.4/systest_vardir-bug34632-2

#0  0x0000003ba880b132 in pthread_kill () from /lib64/libpthread.so.0
#1  0x000000000065e64a in handle_segfault (sig=4) at mysqld.cc:2313
#2  <signal handler called>
#3  0x0000003ba880dd4d in raise () from /lib64/libpthread.so.0
#4  0x00000000008887ac in Error::debugBreak () at Error.cpp:92
#5  0x00000000008888a2 in Error::error (string=<value optimized out>) at Error.cpp:69
#6  0x0000000000888902 in Error::assertionFailed (fileName=0x4 <Address 0x4 out of bounds>, line=27238) at Error.cpp:76
#7  0x00000000008549d7 in Table::checkUniqueRecordVersion (this=0x2aaaaad1b448, recordNumber=<value optimized out>, index=0x2aaaaad1bac8,
    transaction=0x2aaab0f00f30, record=<value optimized out>, sync=0x4882f6a0) at Table.cpp:2441
#8  0x0000000000854e47 in Table::checkUniqueIndex (this=0x2aaaaad1b448, index=0x2aaaaad1bac8, transaction=0x2aaab0f00f30, record=0x2aaab381dcc8,
    sync=0x4882f6a0) at Table.cpp:2381
#9  0x0000000000854f22 in Table::checkUniqueIndexes (this=0x2aaaaad1b448, transaction=0x2aaab0f00f30, record=0x2aaab381dcc8, sync=0x4882f6a0)
    at Table.cpp:2355
#10 0x0000000000855af4 in Table::insert (this=0x2aaaaad1b448, transaction=0x2aaab0f00f30, stream=<value optimized out>) at Table.cpp:2914
#11 0x00000000008486ce in StorageDatabase::insert (this=<value optimized out>, connection=<value optimized out>, table=0x2aaaaad1b448, stream=0x2aaabd2caef0)
    at StorageDatabase.cpp:226
#12 0x000000000084c8b3 in StorageTable::insert (this=0x2aaabd2c5968) at StorageTable.cpp:122
#13 0x00000000008458c4 in StorageInterface::write_row (this=0x2aaab0d00b90, buff=0x2aaab0d00e30 "А^'") at ha_falcon.cpp:1036
#14 0x000000000075104b in handler::ha_write_row (this=0x2aaab0d00b90, buf=0x2aaab0d00e30 "А^'") at handler.cc:4602
#15 0x00000000006e4efe in write_record (thd=0x2aaab2207fa0, table=0x2aaab13379d0, info=0x18748b48) at sql_insert.cc:1548
#16 0x00000000006e52c1 in select_insert::send_data (this=0x18748b10, values=@0x2aaab2209a90) at sql_insert.cc:3047
#17 0x00000000006bb88e in end_send (join=0x2aaab13ae380, join_tab=<value optimized out>, end_of_records=false) at sql_select.cc:14339
#18 0x00000000006dc198 in do_select (join=0x2aaab13ae380, fields=0x2aaab2209a90, table=0x0, procedure=0x0) at sql_select.cc:13015
#19 0x00000000006e16d1 in JOIN::exec (this=0x2aaab13ae380) at sql_select.cc:2713
#20 0x00000000006e23ce in mysql_select (thd=0x2aaab2207fa0, rref_pointer_array=0x2aaab2209b70, tables=0x187484c8, wild_num=0, fields=@0x2aaab2209a90,
    conds=0x18748990, og_num=0, order=0x0, group=0x0, having=0x0, proc_param=0x0, select_options=3490466304, result=0x18748b10, unit=0x2aaab2209548,
    select_lex=0x2aaab2209988) at sql_select.cc:2901
#21 0x00000000006e2904 in handle_select (thd=0x2aaab2207fa0, lex=0x2aaab22094a8, result=0x18748b10, setup_tables_done_option=1073741824) at sql_select.cc:282
#22 0x000000000066e60c in mysql_execute_command (thd=0x2aaab2207fa0) at sql_parse.cc:2712
#23 0x0000000000672f22 in mysql_parse (thd=0x2aaab2207fa0,
    inBuf=0x18747590 "INSERT INTO systest1.tb1_eng1 (i1, f1, f2, f3, f4)\nSELECT i1, f1, f2, f3, f4\nFROM systest1.t1_tmp WHERE pk = 5", length=110,
    found_semicolon=0x48831000) at sql_parse.cc:5410
#24 0x0000000000673d52 in dispatch_command (command=COM_QUERY, thd=0x2aaab2207fa0, packet=<value optimized out>, packet_length=110) at sql_parse.cc:921
#25 0x0000000000674b42 in do_command (thd=0x2aaab2207fa0) at sql_parse.cc:697
#26 0x00000000006663fc in handle_one_connection (arg=<value optimized out>) at sql_connect.cc:1146
#27 0x0000003ba88062f7 in start_thread () from /lib64/libpthread.so.0
#28 0x0000003ba80ce85d in clone () from /lib64/libc.so.6
[21 Feb 2008 16:38] Philip Stoev
The core file is available for experimentation at dl360-g5-a.mysql.com:/data1/6.0.4/systest_vardir-bug34632-2. 

(gdb) frame 7
#7  0x00000000008549d7 in Table::checkUniqueRecordVersion (this=0x2aaaaad1b448, recordNumber=<value optimized out>, index=0x2aaaaad1bac8,
    transaction=0x2aaab0f00f30, record=<value optimized out>, sync=0x4882f6a0) at Table.cpp:2441
2441                            ASSERT(dup->state == recDeleted);
(gdb) print dup->state
$1 = 7 '\a'

Meaning that dup->state is equal to recUnlocked = 7 (record is being unlocked).
[22 Feb 2008 20:14] Bugs System
A patch for this bug has been committed. After review, it may
be pushed to the relevant source trees for release in the next
version. You can access the patch from:

  http://lists.mysql.com/commits/42873

ChangeSet@1.2821, 2008-02-22 14:13:29-06:00, klewis@klewis-mysql. +1 -0
  Bug#34632 - a lock record can now have state == recUnlocked. In this case, 
  Table::checkUniqueRecordVersion should check the prior record.
[28 Feb 2008 15:29] Bugs System
A patch for this bug has been committed. After review, it may
be pushed to the relevant source trees for release in the next
version. You can access the patch from:

  http://lists.mysql.com/commits/43157

ChangeSet@1.2578, 2008-02-28 09:27:49-06:00, klewis@klewis-mysql. +1 -0
  Bug#34632 - a lock record can now have state == recUnlocked. In this case, 
  Table::checkUniqueRecordVersion should check the prior record.
[12 Mar 2008 23:03] Bugs System
Pushed into 6.0.4-alpha
[13 Mar 2008 15:59] Hakan Küçükyılmaz
Fix is in 6.0.5-alpha.
[8 Jan 2009 9:48] MC Brown
Internal change only. No documentation needed.