[MDEV-13277] main.events_2 failed in buildbot (server crash) Created: 2017-07-09  Updated: 2023-11-29  Resolved: 2023-11-29

Status: Closed
Project: MariaDB Server
Component/s: Events, Tests
Affects Version/s: 10.1, 10.2
Fix Version/s: N/A

Type: Bug Priority: Major
Reporter: Elena Stepanova Assignee: Unassigned
Resolution: Won't Fix Votes: 0
Labels: None


 Description   

http://buildbot.askmonty.org/buildbot/builders/kvm-bintar-trusty-x86/builds/1823/steps/test/logs/stdio

main.events_2                            w2 [ fail ]
        Test ended at 2017-07-06 22:56:46
 
CURRENT_TEST: main.events_2
mysqltest: In included file "/usr/local/mariadb-10.2.7-linux-i686/mysql-test/include/wait_condition.inc": 
included from /usr/local/mariadb-10.2.7-linux-i686/mysql-test/t/events_2.test at line 77:
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 >
"ENABLE the scheduler and get a lock"
set global event_scheduler=on;
select get_lock("test_lock2", 20);
get_lock("test_lock2", 20)
1
"Create an event which tries to acquire a mutex. The event locks on the mutex"
create event закачка on schedule every 10 hour do select get_lock("test_lock2", 20);
"Should have only 2 processes: the scheduler and the locked event"
select /*2*/ user, host, db, command, state, info
from information_schema.processlist
where (info like "select get_lock%" OR user='event_scheduler')
order by info;
user	host	db	command	state	info
event_scheduler	localhost	NULL	Daemon	Waiting for next activation	NULL
root	localhost	events_test	Connect	User lock	select get_lock("test_lock2", 20)
"Release the mutex, the event worker should finish."
select release_lock("test_lock2");
release_lock("test_lock2")
1
drop event закачка;
 
More results from queries before failure can be found in /usr/local/mariadb-10.2.7-linux-i686/mysql-test/var/2/log/events_2.log
 
 
Server [mysqld.1 - pid: 17284, winpid: 17284, exit: 256] failed during test run
Server log from this test:
----------SERVER LOG START-----------
2017-07-06 22:56:44 2955328320 [Note] Event Scheduler: scheduler thread started with id 32
170706 22:56:45 [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.2.7-MariaDB-log
key_buffer_size=1048576
read_buffer_size=131072
max_used_connections=2
max_threads=153
thread_count=5
It is possible that mysqld could use up to 
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 61819 K  bytes of memory
Hope that's ok; if not, decrease some variables in the equation.
 
Thread pointer: 0xb0100508
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 = 0xb02ff2cc thread_stack 0x49000
/usr/local/mariadb-10.2.7-linux-i686/bin/mysqld(my_print_stacktrace+0x2d)[0xb72340fd]
/usr/local/mariadb-10.2.7-linux-i686/bin/mysqld(handle_fatal_signal+0x344)[0xb6c20a64]
[0xb6767400]
/lib/i386-linux-gnu/libc.so.6(+0x83c96)[0xb649dc96]
/usr/local/mariadb-10.2.7-linux-i686/bin/mysqld(_Z23fill_schema_processlistP3THDP10TABLE_LISTP4Item+0x258)[0xb6adeb48]
/usr/local/mariadb-10.2.7-linux-i686/bin/mysqld(_Z24get_schema_tables_resultP4JOIN23enum_schema_table_state+0x250)[0xb6ae8dc0]
/usr/local/mariadb-10.2.7-linux-i686/bin/mysqld(_ZN4JOIN10exec_innerEv+0x7e0)[0xb6acd3c0]
/usr/local/mariadb-10.2.7-linux-i686/bin/mysqld(_ZN4JOIN4execEv+0x39)[0xb6acd909]
/usr/local/mariadb-10.2.7-linux-i686/bin/mysqld(_Z12mysql_selectP3THDP10TABLE_LISTjR4ListI4ItemEPS4_jP8st_orderS9_S7_S9_yP13select_resultP18st_select_lex_unitP13st_select_lex+0x101)[0xb6acda41]
/usr/local/mariadb-10.2.7-linux-i686/bin/mysqld(_Z13handle_selectP3THDP3LEXP13select_resultm+0x293)[0xb6ace643]
/usr/local/mariadb-10.2.7-linux-i686/bin/mysqld(+0x2dfbf8)[0xb6a69bf8]
/usr/local/mariadb-10.2.7-linux-i686/bin/mysqld(_Z21mysql_execute_commandP3THD+0x79f9)[0xb6a77e89]
/usr/local/mariadb-10.2.7-linux-i686/bin/mysqld(_Z11mysql_parseP3THDPcjP12Parser_statebb+0x372)[0xb6a7cb72]
/usr/local/mariadb-10.2.7-linux-i686/bin/mysqld(_Z16dispatch_command19enum_server_commandP3THDPcjbb+0x3525)[0xb6a81265]
/usr/local/mariadb-10.2.7-linux-i686/bin/mysqld(_Z10do_commandP3THD+0x1b0)[0xb6a81cf0]
/usr/local/mariadb-10.2.7-linux-i686/bin/mysqld(_Z24do_handle_one_connectionP7CONNECT+0x1ee)[0xb6b5185e]
/usr/local/mariadb-10.2.7-linux-i686/bin/mysqld(handle_one_connection+0x49)[0xb6b51989]
/usr/local/mariadb-10.2.7-linux-i686/bin/mysqld(+0xa5f09d)[0xb71e909d]
/lib/i386-linux-gnu/libpthread.so.0(+0x6f70)[0xb6700f70]
/lib/i386-linux-gnu/libc.so.6(clone+0x5e)[0xb6506d7e]
 
Trying to get some variables.
Some pointers may be invalid and cause the dump to abort.
Query (0xb010c9b8): select count(*) = 0 from information_schema.processlist where info='select get_lock("test_lock2", 20)'
Connection ID (thread ID): 31
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=on,condition_pushdown_for_derived=on
 
The manual page at http://dev.mysql.com/doc/mysql/en/crashing.html contains
information that should help you find out what is causing the crash.
Writing a core file
----------SERVER LOG END-------------



 Comments   
Comment by Elena Stepanova [ 2017-11-10 ]

Logs are not available at the time

main.events_2                            w4 [ fail ]
        Test ended at 2017-09-29 13:09:51
 
CURRENT_TEST: main.events_2
mysqltest: In included file "/usr/share/mysql/mysql-test/include/wait_condition.inc": 
included from /usr/share/mysql/mysql-test/t/events_2.test at line 120:
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 >
"Should have only 2 processes: the scheduler and the locked event"
select /*3*/ user, host, db, command, state, info
from information_schema.processlist
where (info like "select get_lock%" OR user='event_scheduler')
order by info;
user	host	db	command	state	info
event_scheduler	localhost	NULL	Daemon	Waiting for next activation	NULL
root	localhost	events_test	Connect	User lock	select get_lock("test_lock2_1", 20)
set global event_scheduler=off;
"Should have only our process now:"
select /*4*/ user, host, db, command, state, info
from information_schema.processlist
where (info like "select get_lock%" OR user='event_scheduler')
order by info;
user	host	db	command	state	info
root	localhost	events_test	Connect	User lock	select get_lock("test_lock2_1", 20)
select release_lock("test_lock2_1");
release_lock("test_lock2_1")
1
drop event закачка21;
 
More results from queries before failure can be found in /run/shm/var/4/log/events_2.log
 
 
Server [mysqld.1 - pid: 22362, winpid: 22362, exit: 256] failed during test run
Server log from this test:
----------SERVER LOG START-----------
2017-09-29 13:09:47 140051904056064 [Note] Event Scheduler: scheduler thread started with id 33
2017-09-29 13:09:47 140051904359168 [Note] Event Scheduler: Killing the scheduler thread, thread id 33
2017-09-29 13:09:47 140051904359168 [Note] Event Scheduler: Waiting for the scheduler thread to reply
2017-09-29 13:09:47 140051904359168 [Note] Event Scheduler: Stopped
170929 13:09:47 [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.29-MariaDB-1~trusty
key_buffer_size=1048576
read_buffer_size=131072
max_used_connections=2
max_threads=153
thread_count=2
It is possible that mysqld could use up to 
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 62911 K  bytes of memory
Hope that's ok; if not, decrease some variables in the equation.
 
Thread pointer: 0x7f60597fa008
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 = 0x7f60600261c0 thread_stack 0x48400
/usr/sbin/mysqld(my_print_stacktrace+0x2e)[0x7f6060bb719e]
/usr/sbin/mysqld(handle_fatal_signal+0x305)[0x7f60606da8c5]
/lib/x86_64-linux-gnu/libpthread.so.0(+0x10330)[0x7f605ec24330]
/lib/x86_64-linux-gnu/libc.so.6(strlen+0x2a)[0x7f605e0c5dfa]
/usr/sbin/mysqld(_Z23fill_schema_processlistP3THDP10TABLE_LISTP4Item+0x25b)[0x7f60605bc15b]
/usr/sbin/mysqld(_Z24get_schema_tables_resultP4JOIN23enum_schema_table_state+0x28e)[0x7f60605c662e]
/usr/sbin/mysqld(_ZN4JOIN10exec_innerEv+0x6bd)[0x7f60605ab7ed]
/usr/sbin/mysqld(_ZN4JOIN4execEv+0x54)[0x7f60605adc84]
/usr/sbin/mysqld(_Z12mysql_selectP3THDPPP4ItemP10TABLE_LISTjR4ListIS1_ES2_jP8st_orderSB_S2_SB_yP13select_resultP18st_select_lex_unitP13st_select_lex+0x112)[0x7f60605aa302]
/usr/sbin/mysqld(_Z13handle_selectP3THDP3LEXP13select_resultm+0x255)[0x7f60605aae05]
/usr/sbin/mysqld(+0x3761be)[0x7f60604911be]
/usr/sbin/mysqld(_Z21mysql_execute_commandP3THD+0x6f7d)[0x7f6060555bcd]
/usr/sbin/mysqld(_Z11mysql_parseP3THDPcjP12Parser_state+0x321)[0x7f6060558611]
/usr/sbin/mysqld(_Z16dispatch_command19enum_server_commandP3THDPcj+0x2693)[0x7f606055be03]
/usr/sbin/mysqld(_Z10do_commandP3THD+0x136)[0x7f606055c686]
/usr/sbin/mysqld(_Z24do_handle_one_connectionP3THD+0x18a)[0x7f606062826a]
/usr/sbin/mysqld(handle_one_connection+0x40)[0x7f6060628410]
/usr/sbin/mysqld(+0x74cacd)[0x7f6060867acd]
/lib/x86_64-linux-gnu/libpthread.so.0(+0x8184)[0x7f605ec1c184]
/lib/x86_64-linux-gnu/libc.so.6(clone+0x6d)[0x7f605e13affd]
 
Trying to get some variables.
Some pointers may be invalid and cause the dump to abort.
Query (0x7f605594f020): select count(*) = 0 from information_schema.processlist where db='events_test' and command = 'Connect' and user=current_user()
Connection ID (thread ID): 32
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
 
The manual page at http://dev.mysql.com/doc/mysql/en/crashing.html contains
information that should help you find out what is causing the crash.
Writing a core file
----------SERVER LOG END-------------

Comment by Marko Mäkelä [ 2021-07-30 ]

I have no idea if it could be related to the crash, but I observed a nondeterministic result difference:

bb-10.6-MDEV-24258 a8642ba0072bc018c966dfa376de7c0190b23cd5

CURRENT_TEST: main.events_2
--- /mnt/buildbot/build/mariadb-10.6.4/mysql-test/main/events_2.result	2021-07-30 06:44:19.000000000 -0400
+++ /mnt/buildbot/build/mariadb-10.6.4/mysql-test/main/events_2.reject	2021-07-30 08:43:17.144727409 -0400
@@ -78,6 +78,7 @@
 order by info;
 user	host	db	command	state	info
 event_scheduler	localhost	NULL	Daemon	Waiting for next activation	NULL
+event_scheduler	localhost	events_test	Connect	Starting cleanup	CREATE PROCEDURE `закачка`() SQL SECURITY INVOKER select get_lock("test_lock2", 20)
 root	localhost	events_test	Connect	User lock	select get_lock("test_lock2_1", 20)
 set global event_scheduler=off;
 "Should have only our process now:"

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