Bug #29250 Assertion `row_len <= record_buffer->length' failed.
Submitted: 20 Jun 2007 21:16 Modified: 10 Aug 2007 18:16
Reporter: Shane Bester (Platinum Quality Contributor) Email Updates:
Status: Can't repeat Impact on me:
None 
Category:MySQL Server: Archive storage engine Severity:S1 (Critical)
Version:5.1.20, 5.0.44 OS:Any
Assigned to: Brian Aker CPU Architecture:Any
Tags: crash, hang

[20 Jun 2007 21:16] Shane Bester
Description:
crash when concurrently doing inserts, check table, optimize table on archive table. See error logs:

Version: '5.1.20-beta-debug'  socket: '/tmp/mysql.sock'  port: 3306  yes
mysqld: ha_archive.cc:1090: int ha_archive::unpack_row(azio_stream*, uchar*): Assertion `row_len <= record_buffer->length' failed.
070620 22:54:33 - 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=8388600
read_buffer_size=131072
max_used_connections=1
max_threads=151
threads_connected=1
It is possible that mysqld could use up to 
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 337607 K
bytes of memory
Hope that's ok; if not, decrease some variables in the equation.

thd: 0x8de5430
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...
Cannot determine thread, fp=0x42857fc4, backtrace may not be correct.
Stack range sanity check OK, backtrace follows:
0x81fbec5 handle_segfault + 805
0xffffe410 _end + -142334016
0x400edb75 _end + 932388645
0x400e5903 _end + 932355251
0x83e848d _ZN10ha_archive10unpack_rowEP11azio_streamPh + 621
0x83e8692 _ZN10ha_archive7get_rowEP11azio_streamPh + 322
0x83eab1f _ZN10ha_archive8optimizeEP3THDP15st_ha_check_opt + 863
Stack trace seems successful - bottom reached
Please read http://dev.mysql.com/doc/refman/5.1/en/resolve-stack-dump.html
and follow instructions on how to resolve the stack trace.
Resolved stack trace is much more helpful in diagnosing the
problem, so please do resolve it
Trying to get some variables.
Some pointers may be invalid and cause the dump to abort...
thd->query at 0x8e16078 = insert into t1 values (?,?)
thd->thread_id=1

How to repeat:
will make a testcase later.

Suggested fix:
.
[20 Jun 2007 21:28] Shane Bester
see top of file for user, host, password, gcc compile example.

Attachment: bug29250.c (text/plain), 6.06 KiB.

[20 Jun 2007 21:29] Shane Bester
verified by running the attached C testcase.
5.1.20 on linux crashes nearly immediately.
5.0.44 on windows hang indefinately.
related to bug #29249 - please check if they are indeed the same cause.
[27 Jun 2007 7:43] Sergey Vojtovich
BUG#29249 was marked as duplicate.
[10 Aug 2007 18:16] Brian Aker
I was able to repeat this on 5.1 but was not able to repeat this in 5.0. 5.1's patch was pushed a while ago, but for 5.0... like I said, I can't get a repeat with the test case (this was testing with the latest 5.0-arch tree).
[30 Jan 2009 22:55] Piotr Czachur
Confirmed on 5.0.68 / linux
After my machine has crashed due to power failure, I started it again: after restart there were 120 processess "opening tables" concerning only one ARCHIEVE table. CPU usage was 100%, box was slow down to maximum. In mysql data dir I notoces that there are 3 files:
- systemLogs.ARM
- systemLogs.ARN (size growing for 20 minutes than froze)
- systemLogs.ARZ

I was desperated and run 'kill -9 MYSQL_PID' because it was impossible to restart MySQL, and even `strace -p MYSQL_PID` was silent. After kill -9 I started server again and after a few minutes systemLogs were repaired and working fine.

I'm getting rid of ARCHIEVE in favour of InnoDB/MyISAM because it's damn insecure, and can lead whole service to be unavailable.
[31 Jan 2009 9:43] Piotr Czachur
mysql> check table systemLogs EXTENDED;
+-----------------+-------+----------+----------+
| Table           | Op    | Msg_type | Msg_text |
+-----------------+-------+----------+----------+
| mydb.systemLogs | check | status   | OK       | 
+-----------------+-------+----------+----------+

But when I make mysqldump of this table, data inside (from some point) is trash:
========================
INSERT INTO `systemLogs` VALUES ('55555555555555555555555555555555555555555555555555555','<DA>916-04-18 06:36:69','55555555555555555555555555555555555555555555555555555','55555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555555\0\0\0\0\0\0\0transactions\0frm\0\0\0\0\0\0\0\0#sql-2081_36.frm\0\0\0\0\0\0\0\0#sql-2081_36.MYI\0\0\0\0\0\0\0\0#sql-2081_36.MYD\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0...
========================
It definitely is not what I inserted into the table.
[2 Feb 2009 17:38] Brian Aker
If this happens on 5.1 you can run "archive_reader" (it comes only with the source). It can offline rebuild an archive table.
[3 Feb 2009 8:01] Piotr Czachur
Brian,
thanks for fast response and sorry for my anger - it was friday's night and I  lost data.
I'll try your method, not sure if rebuild_archive from 5.1 will fix 5.0 table (fortunetly I have some backup). Please notice that data inside row I presented above, contains some filenames (including some temporary data) from datadir: "\0transactions\0frm\0\0\0\0\0\0\0\0#sql-2081_36.frm\0\0\0\0\0\0\0\0#sql-2081_36.MYI\0\0\0\0\0\0\0\0#sql-2081_36.MYD" - looks like something is really nasty spoiled.

Important note: after power failure system boot up with /tmp partition with free space of only 16MB. On '/' there was 25GB free, so MySQL data dir have enough free space to perform any operations (largest table has ~ 100MB).
If you need some more info to debug this situation, I'm ready to help.