[debian-mysql] Bug#706072: mysql-server-5.5: Killing a query inside InnoDB causes it to eventually crash with an assertion
Joshua Dennis
jmd at rhsonline.net
Wed Apr 24 12:43:14 UTC 2013
Package: mysql-server-5.5
Version: 5.5.30+dfsg-1.1
Severity: normal
Dear Maintainer,
Yesterday I had a bad situation where mysqld crashed and restarted twice
within the span of 20 minutes. Both times the crash was due to me doing
a ctrl-c to stop a subselect query that was taking too long to run. I
found what looks like a similar if not exact bug for this on
bugs.mysql.com. They have it marked as "closed" with no indication as
to if there is a fix etc.
http://bugs.mysql.com/bug.php?id=68051
Here is a copy/paste from my daemon.log
--------------
Apr 23 16:15:55 onyx mysqld: len 224; hex 98a11968167f0000e94104e3167f000000575583167f00000000000000000000000000000000000000000000000000000100000000000000020000000000000001000000000000000000000000000000000000000000000004000000000000000100000000000000000000000000000019a020c8046300000000000000000000010000000000000083445107000000000ee3085c167f00000200000000000000010000000000000000575583167f0000110000000000000060e1117700000000020000000000000058d9825c167f000008e3085c167f00001800000000000000; asc h A WU c DQ \ WU w X \ \ ;
Apr 23 16:15:55 onyx mysqld: TRANSACTION 29D9E4A4, ACTIVE 27 sec fetching rows
Apr 23 16:15:55 onyx mysqld: mysql tables in use 2, locked 0
Apr 23 16:15:55 onyx mysqld: MySQL thread id 3501338, OS thread handle 0x7f1915b74700, query id 50470056 localhost rhs preparing
Apr 23 16:15:55 onyx mysqld: select * from podetail where ponum in(select ponum from pomast where whsein='84' and year(podate)='2013')
Apr 23 16:15:55 onyx mysqld: 130423 16:15:55 InnoDB: Assertion failure in thread 139745715242752 in file btr0pcur.c line 250
Apr 23 16:15:55 onyx mysqld: InnoDB: We intentionally generate a memory trap.
Apr 23 16:15:55 onyx mysqld: InnoDB: Submit a detailed bug report to http://bugs.mysql.com.
Apr 23 16:15:55 onyx mysqld: InnoDB: If you get repeated assertion failures or crashes, even
Apr 23 16:15:55 onyx mysqld: InnoDB: immediately after the mysqld startup, there may be
Apr 23 16:15:55 onyx mysqld: InnoDB: corruption in the InnoDB tablespace. Please refer to
Apr 23 16:15:55 onyx mysqld: InnoDB: http://dev.mysql.com/doc/refman/5.5/en/forcing-innodb-recovery.html
Apr 23 16:15:55 onyx mysqld: InnoDB: about forcing recovery.
Apr 23 16:15:55 onyx mysqld: 20:15:55 UTC - mysqld got signal 6 ;
Apr 23 16:15:55 onyx mysqld: This could be because you hit a bug. It is also possible that this binary
Apr 23 16:15:55 onyx mysqld: or one of the libraries it was linked against is corrupt, improperly built,
Apr 23 16:15:55 onyx mysqld: or misconfigured. This error can also be caused by malfunctioning hardware.
Apr 23 16:15:55 onyx mysqld: We will try our best to scrape up some info that will hopefully help
Apr 23 16:15:55 onyx mysqld: diagnose the problem, but since we have already crashed,
Apr 23 16:15:55 onyx mysqld: something is definitely wrong and this may fail.
Apr 23 16:15:55 onyx mysqld:
Apr 23 16:15:55 onyx mysqld: key_buffer_size=16777216
Apr 23 16:15:55 onyx mysqld: read_buffer_size=131072
Apr 23 16:15:55 onyx mysqld: max_used_connections=50
Apr 23 16:15:55 onyx mysqld: max_threads=151
Apr 23 16:15:55 onyx mysqld: thread_count=26
Apr 23 16:15:55 onyx mysqld: connection_count=26
Apr 23 16:15:55 onyx mysqld: It is possible that mysqld could use up to
Apr 23 16:15:55 onyx mysqld: key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 346682 K bytes of memory
Apr 23 16:15:55 onyx mysqld: Hope that's ok; if not, decrease some variables in the equation.
Apr 23 16:15:55 onyx mysqld:
Apr 23 16:15:55 onyx mysqld: Thread pointer: 0x7f19280d04d0
Apr 23 16:15:55 onyx mysqld: Attempting backtrace. You can use the following information to find out
Apr 23 16:15:55 onyx mysqld: where mysqld died. If you see no messages after this, something went
Apr 23 16:15:55 onyx mysqld: terribly wrong...
Apr 23 16:15:55 onyx mysqld: stack_bottom = 7f1915b73e80 thread_stack 0x30000
Apr 23 16:15:55 onyx mysqld: /usr/sbin/mysqld(my_print_stacktrace+0x29)[0x7f19161139d9]
Apr 23 16:15:55 onyx mysqld: /usr/sbin/mysqld(handle_fatal_signal+0x3d8)[0x7f1915ffc498]
Apr 23 16:15:55 onyx mysqld: /lib/x86_64-linux-gnu/libpthread.so.0(+0xf030)[0x7f19157a7030]
Apr 23 16:15:55 onyx mysqld: /lib/x86_64-linux-gnu/libc.so.6(gsignal+0x35)[0x7f191401a475]
Apr 23 16:15:55 onyx mysqld: /lib/x86_64-linux-gnu/libc.so.6(abort+0x180)[0x7f191401d6f0]
Apr 23 16:15:55 onyx mysqld: /usr/sbin/mysqld(+0x5a85a4)[0x7f19161885a4]
Apr 23 16:15:55 onyx mysqld: /usr/sbin/mysqld(+0x29b6d7)[0x7f1915e7b6d7]
Apr 23 16:15:55 onyx mysqld: /usr/sbin/mysqld(+0x564f64)[0x7f1916144f64]
Apr 23 16:15:55 onyx mysqld: /usr/sbin/mysqld(+0x5494ec)[0x7f19161294ec]
Apr 23 16:15:55 onyx mysqld: /usr/sbin/mysqld(_ZN30subselect_indexsubquery_engine4execEv+0x11f)[0x7f1916064bcf]
Apr 23 16:15:55 onyx mysqld: /usr/sbin/mysqld(_ZN14Item_subselect4execEv+0x32)[0x7f1916061a82]
Apr 23 16:15:55 onyx mysqld: /usr/sbin/mysqld(_ZN17Item_in_subselect8val_boolEv+0x18)[0x7f1916061478]
Apr 23 16:15:55 onyx mysqld: /usr/sbin/mysqld(_ZN17Item_in_optimizer7val_intEv+0x13d)[0x7f191601f09d]
Apr 23 16:15:55 onyx mysqld: /usr/sbin/mysqld(+0x34599c)[0x7f1915f2599c]
Apr 23 16:15:55 onyx mysqld: /usr/sbin/mysqld(_Z10sub_selectP4JOINP13st_join_tableb+0x76)[0x7f1915f25c46]
Apr 23 16:15:55 onyx mysqld: /usr/sbin/mysqld(+0x354f85)[0x7f1915f34f85]
Apr 23 16:15:55 onyx mysqld: /usr/sbin/mysqld(_ZN4JOIN4execEv+0x7ca)[0x7f1915f431fa]
Apr 23 16:15:55 onyx mysqld: /usr/sbin/mysqld(_Z12mysql_selectP3THDPPP4ItemP10TABLE_LISTjR4ListIS1_ES2_jP8st_orderSB_S2_SB_yP13select_resultP18st_select_lex_unitP13st_select_lex+0x11d)[0x7f1915f3ecdd]
Apr 23 16:15:55 onyx mysqld: /usr/sbin/mysqld(_Z13handle_selectP3THDP3LEXP13select_resultm+0x174)[0x7f1915f44da4]
Apr 23 16:15:55 onyx mysqld: /usr/sbin/mysqld(+0x31dc74)[0x7f1915efdc74]
Apr 23 16:15:55 onyx mysqld: /usr/sbin/mysqld(_Z21mysql_execute_commandP3THD+0x1309)[0x7f1915f04999]
Apr 23 16:15:55 onyx mysqld: /usr/sbin/mysqld(+0x327e5e)[0x7f1915f07e5e]
Apr 23 16:15:55 onyx mysqld: /usr/sbin/mysqld(_Z16dispatch_command19enum_server_commandP3THDPcj+0x193b)[0x7f1915f09fdb]
Apr 23 16:15:55 onyx mysqld: /usr/sbin/mysqld(_Z24do_handle_one_connectionP3THD+0x105)[0x7f1915fa37b5]
Apr 23 16:15:55 onyx mysqld: /usr/sbin/mysqld(handle_one_connection+0x50)[0x7f1915fa38d0]
Apr 23 16:15:55 onyx mysqld: /lib/x86_64-linux-gnu/libpthread.so.0(+0x6b50)[0x7f191579eb50]
Apr 23 16:15:55 onyx mysqld: /lib/x86_64-linux-gnu/libc.so.6(clone+0x6d)[0x7f19140c2a7d]
Apr 23 16:15:55 onyx mysqld:
Apr 23 16:15:55 onyx mysqld: Trying to get some variables.
Apr 23 16:15:55 onyx mysqld: Some pointers may be invalid and cause the dump to abort.
Apr 23 16:15:55 onyx mysqld: Query (7f165c300e30): is an invalid pointer
Apr 23 16:15:55 onyx mysqld: Connection ID (thread ID): 3501338
Apr 23 16:15:55 onyx mysqld: Status: KILL_QUERY
Apr 23 16:15:55 onyx mysqld:
Apr 23 16:15:55 onyx mysqld: The manual page at http://dev.mysql.com/doc/mysql/en/crashing.html contains
Apr 23 16:15:55 onyx mysqld: information that should help you find out what is causing the crash.
Apr 23 16:15:56 onyx mysqld_safe: Number of processes running now: 0
Apr 23 16:15:56 onyx mysqld_safe: mysqld restarted
Apr 23 16:15:56 onyx mysqld: 130423 16:15:56 [Warning] The syntax '--log-slow-queries' is deprecated and will be removed in a future release. Please use '--slow-query-log'/'--slow-query-log-file' instead.
Apr 23 16:15:56 onyx mysqld: 130423 16:15:56 InnoDB: The InnoDB memory heap is disabled
Apr 23 16:15:56 onyx mysqld: 130423 16:15:56 InnoDB: Mutexes and rw_locks use GCC atomic builtins
Apr 23 16:15:56 onyx mysqld: 130423 16:15:56 InnoDB: Compressed tables use zlib 1.2.7
Apr 23 16:15:56 onyx mysqld: 130423 16:15:56 InnoDB: Using Linux native AIO
Apr 23 16:15:56 onyx mysqld: 130423 16:15:56 InnoDB: Initializing buffer pool, size = 10.0G
Apr 23 16:15:57 onyx mysqld: 130423 16:15:57 InnoDB: Completed initialization of buffer pool
Apr 23 16:15:57 onyx mysqld: 130423 16:15:57 InnoDB: highest supported file format is Barracuda.
Apr 23 16:15:58 onyx mysqld: InnoDB: Log scan progressed past the checkpoint lsn 199373479329
Apr 23 16:15:58 onyx mysqld: 130423 16:15:58 InnoDB: Database was not shut down normally!
Apr 23 16:15:58 onyx mysqld: InnoDB: Starting crash recovery.
Apr 23 16:15:58 onyx mysqld: InnoDB: Reading tablespace information from the .ibd files...
Apr 23 16:16:00 onyx mysqld: InnoDB: Restoring possible half-written data pages from the doublewrite
Apr 23 16:16:00 onyx mysqld: InnoDB: buffer...
Apr 23 16:16:00 onyx mysqld: InnoDB: Doing recovery: scanned up to log sequence number 199373484219
Apr 23 16:16:01 onyx mysqld: 130423 16:16:01 InnoDB: Starting an apply batch of log records to the database...
Apr 23 16:16:02 onyx mysqld: InnoDB: Progress in percents: 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 57 58 59 60 61 62 63 64 65 66 67 68 69 70 71 72 73 74 75 76 77 78 79 80 81 82 83 84 85 86 87 88 89 90 91 92 93 94 95 96 97 98 99
Apr 23 16:16:02 onyx mysqld: InnoDB: Apply batch completed
Apr 23 16:16:02 onyx mysqld: InnoDB: Last MySQL binlog file position 0 85202446, file name /var/log/mysql/mysql-bin.000943
Apr 23 16:16:02 onyx mysqld: 130423 16:16:02 InnoDB: Waiting for the background threads to start
Apr 23 16:16:03 onyx mysqld: 130423 16:16:03 InnoDB: 5.5.30 started; log sequence number 199373484219
Apr 23 16:16:03 onyx mysqld: 130423 16:16:03 [Note] Recovering after a crash using /var/log/mysql/mysql-bin
Apr 23 16:16:04 onyx mysqld: 130423 16:16:04 [Note] Starting crash recovery...
Apr 23 16:16:04 onyx mysqld: 130423 16:16:04 [Note] Crash recovery finished.
Apr 23 16:16:05 onyx mysqld: 130423 16:16:05 [Note] Server hostname (bind-address): '0.0.0.0'; port: 3306
Apr 23 16:16:05 onyx mysqld: 130423 16:16:05 [Note] - '0.0.0.0' resolves to '0.0.0.0';
Apr 23 16:16:05 onyx mysqld: 130423 16:16:05 [Note] Server socket created on IP: '0.0.0.0'.
Apr 23 16:16:05 onyx mysqld: 130423 16:16:05 [Warning] 'proxies_priv' entry '@ root at newonyx' ignored in --skip-name-resolve mode.
Apr 23 16:16:05 onyx mysqld: 130423 16:16:05 [Note] Event Scheduler: Loaded 0 events
Apr 23 16:16:05 onyx mysqld: 130423 16:16:05 [Note] /usr/sbin/mysqld: ready for connections.
Apr 23 16:16:05 onyx mysqld: Version: '5.5.30-1-log' socket: '/var/run/mysqld/mysqld.sock' port: 3306 (Debian)
-----------------
-- System Information:
Debian Release: 7.0
APT prefers testing
APT policy: (500, 'testing')
Architecture: amd64 (x86_64)
Kernel: Linux 3.2.0-4-amd64 (SMP w/4 CPU cores)
Locale: LANG=en_US.UTF-8, LC_CTYPE=en_US.UTF-8 (charmap=UTF-8)
Shell: /bin/sh linked to /bin/dash
Versions of packages mysql-server-5.5 depends on:
ii adduser 3.113+nmu3
ii debconf [debconf-2.0] 1.5.49
ii initscripts 2.88dsf-41
ii libc6 2.13-38
ii libdbi-perl 1.622-1
ii libgcc1 1:4.7.2-5
ii libstdc++6 4.7.2-5
ii lsb-base 4.1+Debian8
ii mysql-client-5.5 5.5.30+dfsg-1.1
ii mysql-common 5.5.30+dfsg-1.1
ii mysql-server-core-5.5 5.5.30+dfsg-1.1
ii passwd 1:4.1.5.1-1
ii perl 5.14.2-21
ii psmisc 22.19-1+deb7u1
ii zlib1g 1:1.2.7.dfsg-13
Versions of packages mysql-server-5.5 recommends:
ii bsd-mailx [mailx] 8.1.2-0.20111106cvs-1
ii libhtml-template-perl 2.91-1
Versions of packages mysql-server-5.5 suggests:
pn tinyca <none>
-- debconf information:
mysql-server/error_setting_password:
mysql-server-5.5/postrm_remove_databases: false
mysql-server-5.5/start_on_boot: true
mysql-server-5.5/nis_warning:
mysql-server-5.5/really_downgrade: false
mysql-server/password_mismatch:
mysql-server/no_upgrade_when_using_ndb:
Joshua Dennis
Robertson Heating Supply
IS Manager
More information about the pkg-mysql-maint
mailing list