Bug #17589 select count(*) from general_log; with file size of 27GB results in core
Submitted: 20 Feb 2006 17:24 Modified: 23 Jun 2006 4:43
Reporter: Jonathan Miller Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Server: Logging Severity:S1 (Critical)
Version:5.1.8 OS:Linux (Linux 64 bit OS)
Assigned to: Petr Chardin CPU Architecture:Any

[20 Feb 2006 17:24] Jonathan Miller
Description:
I noticed from the cluster stress test that the mysql database general log table had grown to 27GB in size. Wanting to now how many rows that table contained I issues a "select count(*) from general_log; after a "use mysql;" Results:

mysql> use mysql
Reading table information for completion of table and column names
You can turn off this feature to get a quicker startup with -A

Database changed
mysql> select count(*) from general_log;
ERROR 2013 (HY000): Lost connection to MySQL server during query
mysql> 060220 18:15:01  guardian: starting instance mysqld
060220 18:15:01 starting instance mysqld

Error Log:
mysqld got signal 11;
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=2
max_connections=100
threads_connected=1
It is possible that mysqld could use up to
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_connections = 225791 K
bytes of memory
Hope that's ok; if not, decrease some variables in the equation.

Writing a core file

Core BT:
#0  0x00000033b8c096a7 in pthread_kill () from /lib64/libpthread.so.0
#1  0x0000000000701518 in write_core ()
#2  0x00000000005baf86 in handle_segfault ()
#3  <signal handler called>
#4  0x000000000075621a in find_eoln ()
#5  0x000000000075696f in ha_tina::find_current_row ()
#6  0x000000000075721e in ha_tina::rnd_next ()
#7  0x00000000006a18f5 in rr_sequential ()
#8  0x0000000000629cb7 in sub_select ()
#9  0x000000000062a000 in do_select ()
#10 0x000000000063bfe7 in JOIN::exec ()
#11 0x000000000063c2db in mysql_select ()
#12 0x000000000063c56d in handle_select ()
#13 0x00000000005d4fa6 in mysql_execute_command ()
#14 0x00000000005dd1cf in mysql_parse ()
#15 0x00000000005ddc07 in dispatch_command ()
#16 0x00000000005df1ad in do_command ()
#17 0x00000000005df595 in handle_one_connection ()
#18 0x00000033b8c0697c in start_thread () from /lib64/libpthread.so.0
#19 0x00000033b83c992e in clone () from /lib64/libc.so.6

How to repeat:
I repeated it several time to be able to get the core file due to ulimit not being set correctly on the system. Problem is that you need a 27GB genereal log table to produce this crash.

-rw-rw----  1 ndbdev ndbdev 27697211595 Feb 20 18:22 general_log.CSV
-rw-rw----  1 ndbdev ndbdev        8776 Feb 17 23:13 general_log.frm

So not that easy to repeat
[23 Feb 2006 1:57] Brian Aker
Jonathan, what distribution were you using? Could you run this and tell me what the output was:

cat >> foo.c
#include <stdio.h>
#include <sys/types.h>

int main()
{
    printf("Foo %d\n", sizeof(off_t));
      return 0;
} 

gcc foo.c
./a.out

Thanks,

  -Brian
[25 Feb 2006 18:33] Jonathan Miller
Per Brians request, it shows 4 on 32 bit systems and 8 on 64 bit systems
[28 Mar 2006 19:49] Jonathan Miller
Hi, 

Running cluster stress test today, wanted to see if I needed to truncate the general_log table so I did select count(*) from it and boom mysqld gone :-(

#0  0x008f6465 in mempcpy () from /lib/libc.so.6
#1  0x008ea9ed in _IO_new_file_xsputn () from /lib/libc.so.6
#2  0x008c59e3 in buffered_vfprintf () from /lib/libc.so.6
#3  0x008c5c37 in vfprintf () from /lib/libc.so.6
#4  0x008df9aa in __fxprintf () from /lib/libc.so.6
#5  0x008ac2d5 in __assert_fail () from /lib/libc.so.6
#6  0x0841cf48 in __cxa_pure_virtual ()
#7  0x0818e144 in Item_func_now_local::store_now_in_TIME ()
#8  0x0818e0a9 in Item_func_now::fix_length_and_dec ()
#9  0x081611d8 in Item_func::fix_fields ()
#10 0x082166ed in setup_fields ()
#11 0x08251ca3 in mysql_update ()
#12 0x081eafc4 in mysql_execute_command ()
#13 0x08305a2b in sp_instr_stmt::exec_core ()
#14 0x0830584e in sp_lex_keeper::reset_lex_and_exec_core ()
#15 0x08307f61 in sp_instr_stmt::execute ()
#16 0x0830322d in sp_head::execute ()
#17 0x083040c4 in sp_head::execute_procedure ()
#18 0x081eee13 in mysql_execute_command ()
#19 0x081f0ba0 in mysql_parse ()
#20 0x081f142c in dispatch_command ()
#21 0x081f256e in do_command ()
#22 0x081f2925 in handle_one_connection ()
#23 0x009fdb80 in start_thread () from /lib/libpthread.so.0
#24 0x009559ce in clone () from /lib/libc.so.6
[28 Mar 2006 19:51] Jonathan Miller
Also got this nice stack trace in the error log:

0x81cfe00 handle_segfault + 438
0xc4f420 (?)
0x81 (?)
0x829a13d _Z13rr_sequentialP14st_read_record + 115
0x8233567 _Z10sub_selectP4JOINP13st_join_tableb + 333
0x823386c _Z9do_selectP4JOINP4ListI4ItemEP8st_tableP9Procedure + 668
0x8243783 _ZN4JOIN4execEv + 6235
0x82439ff _Z12mysql_selectP3THDPPP4ItemP13st_table_listjR4ListIS1_ES2_jP8st_orderSB_S2_SB_mP13select_resultP18st_select_lex_unitP13st_sel + 561
0x8243c2f _Z13handle_selectP3THDP6st_lexP13select_resultm + 309
0x81e92f9 _Z21mysql_execute_commandP3THD + 1877
0x81f0ba0 _Z11mysql_parseP3THDPcj + 608
[16 Jun 2006 22:05] Petr Chardin
Fixed in scope of WL#3244  "CSV engine: convert mmap to read/write calls"
[21 Jun 2006 4:28] Paul DuBois
Need the three-part version number for the patch.
Thanks.
[22 Jun 2006 19:29] Petr Chardin
the patch was pushed to 5.1.12-beta
[23 Jun 2006 4:43] Paul DuBois
Noted in 5.1.12 changelog.

If the general log table reached a large enough file size (27GB),
SELECT COUNT(*) on the table caused a server crash.