Bug #42592 Falcon assertion (insert(NULL, record, record->recordNumber)) when backlogging
Submitted: 4 Feb 2009 13:23 Modified: 15 May 2009 16:13
Reporter: Hakan Küçükyılmaz Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Server: Falcon storage engine Severity:S1 (Critical)
Version:mysql-6.0-falcon-team OS:Linux
Assigned to: Christopher Powers CPU Architecture:Any
Tags: F_BACKLOG
Triage: Triaged: D1 (Critical)

[4 Feb 2009 13:23] Hakan Küçükyılmaz
Description:
Running iuds6.tst leads to assert in Falcon.

How to repeat:
Run iuds6.tst and look for this assertion:

[Falcon] Error: assertion (insert(NULL, record, record->recordNumber)) failed at line 3801 in file Table.cpp

090204 14:00:28 - mysqld got signal 6 ;
This could be because you hit a bug. It is also possible that this binary
or one of the libraries it was linked against is corrupt, improperly built,
or misconfigured. This error can also be caused by malfunctioning hardware.
We will try our best to scrape up some info that will hopefully help diagnose
the problem, but since we have already crashed, something is definitely wrong
and this may fail.

key_buffer_size=1048576
read_buffer_size=131072
max_used_connections=52
max_threads=151
thread_count=52
connection_count=51
It is possible that mysqld could use up to
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 60622 K
bytes of memory
Hope that's ok; if not, decrease some variables in the equation.

thd: 0x45f1850
Attempting backtrace. You can use the following information to find out
where mysqld died. If you see no messages after this, something went
terribly wrong...
stack_bottom = 0x4b5730e0 thread_stack 0x40000
/data0/fsqa/cb/mysql-6.0.10-alpha/sql/mysqld(my_print_stacktrace+0x29) [0xaf47a9]
/data0/fsqa/cb/mysql-6.0.10-alpha/sql/mysqld(handle_segfault+0x378) [0x67e788]
/lib/libpthread.so.0 [0x7fb9ffb0e0f0]
/lib/libpthread.so.0(raise+0x2b) [0x7fb9ffb0dfab]
/data0/fsqa/cb/mysql-6.0.10-alpha/sql/mysqld(Error::error(char const*, ...)+0x104) [0x8de644]
/data0/fsqa/cb/mysql-6.0.10-alpha/sql/mysqld(Table::backlogRecord(RecordVersion*)+0x214) [0x899f14]
/data0/fsqa/cb/mysql-6.0.10-alpha/sql/mysqld(SavePoint::backlogRecord(RecordVersion*)+0x30) [0x919070]
/data0/fsqa/cb/mysql-6.0.10-alpha/sql/mysqld(Transaction::backlogRecords()+0x134) [0x8a80a4]
/data0/fsqa/cb/mysql-6.0.10-alpha/sql/mysqld(Transaction::addRecord(RecordVersion*)+0x210) [0x8a85b0]
/data0/fsqa/cb/mysql-6.0.10-alpha/sql/mysqld(Table::fetchForUpdate(Transaction*, Record*, bool)+0x300) [0x89cbf
0]
/data0/fsqa/cb/mysql-6.0.10-alpha/sql/mysqld(StorageDatabase::nextRow(StorageTable*, int, bool)+0x60) [0x888560
]
/data0/fsqa/cb/mysql-6.0.10-alpha/sql/mysqld(StorageInterface::rnd_next(unsigned char*)+0x79) [0x882e09]
/data0/fsqa/cb/mysql-6.0.10-alpha/sql/mysqld(ha_partition::rnd_next(unsigned char*)+0x47) [0x78e437]
/data0/fsqa/cb/mysql-6.0.10-alpha/sql/mysqld(rr_sequential(READ_RECORD*)+0x21) [0x77dda1]
/data0/fsqa/cb/mysql-6.0.10-alpha/sql/mysqld(mysql_delete(THD*, TABLE_LIST*, Item*, st_sql_list*, unsigned long
 long, unsigned long long, bool)+0x869) [0x7241f9]
/data0/fsqa/cb/mysql-6.0.10-alpha/sql/mysqld(mysql_execute_command(THD*)+0x18fe) [0x6909ce]
/data0/fsqa/cb/mysql-6.0.10-alpha/sql/mysqld(mysql_parse(THD*, char const*, unsigned int, char const**)+0x36e)
[0x69452e]
/data0/fsqa/cb/mysql-6.0.10-alpha/sql/mysqld(dispatch_command(enum_server_command, THD*, char*, unsigned int)+0
xad1) [0x695451]
/data0/fsqa/cb/mysql-6.0.10-alpha/sql/mysqld(handle_one_connection+0x1a9) [0x688069]
/lib/libpthread.so.0 [0x7fb9ffb063ea]
/lib/libc.so.6(clone+0x6d) [0x7fb9fea78c6d]
Trying to get some variables.
Some pointers may be invalid and cause the dump to abort...
thd->query at 0x285c158 = delete from tb0_eng1 where f1=@tmp_num
thd->thread_id=595
thd->killed=NOT_KILLED
The manual page at http://dev.mysql.com/doc/mysql/en/crashing.html contains
information that should help you find out what is causing the crash.
Writing a core file
[4 Feb 2009 13:36] Philip Stoev
This failure started happening on the falcon_backlog test after this push:

revno: 2997
revision-id: christopher.powers@sun.com-20090203025827-d5dz9om99lmnqyeh
parent: christopher.powers@sun.com-20090203025445-0sfk408p8nq8fx4m
parent: vvaintroub@mysql.com-20090202130038-11e85n0j2qr52xkv
committer: Christopher Powers <christopher.powers@sun.com>
branch nick: mysql
timestamp: Mon 2009-02-02 20:58:27 -0600
message:
  merge
------------------------------------------------------------
revno: 2996
revision-id: christopher.powers@sun.com-20090203025445-0sfk408p8nq8fx4m
parent: christopher.powers@sun.com-20090203025342-y56cz1w2jonxwyy9
parent: vvaintroub@mysql.com-20090201205427-yzedgslc2jqiu626
committer: Christopher Powers <christopher.powers@sun.com>
branch nick: mysql
timestamp: Mon 2009-02-02 20:54:45 -0600
message:
  merge
------------------------------------------------------------
revno: 2995
revision-id: christopher.powers@sun.com-20090203025342-y56cz1w2jonxwyy9
parent: christopher.powers@sun.com-20090201165421-3dd842hdefg2aerh
committer: Christopher Powers <christopher.powers@sun.com>
branch nick: mysql
timestamp: Mon 2009-02-02 20:53:42 -0600
message:
  Bug #42505 "Falcon: Record backlogging not enabled by the Scavenger"
  
  Limit updateCardinalities() to once every 20 scavenge cycles. This
  function is too expensive to call every scavenge cycle. 
  
  Made Changes per Kevin's comments in the bug report, with one
  exception: Database::scavengeRecords() still determines low
  memory with retiredActiveMemory > recordScavengeFloor. Using 
  spaceRemaining > recordScavengeFloor does not enable backlogging
  when needed (confirmed against falcon_bug_36294-big.test). 
------------------------------------------------------------
revno: 2994
revision-id: christopher.powers@sun.com-20090201165421-3dd842hdefg2aerh
parent: christopher.powers@sun.com-20090201095043-sg05gj7sjf1xdrs1
committer: Christopher Powers <christopher.powers@sun.com>
branch nick: mysql
timestamp: Sun 2009-02-01 10:54:21 -0600
message:
  Bug #42510, "Falcon: Default memory parameters must be changed"
  
  Updated Falcon options tests.
------------------------------------------------------------
revno: 2993
revision-id: christopher.powers@sun.com-20090201095043-sg05gj7sjf1xdrs1
parent: christopher.powers@sun.com-20090201090052-v2eypv06210t9j6r
committer: Christopher Powers <christopher.powers@sun.com>
branch nick: mysql
timestamp: Sun 2009-02-01 03:50:43 -0600
message:
  Bug #42510, "Falcon: Default memory parameters must be changed"
  Bug #36442, "Falcon: crash during optimize table"
  
  Increased default page cache size from 4MB to 250MB
  Increased record scavenge threshold from 67 to 90
  Increased record scavenge floor from 50 to 80
------------------------------------------------------------
revno: 2992
revision-id: christopher.powers@sun.com-20090201090052-v2eypv06210t9j6r
parent: christopher.powers@sun.com-20090201081851-4n0mat7z22cgmckl
committer: Christopher Powers <christopher.powers@sun.com>
branch nick: mysql
timestamp: Sun 2009-02-01 03:00:52 -0600
message:
  Bug #42424, "Serious performance degradation after new scavenger"
  
  Increased scavenger wait increment from 10 to 20ms.
  Use progressive scavenger wait timeout for record allocation methods.
------------------------------------------------------------
revno: 2991
revision-id: christopher.powers@sun.com-20090201081851-4n0mat7z22cgmckl
parent: christopher.powers@sun.com-20090131232242-vcqjhiswh5zwl3ku
committer: Christopher Powers <christopher.powers@sun.com>
branch nick: mysql
timestamp: Sun 2009-02-01 02:18:51 -0600
message:
  Bug #42424, "Serious performance degradation after new scavenger"
  
  Several fixes for the Scavenger:
  
  1. Don't run updateCardinalities() in a low memory state
  2. Distinguish between scheduled and load-based or 'forced' scavenges
  3. Progessively increase the time that record alloc waits for a scavenge
  4. Retire records during a low memory state, even if active memory is
     below the cache threshold
------------------------------------------------------------
revno: 2990
revision-id: christopher.powers@sun.com-20090131232242-vcqjhiswh5zwl3ku
parent: vvaintroub@mysql.com-20090130113552-hvh65u3glt0tsg5s
committer: Christopher Powers <christopher.powers@sun.com>
branch nick: mysql
timestamp: Sat 2009-01-31 17:22:42 -0600
message:
  Bug #42505, "Falcon: Record backlogging not enabled by the Scavenger"
  
  Fixed several issues with record backlogging.
[4 Feb 2009 14:56] Kevin Lewis
Table::Insert() failed to put NULL into the RecordLeaf.  There must have been another insert to that slot during Table::backlogRecord.  We can do one of three things;
1) Do not allow updates, deletes, or locks to a record that is being backlogged.  
2) Retry the backlog again with the new base record, 
3) Fail to backlog that record.
[4 Feb 2009 16:07] Ann Harrison
Backlogging is optional - responding to user requests is not.  If 
we were to block the operation until we got the record backlogged,
we'd just have to revive the record.  The right answer, I think,
is not to backlog a record if any other operation happens on the
record.
[18 Feb 2009 12:28] Philip Stoev
This assertion was just hit using a non-concurrent mysqltest that does multiple-table DELETE. Backtrace:

#7  0x00000000009e471b in Error::assertionFailed (text=0xe34948 "insertIntoTree(NULL, record, record->recordNumber)", fileName=0xe33f21 "Table.cpp",
    line=3816) at Error.cpp:78
#8  0x0000000000990497 in Table::backlogRecord (this=0x7f615aaee030, record=0x2a490e30) at Table.cpp:3816
#9  0x00000000009a20d7 in Transaction::backlogRecords (this=0x7f615aac4d48) at Transaction.cpp:1512
#10 0x00000000009a24fc in Transaction::addRecord (this=0x7f615aac4d48, record=0x2a491010) at Transaction.cpp:628
#11 0x0000000000990ebb in Table::fetchForUpdate (this=0x7f615aaee030, transaction=0x7f615aac4d48, source=0x2a3f5100, usingIndex=false) at Table.cpp:3545
#12 0x0000000000978445 in StorageDatabase::nextRow (this=0x7f615a701208, storageTable=0x7f615aae8610, recordNumber=1, lockForUpdate=true)
    at StorageDatabase.cpp:288
#13 0x000000000097f72d in StorageTable::next (this=0x7f615aae8610, recordNumber=1, lockForUpdate=true) at StorageTable.cpp:158
#14 0x000000000096fb37 in StorageInterface::rnd_next (this=0x3cc7a60, buf=0x3cc7d38 "Ъ\f") at ha_falcon.cpp:636
#15 0x000000000080c48b in rr_sequential (info=0x3e213a8) at records.cc:390
#16 0x000000000074c317 in sub_select (join=0x3ec9a50, join_tab=0x3e21320, end_of_records=false) at sql_select.cc:16247
#17 0x000000000074bfb5 in evaluate_join_record (join=0x3ec9a50, join_tab=0x3e21080, error=0) at sql_select.cc:16492
#18 0x000000000074c3d0 in sub_select (join=0x3ec9a50, join_tab=0x3e21080, end_of_records=false) at sql_select.cc:16259
#19 0x0000000000759bb1 in do_select (join=0x3ec9a50, fields=0x7f6154e6b210, table=0x0, procedure=0x0) at sql_select.cc:15788
#20 0x0000000000773bbc in JOIN::exec (this=0x3ec9a50) at sql_select.cc:2881
#21 0x000000000076e732 in mysql_select (thd=0x7f6154e69368, rref_pointer_array=0x7f6154e6b2f0, tables=0x3cc24c8, wild_num=0, fields=@0x7f6154e6b210,
    conds=0x3cc32b0, og_num=0, order=0x0, group=0x0, having=0x0, proc_param=0x0, select_options=3489942144, result=0x3cc34b0, unit=0x7f6154e6aca0,
    select_lex=0x7f6154e6b108) at sql_select.cc:3062
#22 0x00000000006d5dc7 in mysql_execute_command (thd=0x7f6154e69368) at sql_parse.cc:3300
#23 0x00000000006daa99 in mysql_parse (thd=0x7f6154e69368,
    inBuf=0x3cc1520 "DELETE space1, space2 FROM space1, space2 WHERE space1.t1_autoinc = space2.t1_autoinc", length=85, found_semicolon=0x7f6138f0bf00)
    at sql_parse.cc:5752
#24 0x00000000006db684 in dispatch_command (command=COM_QUERY, thd=0x7f6154e69368,
    packet=0x7f6154ff57b9 "DELETE space1, space2 FROM space1, space2 WHERE space1.t1_autoinc = space2.t1_autoinc", packet_length=85) at sql_parse.cc:1009
#25 0x00000000006dcbad in do_command (thd=0x7f6154e69368) at sql_parse.cc:691
#26 0x00000000006cab2d in handle_one_connection (arg=0x7f6154e69368) at sql_connect.cc:1146
#27 0x000000315b0073da in start_thread () from /lib64/libpthread.so.0
#28 0x000000315a4e627d in clone () from /lib64/libc.so.6
[2 Mar 2009 23:38] 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/68049

3043 Christopher Powers	2009-03-02
      Bug #42592 "Falcon assertion (insert(NULL, record, record->recordNumber)) when backlogging"
      
      There are two contributing factors to this failure:
      
      1) Handle a failed backlog more gracefully
      
      If Table::insertIntoTree(NULL) fails during a backlog,
      just removed the backlogged record instead of assert.
      
      insertIntoTree() should never fail for pending records
      in a transaction except possibly system transactions,
      which can span multiple threads.
       
      2) Don't chill or backlog system transactions
[2 Mar 2009 23:44] 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/68050

3044 Christopher Powers	2009-03-02
      Bug #42592 "Falcon assertion (insert(NULL, record, record->recordNumber)) when backlogging"
      
      Removed control character from copyright
[3 Mar 2009 6:54] 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/68086

3045 Christopher Powers	2009-03-03
      Bug #42592 "Falcon assertion (insert(NULL, record, record->recordNumber)) when backlogging"
      
      Changes per code review
[4 Mar 2009 4:27] 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/68163

3047 Christopher Powers	2009-03-03
      Bug #42592, "Falcon assertion (insert(NULL, record, record->recordNumber)) when backlogging"
      
      Removed warning in Table.cpp, line 1038
[2 Apr 2009 17:39] Bugs System
Pushed into 6.0.11-alpha (revid:hky@sun.com-20090402144811-yc5kp8g0rjnhz7vy) (version source revid:christopher.powers@sun.com-20090304040124-1z6euouk3r5h8am2) (merge vers: 6.0.11-alpha) (pib:6)
[15 May 2009 16:13] MC Brown
Internal/test fix. No changelog entry required.