[MDEV-12526] MariaDB crash Created: 2017-04-19  Updated: 2022-07-26  Resolved: 2022-07-26

Status: Closed
Project: MariaDB Server
Component/s: Server
Affects Version/s: 10.1.16
Fix Version/s: N/A

Type: Bug Priority: Major
Reporter: Sergey Antonyuk Assignee: Unassigned
Resolution: Incomplete Votes: 0
Labels: None
Environment:

3.2.0-4-amd64 #1 SMP Debian 3.2.35-2 x86_64 GNU/Linux


Attachments: File D_AUDIT.sql     File my.cnf    

 Description   

The server crashes periodically.
Maybe the problem is in the following cursor: SELECT id from information_schema.processlist WHERE (info like 'CREATE TABLE%ENGINE=CONNECT%' and time > 120);
I don't know the scenario how to reproduce the bug.

Here is the syslog:

Apr 19 05:27:08 host mysqld: 170419  5:27:08 [ERROR] mysqld got signal 11 ;
Apr 19 05:27:08 host mysqld: This could be because you hit a bug. It is also possible that this binary
Apr 19 05:27:08 host mysqld: or one of the libraries it was linked against is corrupt, improperly built,
Apr 19 05:27:08 host mysqld: or misconfigured. This error can also be caused by malfunctioning hardware.
Apr 19 05:27:08 host mysqld:
Apr 19 05:27:08 host mysqld: To report this bug, see https://mariadb.com/kb/en/reporting-bugs
Apr 19 05:27:08 host mysqld:
Apr 19 05:27:08 host mysqld: We will try our best to scrape up some info that will hopefully help
Apr 19 05:27:08 host mysqld: diagnose the problem, but since we have already crashed,
Apr 19 05:27:08 host mysqld: something is definitely wrong and this may fail.
Apr 19 05:27:08 host mysqld:
Apr 19 05:27:08 host mysqld: Server version: 10.1.16-MariaDB-1~wheezy
Apr 19 05:27:08 host mysqld: key_buffer_size=33554432
Apr 19 05:27:08 host mysqld: read_buffer_size=131072
Apr 19 05:27:08 host mysqld: max_used_connections=9
Apr 19 05:27:08 host mysqld: max_threads=302
Apr 19 05:27:08 host mysqld: thread_count=10
Apr 19 05:27:08 host mysqld: It is possible that mysqld could use up to
Apr 19 05:27:08 host mysqld: key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 386837 K  bytes of memory
Apr 19 05:27:08 host mysqld: Hope that's ok; if not, decrease some variables in the equation.
Apr 19 05:27:08 host mysqld:
Apr 19 05:27:08 host mysqld: Thread pointer: 0x0x7ff6c3c95008
Apr 19 05:27:08 host mysqld: Attempting backtrace. You can use the following information to find out
Apr 19 05:27:08 host mysqld: where mysqld died. If you see no messages after this, something went
Apr 19 05:27:08 host mysqld: terribly wrong...
Apr 19 05:27:08 host mysqld: stack_bottom = 0x7ff6ecc8fd5f thread_stack 0x80000
Apr 19 05:27:08 host mysqld: /usr/sbin/mysqld(my_print_stacktrace+0x2b)[0x7ff6efa5fa6b]
Apr 19 05:27:08 host mysqld: /usr/sbin/mysqld(handle_fatal_signal+0x475)[0x7ff6ef5bcad5]
Apr 19 05:27:08 host mysqld: /lib/x86_64-linux-gnu/libpthread.so.0(+0xf0a0)[0x7ff6eebae0a0]
Apr 19 05:27:08 host mysqld: /lib/x86_64-linux-gnu/libc.so.6(+0x7fd61)[0x7ff6ed028d61]
Apr 19 05:27:08 host mysqld: /usr/sbin/mysqld(_Z23fill_schema_processlistP3THDP10TABLE_LISTP4Item+0x25c)[0x7ff6ef4ae87c]
Apr 19 05:27:08 host mysqld: /usr/sbin/mysqld(_Z24get_schema_tables_resultP4JOIN23enum_schema_table_state+0x28e)[0x7ff6ef4b802e]
Apr 19 05:27:08 host mysqld: /usr/sbin/mysqld(_ZN4JOIN10exec_innerEv+0x6b5)[0x7ff6ef49de25]
Apr 19 05:27:08 host mysqld: /usr/sbin/mysqld(_ZN4JOIN4execEv+0x5d)[0x7ff6ef4a024d]
Apr 19 05:27:08 host mysqld: /usr/sbin/mysqld(_Z12mysql_selectP3THDPPP4ItemP10TABLE_LISTjR4ListIS1_ES2_jP8st_orderSB_S2_SB_yP13select_resultP18st_select_lex_unitP13st_select_lex+0x12a)[0x7ff6ef49cbfa]
Apr 19 05:27:08 host mysqld: /usr/sbin/mysqld(_Z13handle_selectP3THDP3LEXP13select_resultm+0x25d)[0x7ff6ef4a052d]
Apr 19 05:27:08 host mysqld: /usr/sbin/mysqld(+0x465332)[0x7ff6ef442332]
Apr 19 05:27:08 host mysqld: /usr/sbin/mysqld(_Z21mysql_execute_commandP3THD+0x5d7f)[0x7ff6ef44e5cf]
Apr 19 05:27:08 host mysqld: /usr/sbin/mysqld(_Z17mysql_open_cursorP3THDP13select_resultPP18Server_side_cursor+0x17c)[0x7ff6ef6cdaec]
Apr 19 05:27:08 host mysqld: /usr/sbin/mysqld(_ZN9sp_cursor4openEP3THD+0x1e)[0x7ff6ef6c1f4e]
Apr 19 05:27:08 host mysqld: /usr/sbin/mysqld(_ZN14sp_instr_copen9exec_coreEP3THDPj+0x30)[0x7ff6ef6b8250]
Apr 19 05:27:08 host mysqld: /usr/sbin/mysqld(_ZN13sp_lex_keeper23reset_lex_and_exec_coreEP3THDPjbP8sp_instr+0x8e)[0x7ff6ef6bdeae]
Apr 19 05:27:08 host mysqld: /usr/sbin/mysqld(_ZN14sp_instr_copen7executeEP3THDPj+0x48)[0x7ff6ef6be198]
Apr 19 05:27:08 host mysqld: /usr/sbin/mysqld(_ZN7sp_head7executeEP3THDb+0x73c)[0x7ff6ef6bb38c]
Apr 19 05:27:08 host mysqld: /usr/sbin/mysqld(_ZN7sp_head17execute_procedureEP3THDP4ListI4ItemE+0x616)[0x7ff6ef6bc736]
Apr 19 05:27:08 host mysqld: /usr/sbin/mysqld(_Z21mysql_execute_commandP3THD+0x64f0)[0x7ff6ef44ed40]
 
Apr 19 05:27:08 host mysqld: /usr/sbin/mysqld(_ZN13sp_instr_stmt9exec_coreEP3THDPj+0x1e)[0x7ff6ef6b844e]
Apr 19 05:27:08 host mysqld: /usr/sbin/mysqld(_ZN13sp_lex_keeper23reset_lex_and_exec_coreEP3THDPjbP8sp_instr+0x8e)[0x7ff6ef6bdeae]
Apr 19 05:27:08 host mysqld: /usr/sbin/mysqld(_ZN13sp_instr_stmt7executeEP3THDPj+0x15d)[0x7ff6ef6be3ad]
Apr 19 05:27:08 host mysqld: /usr/sbin/mysqld(_ZN7sp_head7executeEP3THDb+0x73c)[0x7ff6ef6bb38c]
Apr 19 05:27:08 host mysqld: /usr/sbin/mysqld(_ZN7sp_head17execute_procedureEP3THDP4ListI4ItemE+0x616)[0x7ff6ef6bc736]
Apr 19 05:27:08 host mysqld: /usr/sbin/mysqld(_ZN14Event_job_data7executeEP3THDb+0x599)[0x7ff6ef4fd309]
Apr 19 05:27:08 host mysqld: /usr/sbin/mysqld(_ZN19Event_worker_thread3runEP3THDP28Event_queue_element_for_exec+0xf4)[0x7ff6ef6ebc64]
Apr 19 05:27:08 host mysqld: /usr/sbin/mysqld(event_worker_thread+0x56)[0x7ff6ef6ebd06]
Apr 19 05:27:08 host mysqld: /lib/x86_64-linux-gnu/libpthread.so.0(+0x6b50)[0x7ff6eeba5b50]
Apr 19 05:27:08 host mysqld: /lib/x86_64-linux-gnu/libc.so.6(clone+0x6d)[0x7ff6ed08730d]
Apr 19 05:27:08 host mysqld:
Apr 19 05:27:08 host mysqld: Trying to get some variables.
Apr 19 05:27:08 host mysqld: Some pointers may be invalid and cause the dump to abort.
Apr 19 05:27:08 host mysqld: Query (0x7ff6c2424020): is an invalid pointer
Apr 19 05:27:08 host mysqld: Connection ID (thread ID): 24969
Apr 19 05:27:08 host mysqld: Status: NOT_KILLED
Apr 19 05:27:08 host mysqld:
Apr 19 05:27:08 host mysqld: Optimizer switch: index_merge=on,index_merge_union=on,index_merge_sort_union=on,index_merge_intersection=on,index_merge_sort_intersection=off,engine_condition_pushdown=off,index_condition_pushdown=on,derived_merge=on,derived_with_keys=on,firstmatch=on,loosescan=on,materialization=on,in_to_exists=on,semijoin=on,partial_match_rowid_merge=on,partial_match_table_scan=on,subquery_cache=on,mrr=off,mrr_cost_based=off,mrr_sort_keys=off,outer_join_with_cache=on,semijoin_with_cache=on,join_cache_incremental=on,join_cache_hashed=on,join_cache_bka=on,optimize_join_buffer_size=off,table_elimination=on,extended_keys=on,exists_to_in=on,orderby_uses_equalities=off
Apr 19 05:27:08 host mysqld:
Apr 19 05:27:08 host mysqld: The manual page at http://dev.mysql.com/doc/mysql/en/crashing.html contains
Apr 19 05:27:08 host mysqld: information that should help you find out what is causing the crash.
Apr 19 05:27:08 host mysqld:
Apr 19 05:27:08 host mysqld: We think the query pointer is invalid, but we will try to print it anyway.
Apr 19 05:27:08 host mysqld: Query: CALL AUDIT()



 Comments   
Comment by Elena Stepanova [ 2017-04-19 ]

Could you please paste the definition of the AUDIT() procedure and attach your cnf file(s)?
Thank you.

Comment by Sergey Antonyuk [ 2017-04-20 ]

my.cnf D_AUDIT.sql

Comment by Sergey Antonyuk [ 2017-04-20 ]

Elena, I have attached my.cnf and the procedure definition (D_AUDIT.sql)

Comment by Elena Stepanova [ 2017-05-12 ]

Sergey.Antonyuk, so, you are killing CREATE TABLE for CONNECT engine which take longer than 2 minutes. Do you think why the procedure was set up to begin with – why CREATE takes so long, and what kind of CONNECT tables are being created?
When the crash happens, are there likely to be such queries in the processlist?

Comment by Sergey Antonyuk [ 2017-05-12 ]

elenst, the problem is not in killing connect engine specific queries but is in the cursor code (I look at the segfault stack trace).

Comment by Egor Karavaev (Inactive) [ 2017-05-12 ]

Hi, I've looked into the problem in case it's something on our side and I've traced it to mysql_mutex_lock(&tmp->LOCK_thd_data); at sql_show.cc : 2906, which is an inline function which expands to pthread_mutex_lock, which in turn causes the SIGSEGV we see in the stacktrace. It looks like tmp->LOCK_thd_data doesn't hold a valid pthread_t value at this point for some reason.

Comment by Elena Stepanova [ 2022-07-26 ]

It appears we could never reproduce it on our side, but at least the mentioned code was changed in 10.3 by this commit:

commit 7891a713daf52b5afd7e423d83c6d80d788ab733
Author: Monty
Date:   Thu Dec 7 15:15:22 2017 +0200
 
    Don't wait too long in SHOW PROCESSLIST

Hopefully it resolved the issue.

Generated at Thu Feb 08 07:58:24 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.