Bug #52745 Failing assertion: blob_no < page_zip->n_blobs
Submitted: 11 Apr 2010 17:06 Modified: 14 Oct 2010 14:44
Reporter: Shane Bester (Platinum Quality Contributor) Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Server: InnoDB Plugin storage engine Severity:S1 (Critical)
Version:5.1.45 + 1.0.6 plugin, 5.1.47 + 1.0.7 plugin, 5.5.4-m3-debug OS:Any
Assigned to: Marko Mäkelä CPU Architecture:Any
Triage: Triaged: D1 (Critical)

[11 Apr 2010 17:06] Shane Bester
Description:
Version: '5.1.45-enterprise-gpl-advanced-debug'  socket: ''  port: 3306  MySQL Enterprise Server - Advanced Edition Debug (GPL)
100411 19:06:07  InnoDB: Assertion failure in thread 2736 in file .\page\page0zip.c line 3661
InnoDB: Failing assertion: blob_no < page_zip->n_blobs
InnoDB: We intentionally generate a memory trap.

ha_innodb_plugin.dll!page_zip_write_blob_ptr()[page0zip.c:3661]
ha_innodb_plugin.dll!btr_store_big_rec_extern_fields()[btr0cur.c:4064]
ha_innodb_plugin.dll!row_ins_index_entry_low()[row0ins.c:2114]
ha_innodb_plugin.dll!row_ins_index_entry()[row0ins.c:2161]
ha_innodb_plugin.dll!row_ins_index_entry_step()[row0ins.c:2245]
ha_innodb_plugin.dll!row_ins()[row0ins.c:2377]
ha_innodb_plugin.dll!row_ins_step()[row0ins.c:2487]
ha_innodb_plugin.dll!row_insert_for_mysql()[row0mysql.c:1139]
ha_innodb_plugin.dll!ha_innodb::write_row()[ha_innodb.cc:4408]
mysqld-debug.exe!handler::ha_write_row()[handler.cc:4650]
mysqld-debug.exe!write_record()[sql_insert.cc:1606]
mysqld-debug.exe!mysql_insert()[sql_insert.cc:835]
mysqld-debug.exe!mysql_execute_command()[sql_parse.cc:3183]
mysqld-debug.exe!mysql_parse()[sql_parse.cc:5975]
mysqld-debug.exe!dispatch_command()[sql_parse.cc:1235]
mysqld-debug.exe!do_command()[sql_parse.cc:874]
mysqld-debug.exe!handle_one_connection()[sql_connect.cc:1127]
mysqld-debug.exe!pthread_start()[my_winthread.c:85]
mysqld-debug.exe!_callthreadstart()[thread.c:295]
mysqld-debug.exe!_threadstart()[thread.c:277]
kernel32.dll!BaseThreadStart()

How to repeat:
import attached sql file.
[11 Apr 2010 18:06] Valeriy Kravchuk
Verified just as described, also with 5.5.4-m3 (mysql-trunk):

77-52-4-109:trunk openxs$ tail -100 var/77-52-206-97.dialup.umc.net.ua.err
100411 21:02:21 mysqld_safe Starting mysqld daemon with databases from /Users/openxs/dbs/trunk/var
100411 21:02:21 [Warning] Setting lower_case_table_names=2 because file system for /Users/openxs/dbs/trunk/var/ is case insensitive
100411 21:02:21 [Warning] One can only use the --user switch if running as root

100411 21:02:21 [Note] Buffered information: Performance schema disabled (reason: start parameters).

100411 21:02:21 [Note] Plugin 'FEDERATED' is disabled.
100411 21:02:21 [Note] Plugin 'ndbcluster' is disabled.
InnoDB: The InnoDB memory heap is disabled
InnoDB: Mutexes and rw_locks use GCC atomic builtins
100411 21:02:22  InnoDB: highest supported file format is Barracuda.
InnoDB: The log sequence number in ibdata files does not match
InnoDB: the log sequence number in the ib_logfiles!
100411 21:02:22  InnoDB: Database was not shut down normally!
InnoDB: Starting crash recovery.
InnoDB: Reading tablespace information from the .ibd files...
InnoDB: Restoring possible half-written data pages from the doublewrite
InnoDB: buffer...
100411 21:02:22 InnoDB Plugin 1.0.6 started; log sequence number 47122
100411 21:02:22 [Note] Event Scheduler: Loaded 0 events
100411 21:02:22 [Note] /Users/openxs/dbs/trunk/libexec/mysqld: ready for connections.
Version: '5.5.4-m3-debug'  socket: '/tmp/mysql.sock'  port: 3306  Source distribution
100411 21:02:55  InnoDB: Assertion failure in thread 2960117760 in file page/page0zip.c line 3661
InnoDB: Failing assertion: blob_no < page_zip->n_blobs
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.1/en/forcing-recovery.html
InnoDB: about forcing recovery.
100411 21:02:55 - mysqld got signal 6 ;
...
[11 Apr 2010 18:45] Valeriy Kravchuk
InnoDB Plugin 1.0.7 (coming with recent 5.1.47 from bzr) is also affected:

7-52-4-109:5.1 openxs$ tail -120 var/77-52-206-97.dialup.umc.net.ua.err
100411 21:42:26 mysqld_safe Starting mysqld daemon with databases from /Users/openxs/dbs/5.1/var
100411 21:42:26 [Warning] Setting lower_case_table_names=2 because file system for /Users/openxs/dbs/5.1/var/ is case insensitive
100411 21:42:26 [Warning] One can only use the --user switch if running as root

100411 21:42:26 [Note] Plugin 'FEDERATED' is disabled.
100411 21:42:26 [Note] Plugin 'ndbcluster' is disabled.
InnoDB: The InnoDB memory heap is disabled
InnoDB: Mutexes and rw_locks use GCC atomic builtins
InnoDB: Compressed tables use zlib 1.2.3
100411 21:42:27  InnoDB: highest supported file format is Barracuda.
100411 21:42:27 InnoDB Plugin 1.0.7 started; log sequence number 231385001
100411 21:42:27 [Note] Event Scheduler: Loaded 0 events
100411 21:42:27 [Note] /Users/openxs/dbs/5.1/libexec/mysqld: ready for connections.
Version: '5.1.47-debug'  socket: '/tmp/mysql.sock'  port: 3306  Source distribution
100411 21:42:45  InnoDB: Assertion failure in thread 2960650240 in file page/page0zip.c line 3661
InnoDB: Failing assertion: blob_no < page_zip->n_blobs
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.1/en/forcing-recovery.html
InnoDB: about forcing recovery.
100411 21:42:45 - mysqld got signal 6 ;
...
[12 Apr 2010 19:06] Omer Barnir
triage: setting to 1121 SR51MRU, SR55RC and attachment 
"[11 Apr 19:09] Shane Bester" as private as has a DoS vector
[20 Apr 2010 12:06] Marko Mäkelä
With UNIV_DEBUG enabled, I see it fail a little earlier:

#0  ut_dbg_assertion_failed (expr=0xb6d8b8f8 "rec_offs_nth_extern(offsets, big_rec_vec->fields[i].field_no)", file=0xb6d8acbd "btr/btr0cur.c", line=3872) at ut/ut0dbg.c:60
#1  0xb6c910f6 in btr_store_big_rec_extern_fields (index=0x88799b0, rec_block=0xb67360bc, rec=0xb6a1c090 "", offsets=0x8874c00, big_rec_vec=0x88876b8, local_mtr=0xafbe0acc) at btr/btr0cur.c:3871
#2  0xb6d4820a in row_ins_index_entry_low (mode=2, index=0x88799b0, entry=0x8878840, n_ext=0, thr=0x88867a8) at row/row0ins.c:2114
#3  0xb6d482ed in row_ins_index_entry (index=0x88799b0, entry=0x8878840, n_ext=0, foreign=1, thr=0x88867a8) at row/row0ins.c:2162
#4  0xb6d48614 in row_ins_index_entry_step (node=0x8885848, thr=0x88867a8) at row/row0ins.c:2247
#5  0xb6d48877 in row_ins (node=0x8885848, thr=0x88867a8) at row/row0ins.c:2379
#6  0xb6d48ae2 in row_ins_step (thr=0x88867a8) at row/row0ins.c:2489
#7  0xb6d4f6fa in row_insert_for_mysql (mysql_rec=0x8881f08 "\377_", prebuilt=0x885c130) at row/row0mysql.c:1137
#8  0xb6ce4e31 in ha_innodb::write_row (this=0x8852ad8, record=0x8881f08 "\377_") at handler/ha_innodb.cc:4717

Now the question is, why is the column not stored externally? The failure occurs on the very first call to ha_innodb::write_row(), so this should be easy to track down.
[21 Apr 2010 7:00] Marko Mäkelä
Field 54 (col87) is stored externally, but rec_init_offsets_comp_ordinary() will ignore the "external storage" flag, because col->len <= 255 and col->mtype != DATA_BLOB. We have len=221, mtype=DATA_BINARY.

I will have to think about this. The fix must not break ROW_FORMAT=COMPACT, where columns shorter than 788 bytes are never stored externally. We must distinguish ROW_FORMAT=DYNAMIC and ROW_FORMAT=COMPRESSED by looking at index->table->flags.
[21 Apr 2010 7:37] Marko Mäkelä
It is simplest to refuse external storage when the maximum length of the column does not exceed 256 bytes.
[21 Apr 2010 8: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/106197
[21 Apr 2010 8: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/106198
[21 Apr 2010 9:51] 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/106217
[21 Apr 2010 9:51] 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/106218
[21 Apr 2010 9:52] Marko Mäkelä
Pushed to mysql-5.1-innodb r3410
[26 Apr 2010 11:09] 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/106504
[26 Apr 2010 11:09] 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/106505
[5 May 2010 15:18] Bugs System
Pushed into 5.1.47 (revid:joro@sun.com-20100505145753-ivlt4hclbrjy8eye) (version source revid:kristofer.pettersson@sun.com-20100503172109-f9hracq5pqsaomb1) (merge vers: 5.1.47) (pib:16)
[10 May 2010 11:26] Marko Mäkelä
For the documentation:

Bug: InnoDB attempted to choose off-page storage without ensuring that there is a "off-page storage" flag in the record header.

Fix: In DYNAMIC and COMPRESSED format, store locally any non-BLOB columns whose maximum length does not exceed 256 bytes.  This is because there is no room for the "external storage" flag when the maximum length is 255 bytes or less. This restriction trivially holds in REDUNDANT and COMPACT format, because there we always store locally columns whose length is up to local_len == 788 bytes.
[12 May 2010 19:15] Paul Dubois
Noted in 5.1.47 changelog.
[28 May 2010 5:57] Bugs System
Pushed into mysql-next-mr (revid:alik@sun.com-20100524190136-egaq7e8zgkwb9aqi) (version source revid:alik@sun.com-20100512070920-xgpmqeytp0gc183c) (pib:16)
[28 May 2010 6:25] Bugs System
Pushed into 6.0.14-alpha (revid:alik@sun.com-20100524190941-nuudpx60if25wsvx) (version source revid:alik@sun.com-20100507093037-7cykrx1n73v0tetc) (merge vers: 6.0.14-alpha) (pib:16)
[28 May 2010 6:53] Bugs System
Pushed into 5.5.5-m3 (revid:alik@sun.com-20100524185725-c8k5q7v60i5nix3t) (version source revid:alexey.kopytov@sun.com-20100507164602-8w09samq3mpvbxbn) (merge vers: 5.5.5-m3) (pib:16)
[30 May 2010 0:04] Paul Dubois
Noted in 5.5.5, 6.0.14 changelogs.
[17 Jun 2010 11:59] Bugs System
Pushed into 5.1.47-ndb-7.0.16 (revid:martin.skold@mysql.com-20100617114014-bva0dy24yyd67697) (version source revid:martin.skold@mysql.com-20100616204905-jxjg342w35ks9vfy) (merge vers: 5.1.47-ndb-7.0.16) (pib:16)
[17 Jun 2010 12:39] Bugs System
Pushed into 5.1.47-ndb-6.2.19 (revid:martin.skold@mysql.com-20100617115448-idrbic6gbki37h1c) (version source revid:martin.skold@mysql.com-20100615090726-jotpykke96le59w5) (merge vers: 5.1.47-ndb-6.2.19) (pib:16)
[17 Jun 2010 13:25] Bugs System
Pushed into 5.1.47-ndb-6.3.35 (revid:martin.skold@mysql.com-20100617114611-61aqbb52j752y116) (version source revid:martin.skold@mysql.com-20100616120453-jh7wr05z1vf7r8pm) (merge vers: 5.1.47-ndb-6.3.35) (pib:16)
[6 Jul 2010 19:02] Paul Dubois
Noted in 5.1.46sp1 changelog.
[8 Jul 2010 18:54] Bugs System
Pushed into 5.1.49 (revid:sunanda.menon@sun.com-20100708184626-16el4v8gjjci6m1r) (version source revid:sunanda.menon@sun.com-20100708184626-16el4v8gjjci6m1r) (merge vers: 5.1.49) (pib:16)
[4 Aug 2010 7:53] Bugs System
Pushed into mysql-trunk 5.5.6-m3 (revid:alik@sun.com-20100731131027-1n61gseejyxsqk5d) (version source revid:alik@sun.com-20100731074942-o840woifuqioxxe4) (merge vers: 5.5.6-m3) (pib:18)
[4 Aug 2010 8:08] Bugs System
Pushed into mysql-trunk 5.6.1-m4 (revid:alik@ibmvm-20100804080001-bny5271e65xo34ig) (version source revid:alik@sun.com-20100731075120-qz9z8c25zum2wgmm) (merge vers: 5.6.99-m4) (pib:18)
[4 Aug 2010 8:24] Bugs System
Pushed into mysql-trunk 5.6.1-m4 (revid:alik@ibmvm-20100804081533-c1d3rbipo9e8rt1s) (version source revid:alik@sun.com-20100731075120-qz9z8c25zum2wgmm) (merge vers: 5.6.99-m4) (pib:18)
[4 Aug 2010 9:03] Bugs System
Pushed into mysql-next-mr (revid:alik@ibmvm-20100804081630-ntapn8bf9pko9vj3) (version source revid:alik@sun.com-20100731075120-qz9z8c25zum2wgmm) (pib:20)
[4 Aug 2010 23:00] Paul Dubois
Already fixed in 5.1.x, 5.5.x.
Bug does not appear in any released 5.6.x version.
[5 Sep 2010 10:28] Michael Widenius
After adding the test for this bug, there is a failure detected by valgrind when running

mysql-test-run --valgrind innodb_plugin.innodb_bug52745

==25815== Thread 17:                                                            
==25815== Invalid read of size 1                                                
==25815==    at 0x6D00113: mach_read_from_4 (mach0data.ic:182)                  
==25815==    by 0x6C9BEFD: buf_buddy_relocate (buf0buddy.c:445)                 
==25815==    by 0x6C9C9DE: buf_buddy_free_low (buf0buddy.c:639)                 
==25815==    by 0x6C9AAB6: buf_buddy_free (buf0buddy.ic:121)                    
==25815==    by 0x6CA9C93: buf_LRU_block_remove_hashed_page (buf0lru.c:1828)    
==25815==    by 0x6CA6D57: buf_LRU_invalidate_tablespace (buf0lru.c:456)        
==25815==    by 0x6CC57CF: fil_delete_tablespace (fil0fil.c:2264)               
==25815==    by 0x6D42413: row_drop_table_for_mysql (row0mysql.c:3283)          
==25815==    by 0x6CDF6A7: ha_innodb::delete_table(char const*) (ha_innodb.cc:6973)                                                             
==25815==    by 0x828B21: handler::ha_delete_table(char const*) (handler.cc:3373)                                                               
==25815==    by 0x826070: ha_delete_table(THD*, handlerton*, char const*, char const*, char const*, bool) (handler.cc:1996)                                     
==25815==    by 0x849780: mysql_rm_table_part2(THD*, TABLE_LIST*, bool, bool, bool, bool) (sql_table.cc:2071)                                                   
==25815==    by 0x848DE6: mysql_rm_table(THD*, TABLE_LIST*, char, char) (sql_table.cc:1850)                                                             
==25815==    by 0x6DEC09: mysql_execute_command(THD*) (sql_parse.cc:3431)       
==25815==    by 0x6E68BB: mysql_parse(THD*, char*, unsigned int, char const**) (sql_parse.cc:6032)                                                             
==25815==    by 0x6D8E77: dispatch_command(enum_server_command, THD*, char*, unsigned int) (sql_parse.cc:1260)                                                  
==25815==  Address 0x7d79422 is 5,154 bytes inside a  of size 16,384 client-defined                                                                         
==25815==    at 0x6C9E641: buf_block_init (buf0buf.c:650)                       
==25815==    by 0x6C9E843: buf_chunk_init (buf0buf.c:752)                       
==25815==    by 0x6C9EDA1: buf_pool_init (buf0buf.c:967)                        
==25815==    by 0x6D5BCB3: innobase_start_or_create_for_mysql (srv0start.c:1292)
==25815==    by 0x6CD759C: innobase_init(void*) (ha_innodb.cc:2250)             
==25815==    by 0x8231F4: ha_initialize_handlerton(st_plugin_int*) (handler.cc:435)                                                                
==25815==    by 0x8F9730: plugin_initialize(st_plugin_int*) (sql_plugin.cc:1019)
==25815==    by 0x8F9FA5: plugin_init(int*, char**, int) (sql_plugin.cc:1246)   
==25815==    by 0x6CA95D: init_server_components() (mysqld.cc:3998)             
==25815==    by 0x6CB434: main (mysqld.cc:4469)
[14 Oct 2010 8:35] Bugs System
Pushed into mysql-5.1-telco-7.0 5.1.51-ndb-7.0.20 (revid:martin.skold@mysql.com-20101014082627-jrmy9xbfbtrebw3c) (version source revid:martin.skold@mysql.com-20101014082627-jrmy9xbfbtrebw3c) (merge vers: 5.1.51-ndb-7.0.20) (pib:21)
[14 Oct 2010 8:50] Bugs System
Pushed into mysql-5.1-telco-6.3 5.1.51-ndb-6.3.39 (revid:martin.skold@mysql.com-20101014083757-5qo48b86d69zjvzj) (version source revid:martin.skold@mysql.com-20101014083757-5qo48b86d69zjvzj) (merge vers: 5.1.51-ndb-6.3.39) (pib:21)
[14 Oct 2010 9:06] Bugs System
Pushed into mysql-5.1-telco-6.2 5.1.51-ndb-6.2.19 (revid:martin.skold@mysql.com-20101014084420-y54ecj85j5we27oa) (version source revid:martin.skold@mysql.com-20101014084420-y54ecj85j5we27oa) (merge vers: 5.1.51-ndb-6.2.19) (pib:21)
[14 Oct 2010 14:44] Jon Stephens
Already documented as noted above; no new changelog entries required. Setting back to Closed state.