[MDEV-12892] Server crashed in fill_schema_processlist, main.events_bugs failed in buildbot Created: 2017-05-24  Updated: 2022-01-08  Resolved: 2022-01-07

Status: Closed
Project: MariaDB Server
Component/s: Admin statements, Tests
Affects Version/s: 10.0, 10.1, 10.4.17
Fix Version/s: N/A

Type: Bug Priority: Major
Reporter: Elena Stepanova Assignee: Unassigned
Resolution: Cannot Reproduce Votes: 0
Labels: None


 Description   

One-time occurrence so far:
http://buildbot.askmonty.org/buildbot/builders/kvm-deb-trusty-amd64/builds/5685/steps/mtr/logs/stdio

main.events_bugs                         w4 [ fail ]
 
        Test ended at 2017-05-02 06:21:06
 
 
 
CURRENT_TEST: main.events_bugs
 
mysqltest: In included file "/usr/share/mysql/mysql-test/include/wait_condition.inc": 
included from /usr/share/mysql/mysql-test/t/events_bugs.test at line 442:
 
At line 43: query 'let $success= `$wait_condition`' failed with wrong errno 2013: 'Lost connection to MySQL server during query', instead of 0...
 
 
 
The result from queries just before the failure was:
 
< snip >
 
begin
 
select get_lock('ee_16407_5', 60); /*ee_16407_5*/
 
select release_lock('ee_16407_5');
 
call events_test.ee_16407_5_pendant();
 
end|
 
create event ee_16407_6 on schedule every 60 second do
 
begin
 
select get_lock('ee_16407_5', 60); /*ee_16407_6*/
 
select release_lock('ee_16407_5');
 
call events_test.ee_16407_6_pendant();
 
end|
 
"Should have 2 locked processes"
 
select /*4*/ user, host, db, info from information_schema.processlist
 
where state = 'User lock' and info = 'select get_lock(\'ee_16407_5\', 60)';
 
user	host	db	info
 
root	localhost	events_test	select get_lock('ee_16407_5', 60)
 
root	localhost	events_test	select get_lock('ee_16407_5', 60)
 
select release_lock('ee_16407_5');
 
release_lock('ee_16407_5')
 
1


2017-05-02  6:21:02 140122195761088 [Note] Server socket created on IP: '127.0.0.1'.
 
2017-05-02  6:21:02 140122195446528 [Note] Event Scheduler: scheduler thread started with id 1
 
2017-05-02  6:21:02 140122195761088 [Note] /usr/sbin/mysqld: ready for connections.
 
Version: '10.1.23-MariaDB-1~trusty'  socket: '/run/shm/var/tmp/4/mysqld.1.sock'  port: 16040  mariadb.org binary distribution
 
2017-05-02  6:21:03 140122194840320 [Note] Event Scheduler: Killing the scheduler thread, thread id 1
 
2017-05-02  6:21:03 140122194840320 [Note] Event Scheduler: Waiting for the scheduler thread to reply
 
2017-05-02  6:21:03 140122194840320 [Note] Event Scheduler: Stopped
 
2017-05-02  6:21:03 140122195446528 [Note] Event Scheduler: scheduler thread started with id 5
 
2017-05-02  6:21:03 140122194840320 [Note] Event Scheduler: Killing the scheduler thread, thread id 5
 
2017-05-02  6:21:03 140122194840320 [Note] Event Scheduler: Waiting for the scheduler thread to reply
 
2017-05-02  6:21:03 140122194840320 [Note] Event Scheduler: Stopped
 
2017-05-02  6:21:03 140122195446528 [Note] Event Scheduler: scheduler thread started with id 7
 
2017-05-02  6:21:03 140122194537216 [ERROR] Event Scheduler: [root@localhost][events_test.ee_16407_2] Incorrect date value: '1980-19-02' for column 'a' at row 1
 
2017-05-02  6:21:03 140122194537216 [Note] Event Scheduler: [root@localhost].[events_test.ee_16407_2] event execution failed.
 
2017-05-02  6:21:03 140122157058816 [Warning] Event Scheduler: [root@localhost][events_test.ee_16407_4] Data truncated for column 'a' at row 1
 
2017-05-02  6:21:03 140122194840320 [Note] Event Scheduler: Killing the scheduler thread, thread id 7
 
2017-05-02  6:21:03 140122194840320 [Note] Event Scheduler: Waiting for the scheduler thread to reply
 
2017-05-02  6:21:03 140122194840320 [Note] Event Scheduler: Stopped
 
2017-05-02  6:21:03 140122195446528 [Note] Event Scheduler: scheduler thread started with id 11
 
2017-05-02  6:21:03 140122157058816 [ERROR] Event Scheduler: [root@localhost][events_test.ee_16407_5] Incorrect date value: '2001-02-29' for column 'a' at row 1
 
2017-05-02  6:21:03 140122157058816 [Note] Event Scheduler: [root@localhost].[events_test.ee_16407_5] event execution failed.
 
170502  6:21:03 [ERROR] 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.
 
 
 
To report this bug, see https://mariadb.com/kb/en/reporting-bugs
 
 
 
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.
 
 
 
Server version: 10.1.23-MariaDB-1~trusty
 
key_buffer_size=1048576
 
read_buffer_size=131072
 
max_used_connections=1
 
max_threads=153
 
thread_count=3
 
It is possible that mysqld could use up to 
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 62897 K  bytes of memory
 
Hope that's ok; if not, decrease some variables in the equation.
 
 
 
Thread pointer: 0x7f70b6ffa008
 
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...
 
stack_bottom = 0x7f70bda601c0 thread_stack 0x48400
 
/usr/sbin/mysqld(my_print_stacktrace+0x2e)[0x7f70be5e8efe]
 
/usr/sbin/mysqld(handle_fatal_signal+0x305)[0x7f70be10bf95]
 
/lib/x86_64-linux-gnu/libpthread.so.0(+0x10330)[0x7f70bc65e330]
 
/lib/x86_64-linux-gnu/libc.so.6(strlen+0x2a)[0x7f70bbb009ea]
 
/usr/sbin/mysqld(_Z23fill_schema_processlistP3THDP10TABLE_LISTP4Item+0x25b)[0x7f70bdff084b]
 
/usr/sbin/mysqld(_Z24get_schema_tables_resultP4JOIN23enum_schema_table_state+0x28e)[0x7f70bdffa4fe]
 
/usr/sbin/mysqld(_ZN4JOIN10exec_innerEv+0x6bd)[0x7f70bdfe07dd]
 
/usr/sbin/mysqld(_ZN4JOIN4execEv+0x54)[0x7f70bdfe2c64]
 
/usr/sbin/mysqld(_Z12mysql_selectP3THDPPP4ItemP10TABLE_LISTjR4ListIS1_ES2_jP8st_orderSB_S2_SB_yP13select_resultP18st_select_lex_unitP13st_select_lex+0x112)[0x7f70bdfdf312]
 
/usr/sbin/mysqld(_Z13handle_selectP3THDP3LEXP13select_resultm+0x245)[0x7f70bdfdfdf5]
 
/usr/sbin/mysqld(+0x42a2d1)[0x7f70bdf7f2d1]
 
/usr/sbin/mysqld(_Z21mysql_execute_commandP3THD+0x5f46)[0x7f70bdf8b9f6]
 
/usr/sbin/mysqld(_Z11mysql_parseP3THDPcjP12Parser_state+0x311)[0x7f70bdf8ee41]
 
/usr/sbin/mysqld(_Z16dispatch_command19enum_server_commandP3THDPcj+0x2450)[0x7f70bdf92170]
 
/usr/sbin/mysqld(_Z10do_commandP3THD+0x14a)[0x7f70bdf9290a]
 
/usr/sbin/mysqld(_Z24do_handle_one_connectionP3THD+0x18a)[0x7f70be05a81a]
 
/usr/sbin/mysqld(handle_one_connection+0x40)[0x7f70be05a9c0]
 
/usr/sbin/mysqld(+0x741a7d)[0x7f70be296a7d]
 
/lib/x86_64-linux-gnu/libpthread.so.0(+0x8184)[0x7f70bc656184]
 
/lib/x86_64-linux-gnu/libc.so.6(clone+0x6d)[0x7f70bbb75bed]
 
 
 
Trying to get some variables.
 
Some pointers may be invalid and cause the dump to abort.
 
Query (0x7f70b2d05020): select count(*) = 0 from information_schema.processlist where state = 'User lock' and info = 'select get_lock(\'ee_16407_5\', 60)'
 
Connection ID (thread ID): 4
 
Status: NOT_KILLED
 
 
 
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



 Comments   
Comment by Elena Stepanova [ 2018-06-25 ]

New occurrence:
http://buildbot.askmonty.org/buildbot/builders/kvm-deb-stretch-amd64/builds/4099/steps/mtr/logs/stdio

Comment by Pramod Mahto [ 2021-11-25 ]

elenst Similar crash reported for 10..4.17 

 
 
2021-11-24 23:02:20 0 [Note] InnoDB: Using Linux native AIO
 
2021-11-24 23:02:20 0 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
 
2021-11-24 23:02:20 0 [Note] InnoDB: Uses event mutexes
 
2021-11-24 23:02:20 0 [Note] InnoDB: Compressed tables use zlib 1.2.3
 
2021-11-24 23:02:20 0 [Note] InnoDB: Number of pools: 1
 
2021-11-24 23:02:20 0 [Note] InnoDB: Using SSE2 crc32 instructions
 
2021-11-24 23:02:20 0 [Note] InnoDB: Initializing buffer pool, total size = 35G, instances = 8, chunk size = 128M
 
2021-11-24 23:02:21 0 [Note] InnoDB: Completed initialization of buffer pool
 
2021-11-24 23:02:21 0 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().
 
2021-11-24 23:02:22 0 [Note] InnoDB: 128 out of 128 rollback segments are active.
 
2021-11-24 23:02:22 0 [Note] InnoDB: Creating shared tablespace for temporary tables
 
2021-11-24 23:02:22 0 [Note] InnoDB: Setting file '/mysql_data/mysql_products_3104/ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
 
2021-11-24 23:02:23 0 [Note] InnoDB: File '/mysql_data/mysql_products_3104/ibtmp1' size is now 12 MB.
 
2021-11-24 23:02:23 0 [Note] InnoDB: Waiting for purge to start
 
2021-11-24 23:02:23 0 [Note] InnoDB: 10.4.17 started; log sequence number 238154968012824; transaction id 7148535994
 
2021-11-24 23:02:23 0 [Note] InnoDB: Loading buffer pool(s) from /mysql_data/mysql_products_3104/ib_buffer_pool
 
2021-11-24 23:02:23 0 [Note] Plugin 'FEEDBACK' is disabled.
 
2021-11-24 23:02:23 server_audit: MariaDB Audit Plugin version 2.0.3 STARTED.
 
2021-11-24 23:02:23 server_audit: logging started to the file /data/mysql/logs/server_audit_3104.log.
 
2021-11-24 23:02:23 0 [Note] Server socket created on IP: '::'.
 
2021-11-24 23:02:23 7 [Note] Event Scheduler: scheduler thread started with id 7
 
2021-11-24 23:02:23 0 [Note] /data/mysql/bin/mysqld: ready for connections.
 
Version: '10.4.17-10-MariaDB-enterprise-log'  socket: '/data/mysql/socket/products_3104.sock'  port: 3104  MariaDB Enterprise Server
 
2021-11-24 23:02:30 0 [Note] InnoDB: Buffer pool(s) load completed at 211124 23:02:30
 
2021-11-24 23:03:00 4175 [ERROR] Event Scheduler: [DBO@%][dba_no_repl.processlist_logging] Column count doesn't match value count at row 1
 
2021-11-24 23:03:00 4175 [Note] Event Scheduler: [DBO@%][dba_no_repl.processlist_logging] At line 9 in dba_no_repl.processlist_logging
 
2021-11-24 23:03:00 4175 [Note] Event Scheduler: [DBO@%].[dba_no_repl.processlist_logging] event execution failed.
 
2021-11-24 23:03:05 4842 [Warning] IP address '10.31.240.18' could not be resolved: Name or service not known
 
2021-11-24 23:04:00 11086 [ERROR] Event Scheduler: [DBO@%][dba_no_repl.processlist_logging] Column count doesn't match value count at row 1
 
2021-11-24 23:04:00 11086 [Note] Event Scheduler: [DBO@%][dba_no_repl.processlist_logging] At line 9 in dba_no_repl.processlist_logging
 
2021-11-24 23:04:00 11086 [Note] Event Scheduler: [DBO@%].[dba_no_repl.processlist_logging] event execution failed.
 
211124 23:31:00 [ERROR] 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.
 
 
 
To report this bug, see https://mariadb.com/kb/en/reporting-bugs
 
 
 
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.
 
 
 
Server version: 10.4.17-10-MariaDB-enterprise-log
 
key_buffer_size=33554432
 
read_buffer_size=262144
 
max_used_connections=134
 
max_threads=1002
 
thread_count=143
 
It is possible that mysqld could use up to 
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 827086 K  bytes of memory
 
Hope that's ok; if not, decrease some variables in the equation.
 
 
 
Thread pointer: 0x7f8dc0001248
 
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...
 
stack_bottom = 0x7f8dde1c1c5f thread_stack 0x49000
 
/data/mysql/bin/mysqld(my_print_stacktrace+0x2e)[0x7f9785b57f0e]
 
/data/mysql/bin/mysqld(handle_fatal_signal+0x307)[0x7f97855bd247]
 
/lib64/libpthread.so.0(+0x334ea0f710)[0x7f97848ae710]
 
/lib64/libc.so.6(memcpy+0xa0)[0x7f9782d10710]
 
/data/mysql/bin/mysqld(+0xd57374)[0x7f9785a35374]
 
/data/mysql/bin/mysqld(+0xd593a0)[0x7f9785a373a0]
 
/data/mysql/bin/mysqld(+0xd65bcd)[0x7f9785a43bcd]
 
/data/mysql/bin/mysqld(_Z25schema_table_store_recordP3THDP5TABLE+0x1d7)[0x7f9785408987]
 
/data/mysql/bin/mysqld(_Z23fill_schema_processlistP3THDP10TABLE_LISTP4Item+0x549)[0x7f97854096d9]
 
/data/mysql/bin/mysqld(_Z24get_schema_tables_resultP4JOIN23enum_schema_table_state+0x2bc)[0x7f97854137dc]
 
/data/mysql/bin/mysqld(_ZN4JOIN10exec_innerEv+0xa4d)[0x7f97853fa51d]
 
/data/mysql/bin/mysqld(_ZN4JOIN4execEv+0x33)[0x7f97853fab23]
 
/data/mysql/bin/mysqld(_Z12mysql_selectP3THDP10TABLE_LISTjR4ListI4ItemEPS4_jP8st_orderS9_S7_S9_yP13select_resultP18st_select_lex_unitP13st_select_lex+0x186)[0x7f97853f8bd6]
 
/data/mysql/bin/mysqld(_Z13handle_selectP3THDP3LEXP13select_resultm+0xf6)[0x7f97853f9606]
 
/data/mysql/bin/mysqld(_Z21mysql_execute_commandP3THD+0x6f3c)[0x7f978539923c]
 
/data/mysql/bin/mysqld(_ZN13sp_instr_stmt9exec_coreEP3THDPj+0x15)[0x7f97852f4155]
 
/data/mysql/bin/mysqld(_ZN13sp_lex_keeper23reset_lex_and_exec_coreEP3THDPjbP8sp_instr+0x231)[0x7f97852fc3e1]
 
/data/mysql/bin/mysqld(_ZN13sp_instr_stmt7executeEP3THDPj+0x493)[0x7f97852fcb93]
 
/data/mysql/bin/mysqld(_ZN7sp_head7executeEP3THDb+0x997)[0x7f97852f7ee7]
 
/data/mysql/bin/mysqld(_ZN7sp_head17execute_procedureEP3THDP4ListI4ItemE+0x799)[0x7f97852f9579]
 
/data/mysql/bin/mysqld(_ZN14Event_job_data7executeEP3THDb+0x9fb)[0x7f978547556b]
 
/data/mysql/bin/mysqld(_ZN19Event_worker_thread3runEP3THDP28Event_queue_element_for_exec+0xc9)[0x7f978571b019]
 
/data/mysql/bin/mysqld(event_worker_thread+0x4d)[0x7f978571b0cd]
 
/data/mysql/bin/mysqld(+0xe22531)[0x7f9785b00531]
 
/lib64/libpthread.so.0(+0x334ea079d1)[0x7f97848a69d1]
 
/lib64/libc.so.6(clone+0x6d)[0x7f9782d6f8fd]
 
 
 
Trying to get some variables.
 
Some pointers may be invalid and cause the dump to abort.
 
Query (0x7f8ab80068c0): INSERT INTO dba_no_repl.processlist
 
SELECT NOW(),p.*
 
FROM information_schema.processlist p
 
WHERE (COMMAND = 'Sleep' AND TIME < 5)
 
OR COMMAND NOT IN ('Sleep','Daemon','Binlog Dump')
 
AND STATE NOT LIKE 'Waiting for master to send event%'
 
AND STATE NOT LIKE 'Waiting for work from SQL thread%'
 
AND STATE NOT LIKE 'Slave has read all relay log%'
 
AND ID <> CONNECTION_ID()

Generated at Thu Feb 08 08:01:18 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.