Bug #38099 system test stopped with a server crash.
Submitted: 14 Jul 2008 14:06 Modified: 24 Nov 2008 4:00
Reporter: Horst Hunger Email Updates:
Status: No Feedback Impact on me:
None 
Category:MySQL Server Severity:S1 (Critical)
Version:6.0.6-alpha-debug OS:Linux
Assigned to: CPU Architecture:Any

[14 Jul 2008 14:06] Horst Hunger
Description:
See also bug#37859.
The backtrace:
This GDB was configured as "x86_64-suse-linux"...
Using host libthread_db library "/lib64/libthread_db.so.1".
Reading symbols from /lib64/libnsl.so.1...done.
Loaded symbols for /lib64/libnsl.so.1
Reading symbols from /lib64/librt.so.1...done.
Loaded symbols for /lib64/librt.so.1
Reading symbols from /lib64/libpthread.so.0...done.
Loaded symbols for /lib64/libpthread.so.0
Reading symbols from /usr/lib64/libstdc++.so.6...done.
Loaded symbols for /usr/lib64/libstdc++.so.6
Reading symbols from /lib64/libm.so.6...done.
Loaded symbols for /lib64/libm.so.6
Reading symbols from /lib64/libgcc_s.so.1...done.
Loaded symbols for /lib64/libgcc_s.so.1
Reading symbols from /lib64/libc.so.6...done.
Loaded symbols for /lib64/libc.so.6
Reading symbols from /lib64/libdl.so.2...done.
Loaded symbols for /lib64/libdl.so.2
Reading symbols from /lib64/libresolv.so.2...done.
Loaded symbols for /lib64/libresolv.so.2
Reading symbols from /lib64/libcrypt.so.1...done.
Loaded symbols for /lib64/libcrypt.so.1
Reading symbols from /lib64/ld-linux-x86-64.so.2...done.
Loaded symbols for /lib64/ld-linux-x86-64.so.2
Core was generated by `/data0/bzr/mysql-6.0-system-test/sql/mysqld --no-defaults --basedir=/data0/bzr/'.
Program terminated with signal 11, Segmentation fault.
#0  0x00002afe5942eea3 in pthread_kill () from /lib64/libpthread.so.0
(gdb) bt
#0  0x00002afe5942eea3 in pthread_kill () from /lib64/libpthread.so.0
#1  0x0000000000d36341 in my_write_core (sig=11) at stacktrace.c:307
#2  0x00000000006f780b in handle_segfault (sig=11) at mysqld.cc:2638
#3  <signal handler called>
#4  0x0000000000d3ad8c in safe_mutex_lock (mp=0xa5a5a5a5a5a5a5bd, try_lock=0 '\0',
    file=0xfa212f "thr_lock.c", line=525) at thr_mutex.c:99
#5  0x0000000000d38b92 in thr_lock (data=0x5759680, owner=0x4dc35a0,
    lock_type=-1515870811) at thr_lock.c:525
#6  0x0000000000d39e62 in thr_multi_lock (data=0x33c59b8, count=1, owner=0x4dc35a0)
    at thr_lock.c:990
#7  0x00000000006ede19 in mysql_lock_tables (thd=0x4dc2838, tables=0x4aee9838,
    count=1, flags=27, need_reopen=0x4aee96cb) at lock.cc:306
#8  0x0000000000755d85 in open_ltable (thd=0x4dc2838, table_list=0x4aee9790,
    lock_type=TL_WRITE_CONCURRENT_INSERT, lock_flags=27) at sql_base.cc:4042
#9  0x0000000000755e82 in open_performance_schema_table (thd=0x4dc2838,
    one_table=0x4aee9790, backup=0x4aee9d10) at sql_base.cc:7891
#10 0x00000000007cc133 in Log_to_csv_event_handler::log_general (this=0x1e00dc0,
    thd=0x4dc2838, event_time=1216032213,
    user_host=0x4aee9e60 "root[root] @ localhost [localhost]", user_host_len=34,
    thread_id=580, command_type=0xe72b4d "Query", command_type_len=5,
    sql_text=0x2801a40 "insert into tb1_logs (dt1, entry_dsc, f4)\nvalues (now(), concat('Update row ', old.f1,' ', old.f2, '->',\nnew.f2, ' ', old.f3, '->', new.f3, ' (tb1_eng1)'), new.f1)", sql_text_len=163, client_cs=0x134e6a0) at log.cc:391
#11 0x00000000007caaf6 in LOGGER::general_log_write (this=0x1360700,
    thd=0x4dc2838, command=COM_QUERY,
    query=0x2801a40 "insert into tb1_logs (dt1, entry_dsc, f4)\nvalues (now(), concat('Update row ', old.f1,' ', old.f2, '->',\nnew.f2, ' ', old.f3, '->', new.f3, ' (tb1_eng1)'), new.f1)", query_length=163) at log.cc:1046
#12 0x00000000007caba6 in general_log_write (thd=0x4dc2838, command=COM_QUERY,
    query=0x2801a40 "insert into tb1_logs (dt1, entry_dsc, f4)\nvalues (now(), concat('Update row ', old.f1,' ', old.f2, '->',\nnew.f2, ' ', old.f3, '->', new.f3, ' (tb1_eng1)'), new.f1)", query_length=163) at log.cc:4091
#13 0x00000000008c36bc in sp_instr_stmt::execute (this=0x3cd0cd0, thd=0x4dc2838,
    nextp=0x4aeea378) at sp_head.cc:2824
#14 0x00000000008c56ab in sp_head::execute (this=0x3cc9780, thd=0x4dc2838)
    at sp_head.cc:1238
#15 0x00000000008c710b in sp_head::execute_trigger (this=0x3cc9780, thd=0x4dc2838,
    db_name=0x289cda0, table_name=0x289cdb0, grant_info=0x3f3ee18)
    at sp_head.cc:1541
#16 0x00000000008d40ad in Table_triggers_list::process_triggers (this=0x3f3ecf0,
    thd=0x4dc2838, event=TRG_EVENT_UPDATE, time_type=TRG_ACTION_AFTER,
    old_row_is_record1=true) at sql_trigger.cc:1969
#17 0x00000000007b784f in mysql_update (thd=0x4dc2838, table_list=0x4ffbd50,
    fields=@0x4ffe878, values=@0x4ffec80, conds=0x4fffe40, order_num=0, order=0x0,
    limit=18446744073709551300, handle_duplicates=DUP_ERROR, ignore=false)
    at sql_update.cc:668
#18 0x000000000070b16b in mysql_execute_command (thd=0x4dc2838)
    at sql_parse.cc:2843
#19 0x00000000008c27d3 in sp_instr_stmt::exec_core (this=0x4ffffb0, thd=0x4dc2838,
    nextp=0x4aeebc38) at sp_head.cc:2885
#20 0x00000000008c30ee in sp_lex_keeper::reset_lex_and_exec_core (this=0x4fffff0,
    thd=0x4dc2838, nextp=0x4aeebc38, open_tables=false, instr=0x4ffffb0)
    at sp_head.cc:2715
#21 0x00000000008c3703 in sp_instr_stmt::execute (this=0x4ffffb0, thd=0x4dc2838,
    nextp=0x4aeebc38) at sp_head.cc:2828
#22 0x00000000008c56ab in sp_head::execute (this=0x2b053d0, thd=0x4dc2838)
---Type <return> to continue, or q <return> to quit---
    at sp_head.cc:1238
#23 0x00000000008c63a1 in sp_head::execute_procedure (this=0x2b053d0,
    thd=0x4dc2838, args=0x4aeebff0) at sp_head.cc:1963
#24 0x00000000008d9f58 in Event_job_data::execute (this=0x4aeec080, thd=0x4dc2838,
    drop=false) at event_data_objects.cc:1467
#25 0x00000000008d9398 in Event_worker_thread::run (this=0x4aeec19f,
    thd=0x4dc2838, event=0x44f3400) at event_scheduler.cc:312
#26 0x00000000008d94d3 in event_worker_thread (arg=0x44f3400)
    at event_scheduler.cc:263
#27 0x00002afe5942a143 in start_thread () from /lib64/libpthread.so.0
#28 0x00002afe59a5c74d in clone () from /lib64/libc.so.6
#29 0x0000000000000000 in ?? ()
(gdb)                                                                            

More info can be found on the machine "dl360-g5-d" in "/data0/bzr/mysql-6.0-system-test/mysql-test".
The var directory is available as "system-crash-2.tar.gz".

How to repeat:
The system test executes sql in an arbitrary order and run about 1 hour. So, reproduction
is difficult. The analysis of general_log.CSV or master.log may help to find the sequence
of sql to reproduce the crash.
[16 Jul 2008 12:15] Susanne Ebrecht
could be related to bug #33362
[2 Aug 2008 12:16] MySQL Verification Team
from the stack trace:
the event thread run some stored procedure 
that executed an update against a table
which contains a trigger
which inserts the old values into a tbl_logs table.

the general query log is enabled --log --log-output=FILE
the crash is due to some uninitialized mutex when opening the
general_log table.
[2 Aug 2008 12:35] MySQL Verification Team
Horst do you get the assertion/crash quicker if you run 'flush tables' 10 times per second in another connection ?
[11 Aug 2008 7:30] Sveta Smirnova
Bug #37859 was marked as duplicate of this one.
[24 Oct 2008 4:00] Valeriy Kravchuk
Is this still repeatable with 6.0.7?
[25 Nov 2008 0:00] Bugs System
No feedback was provided for this bug for over a month, so it is
being suspended automatically. If you are able to provide the
information that was originally requested, please do so and change
the status of the bug back to "Open".