[MDEV-10679] Server crashes in in mysql_create_frm_image upon query from performance schema in ps-protocol mode Created: 2016-08-27  Updated: 2018-05-26  Resolved: 2018-05-26

Status: Closed
Project: MariaDB Server
Component/s: Admin statements, Server
Affects Version/s: 10.1, 10.2, 10.3
Fix Version/s: 10.1.34, 10.2.16, 10.3.8

Type: Bug Priority: Major
Reporter: Elena Stepanova Assignee: Michael Widenius
Resolution: Fixed Votes: 0
Labels: None

Issue Links:
Relates
relates to MDEV-7069 Fix buildbot failures in main server ... Stalled

 Description   

Run with --ps-protocol:

--source include/have_perfschema.inc
 
CREATE TABLE t1 (i INT);
--error ER_PARTITION_MGMT_ON_NONPARTITIONED
ALTER TABLE t1 ADD PARTITION (PARTITION p VALUES LESS THAN (1));
SELECT * FROM performance_schema.events_stages_summary_by_user_by_event_name;
 
# Cleanup
DROP TABLE t1;

10.1 debug 2bf355fa812

#3  <signal handler called>
#4  0x0000558e85098cea in base_list_iterator::next (this=0x7f7648e16d00) at /data/src/10.1/sql/sql_list.h:451
#5  0x0000558e851ae8f9 in List_iterator<partition_element>::operator++ (this=0x7f7648e16d00) at /data/src/10.1/sql/sql_list.h:551
#6  0x0000558e851c66ea in mysql_create_frm_image (thd=0x7f763fcd5070, db=0x7f763e068358 "performance_schema", table_name=0x7f763e06836b "events_stages_summary_by_user_by_event_name", create_info=0x7f7648e17ef8, alter_info=0x7f7648e182b8, create_table_mode=0, key_info=0x7f7648e16db8, key_count=0x7f7648e16db4, frm=0x7f7648e16e00) at /data/src/10.1/sql/sql_table.cc:4464
#7  0x0000558e851fa1a8 in TABLE_SHARE::init_from_sql_statement_string (this=0x7f763e067e88, thd=0x7f763fcd5070, write=false, sql=0x558e85b76560 "CREATE TABLE events_stages_summary_by_user_by_event_name(USER CHAR(16) collate utf8_bin default null,EVENT_NAME VARCHAR(128) not null,COUNT_STAR BIGINT unsigned not null,SUM_TIMER_WAIT BIGINT unsigned"..., sql_length=330) at /data/src/10.1/sql/table.cc:2243
#8  0x0000558e855c6e52 in pfs_discover_table (hton=0x7f76464371f0, thd=0x7f763fcd5070, share=0x7f763e067e88) at /data/src/10.1/storage/perfschema/ha_perfschema.cc:81
#9  0x0000558e8535184f in discover_handlerton (thd=0x7f763fcd5070, plugin=0x7f763e020570, arg=0x7f763e067e88) at /data/src/10.1/sql/handler.cc:4887
#10 0x0000558e8512435a in plugin_foreach_with_mask (thd=0x7f763fcd5070, func=0x558e853517d6 <discover_handlerton(THD*, plugin_ref, void*)>, type=1, state_mask=8, arg=0x7f763e067e88) at /data/src/10.1/sql/sql_plugin.cc:2375
#11 0x0000558e85351a43 in ha_discover_table (thd=0x7f763fcd5070, share=0x7f763e067e88) at /data/src/10.1/sql/handler.cc:4931
#12 0x0000558e851f4a30 in open_table_def (thd=0x7f763fcd5070, share=0x7f763e067e88, flags=11) at /data/src/10.1/sql/table.cc:584
#13 0x0000558e852cee3f in tdc_acquire_share (thd=0x7f763fcd5070, db=0x7f763e0fd7c0 "performance_schema", table_name=0x7f763e0fd7d8 "events_stages_summary_by_user_by_event_name", key=0x7f763e0fdcb1 "performance_schema", key_length=63, hash_value=1906063503, flags=3, out_table=0x7f7648e18b08) at /data/src/10.1/sql/table_cache.cc:639
#14 0x0000558e850a1185 in open_table (thd=0x7f763fcd5070, table_list=0x7f763e0fd860, ot_ctx=0x7f7648e18f40) at /data/src/10.1/sql/sql_base.cc:2414
#15 0x0000558e850a3ebf in open_and_process_table (thd=0x7f763fcd5070, lex=0x7f763e0fc088, tables=0x7f763e0fd860, counter=0x7f7648e1900c, flags=512, prelocking_strategy=0x7f7648e19010, has_prelocking_list=false, ot_ctx=0x7f7648e18f40) at /data/src/10.1/sql/sql_base.cc:4068
#16 0x0000558e850a4f3a in open_tables (thd=0x7f763fcd5070, options=..., start=0x7f7648e18ff0, counter=0x7f7648e1900c, flags=512, prelocking_strategy=0x7f7648e19010) at /data/src/10.1/sql/sql_base.cc:4579
#17 0x0000558e8509c938 in open_tables (thd=0x7f763fcd5070, tables=0x7f7648e18ff0, counter=0x7f7648e1900c, flags=512, prelocking_strategy=0x7f7648e19010) at /data/src/10.1/sql/sql_base.h:252
#18 0x0000558e850a6478 in open_normal_and_derived_tables (thd=0x7f763fcd5070, tables=0x7f763e0fd860, flags=512, dt_phases=34) at /data/src/10.1/sql/sql_base.cc:5322
#19 0x0000558e8512be7c in mysql_test_select (stmt=0x7f763e196470, tables=0x7f763e0fd860) at /data/src/10.1/sql/sql_prepare.cc:1517
#20 0x0000558e8512d62a in check_prepared_statement (stmt=0x7f763e196470) at /data/src/10.1/sql/sql_prepare.cc:2312
#21 0x0000558e8513059f in Prepared_statement::prepare (this=0x7f763e196470, packet=0x7f76427f9071 "SELECT * FROM performance_schema.events_stages_summary_by_user_by_event_name", packet_len=76) at /data/src/10.1/sql/sql_prepare.cc:3710
#22 0x0000558e8512dc59 in mysqld_stmt_prepare (thd=0x7f763fcd5070, packet=0x7f76427f9071 "SELECT * FROM performance_schema.events_stages_summary_by_user_by_event_name", packet_length=76) at /data/src/10.1/sql/sql_prepare.cc:2571
#23 0x0000558e85106247 in dispatch_command (command=COM_STMT_PREPARE, thd=0x7f763fcd5070, packet=0x7f76427f9071 "SELECT * FROM performance_schema.events_stages_summary_by_user_by_event_name", packet_length=76) at /data/src/10.1/sql/sql_parse.cc:1450
#24 0x0000558e851052ad in do_command (thd=0x7f763fcd5070) at /data/src/10.1/sql/sql_parse.cc:1120
#25 0x0000558e8523e135 in do_handle_one_connection (thd_arg=0x7f763fcd5070) at /data/src/10.1/sql/sql_connect.cc:1330
#26 0x0000558e8523de99 in handle_one_connection (arg=0x7f763fcd5070) at /data/src/10.1/sql/sql_connect.cc:1242
#27 0x0000558e855f938c in pfs_spawn_thread (arg=0x7f7646439ef0) at /data/src/10.1/storage/perfschema/pfs.cc:1861
#28 0x00007f7648a99494 in start_thread (arg=0x7f7648e1ab00) at pthread_create.c:333
#29 0x00007f7646e5293f in clone () from /lib/x86_64-linux-gnu/libc.so.6

10.1 non-debug 0b74a1fa64

#2  <signal handler called>
#3  0x000055eae57b9373 in partition_info::check_partition_info (this=0x7f2a6cd570b8, thd=0x7f2a713e9008, eng_type=0x7f2a77bf3330, file=0x7f2a6cd76d88, info=0x7f2a77bf4518, add_or_reorg_part=false) at /data/src/10.1/sql/partition_info.cc:1670
#4  0x000055eae5781328 in mysql_create_frm_image (thd=0x7f2a713e9008, db=0x361 <error: Cannot access memory at address 0x361>, table_name=0x0, create_info=0x0, alter_info=0x0, create_table_mode=create_table_mode@entry=0, key_info=0x7f2a77bf3418, key_count=0x7f2a77bf3414, frm=0x7f2a77bf3420) at /data/src/10.1/sql/sql_table.cc:4532
#5  0x000055eae57a0f9c in TABLE_SHARE::init_from_sql_statement_string (this=0x7f2a6cc5fd20, thd=0x7f2a713e9008, write=<optimized out>, sql=<optimized out>, sql_length=<optimized out>) at /data/src/10.1/sql/table.cc:2243
#6  0x000055eae5874258 in discover_handlerton (thd=thd@entry=0x7f2a713e9008, plugin=0x7f2a70bf6790, arg=arg@entry=0x7f2a6cc5fd20) at /data/src/10.1/sql/handler.cc:4887
#7  0x000055eae571031e in plugin_foreach_with_mask (thd=0x7f2a713e9008, func=func@entry=0x55eae5874220 <discover_handlerton(THD*, plugin_ref, void*)>, type=type@entry=1, state_mask=state_mask@entry=8, arg=arg@entry=0x7f2a6cc5fd20) at /data/src/10.1/sql/sql_plugin.cc:2375
#8  0x000055eae587c629 in ha_discover_table (thd=thd@entry=0x7f2a713e9008, share=share@entry=0x7f2a6cc5fd20) at /data/src/10.1/sql/handler.cc:4931
#9  0x000055eae57a11a8 in open_table_def (thd=thd@entry=0x7f2a713e9008, share=share@entry=0x7f2a6cc5fd20, flags=flags@entry=11) at /data/src/10.1/sql/table.cc:584
#10 0x000055eae582b079 in tdc_acquire_share (thd=0x7f2a713e9008, db=<optimized out>, table_name=<optimized out>, key=<optimized out>, key_length=<optimized out>, hash_value=<optimized out>, flags=3, out_table=0x7f2a77bf52b0) at /data/src/10.1/sql/table_cache.cc:639
#11 0x000055eae56c0352 in open_table (thd=0x7f2a713e9008, table_list=0x7f2a6cd757f8, ot_ctx=0x7f2a77bf5920) at /data/src/10.1/sql/sql_base.cc:2414
#12 0x000055eae56c4527 in open_and_process_table (ot_ctx=0x7f2a77bf5920, has_prelocking_list=false, prelocking_strategy=0x7f2a77bf59c0, flags=512, counter=0x7f2a77bf59bc, tables=0x7f2a6cd757f8, lex=0x7f2a6cd74020, thd=0x7f2a713e9008) at /data/src/10.1/sql/sql_base.cc:4068
#13 open_tables (thd=thd@entry=0x7f2a713e9008, options=..., start=start@entry=0x7f2a77bf59a8, counter=counter@entry=0x7f2a77bf59bc, flags=512, prelocking_strategy=prelocking_strategy@entry=0x7f2a77bf59c0) at /data/src/10.1/sql/sql_base.cc:4579
#14 0x000055eae56c4daa in open_tables (prelocking_strategy=0x7f2a77bf59c0, flags=<optimized out>, counter=0x7f2a77bf59bc, tables=0x7f2a77bf59a8, thd=0x7f2a713e9008) at /data/src/10.1/sql/sql_base.h:252
#15 open_normal_and_derived_tables (thd=0x7f2a713e9008, tables=0x7f2a6cd757f8, flags=<optimized out>, dt_phases=34) at /data/src/10.1/sql/sql_base.cc:5322
#16 0x000055eae57166cb in mysql_test_select (tables=<optimized out>, stmt=<optimized out>) at /data/src/10.1/sql/sql_prepare.cc:1517
#17 check_prepared_statement (stmt=<optimized out>) at /data/src/10.1/sql/sql_prepare.cc:2312
#18 Prepared_statement::prepare (this=0x7f2a6cdae288, packet=0x7f2a77bf5b50 "", packet_len=1899925536) at /data/src/10.1/sql/sql_prepare.cc:3710
#19 0x000055eae57178d4 in mysqld_stmt_prepare (thd=0x7f2a713e9008, packet=0x7f2a6eb8c009 "SELECT * FROM performance_schema.events_stages_summary_by_user_by_event_name", packet_length=76) at /data/src/10.1/sql/sql_prepare.cc:2571
#20 0x000055eae570a1de in dispatch_command (command=command@entry=COM_STMT_PREPARE, thd=thd@entry=0x7f2a713e9008, packet=packet@entry=0x7f2a6eb8c009 "SELECT * FROM performance_schema.events_stages_summary_by_user_by_event_name", packet_length=packet_length@entry=76) at /data/src/10.1/sql/sql_parse.cc:1445
#21 0x000055eae570b6aa in do_command (thd=0x7f2a713e9008) at /data/src/10.1/sql/sql_parse.cc:1115
#22 0x000055eae57c89dc in do_handle_one_connection (thd_arg=thd_arg@entry=0x7f2a713e9008) at /data/src/10.1/sql/sql_connect.cc:1330
#23 0x000055eae57c8b97 in handle_one_connection (arg=arg@entry=0x7f2a713e9008) at /data/src/10.1/sql/sql_connect.cc:1242
#24 0x000055eae5a42184 in pfs_spawn_thread (arg=0x7f2a7503ea08) at /data/src/10.1/storage/perfschema/pfs.cc:1861
#25 0x00007f2a77876494 in start_thread (arg=0x7f2a77bf7b00) at pthread_create.c:333
#26 0x00007f2a75c2f93f in clone () from /lib/x86_64-linux-gnu/libc.so.6

We also have a very rare buildbot failure with a similar stack trace, also upon a query from perfschema with ps-protocol:

perfschema.setup_actors                  w3 [ fail ]
        Test ended at 2016-06-19 23:38:24
 
CURRENT_TEST: perfschema.setup_actors
mysqltest: At line 53: query 'select NAME, TYPE, INSTRUMENTED, PROCESSLIST_USER, PROCESSLIST_HOST
from performance_schema.threads
where PROCESSLIST_ID = connection_id()' failed: 2013: Lost connection to MySQL server during query
 
The result from queries just before the failure was:
< snip >
HOST	USER	ROLE
hostb	%	%
hosta	user1	%
%	user2	%
localhost	user3	%
create user user1@localhost;
grant ALL on *.* to user1@localhost;
create user user2@localhost;
grant ALL on *.* to user2@localhost;
create user user3@localhost;
grant ALL on *.* to user3@localhost;
create user user4@localhost;
grant ALL on *.* to user4@localhost;
create user user5@localhost;
grant select on test.* to user5@localhost;
flush privileges;
# Switch to (con1, localhost, user1, , )
select NAME, TYPE, INSTRUMENTED, PROCESSLIST_USER, PROCESSLIST_HOST
from performance_schema.threads
where PROCESSLIST_ID = connection_id();
 
More results from queries before failure can be found in /mnt/buildbot/build/mariadb-10.1.15/mysql-test/var/3/log/setup_actors.log
 
 
Server [mysqld.1 - pid: 6521, winpid: 6521, exit: 256] failed during test run
Server log from this test:
----------SERVER LOG START-----------
160619 23:38:23 [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.15-MariaDB-debug
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 = 61813 K  bytes of memory
Hope that's ok; if not, decrease some variables in the equation.
 
Thread pointer: 0x0xbb65310
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 = 0xb178069c thread_stack 0x48400
/mnt/buildbot/build/mariadb-10.1.15/sql/mysqld(my_print_stacktrace+0x29)[0x8b0b2e9]
/mnt/buildbot/build/mariadb-10.1.15/sql/mysqld(handle_fatal_signal+0x53c)[0x8438f5c]
[0xb777c400]
/mnt/buildbot/build/mariadb-10.1.15/sql/mysqld(_Z22mysql_create_frm_imageP3THDPKcS2_P14HA_CREATE_INFOP10Alter_infoiPP6st_keyPjP34st_mysql_const_unsigned_lex_string+0xf4)[0x82f8e14]
/mnt/buildbot/build/mariadb-10.1.15/sql/mysqld(_ZN11TABLE_SHARE30init_from_sql_statement_stringEP3THDbPKcj+0x831)[0x83221c1]
/mnt/buildbot/build/mariadb-10.1.15/sql/mysqld[0x85df5dc]
/mnt/buildbot/build/mariadb-10.1.15/sql/mysqld[0x8439a42]
/mnt/buildbot/build/mariadb-10.1.15/sql/mysqld(_Z24plugin_foreach_with_maskP3THDPFcS0_PP13st_plugin_intPvEijS4_+0x261)[0x826cec1]
/mnt/buildbot/build/mariadb-10.1.15/sql/mysqld(_Z17ha_discover_tableP3THDP11TABLE_SHARE+0x10a)[0x8445c0a]
/mnt/buildbot/build/mariadb-10.1.15/sql/mysqld(_Z14open_table_defP3THDP11TABLE_SHAREj+0x460)[0x8322730]
mysys/stacktrace.c:246(my_print_stacktrace)[0x83d4852]
sql/signal_handler.cc:160(handle_fatal_signal)[0x81fab85]
sql/table.cc:2205(TABLE_SHARE::init_from_sql_statement_string(THD*, bool, char const*, unsigned int))[0x8200450]
sql/handler.cc:4846(discover_handlerton)[0x8200c40]
sql/sql_base.cc:2426(open_table(THD*, TABLE_LIST*, Open_table_context*))[0x8277062]
sql/sql_prepare.cc:1530(mysql_test_select)[0x8278054]
sql/sql_parse.cc:1241(dispatch_command(enum_server_command, THD*, char*, unsigned int))[0x826481f]
sql/sql_parse.cc:1109(do_command(THD*))[0x82668d2]
sql/sql_connect.cc:1350(do_handle_one_connection(THD*))[0x83596d0]
sql/sql_connect.cc:1264(handle_one_connection)[0x83598ff]
perfschema/pfs.cc:1863(pfs_spawn_thread)[0x861912a]
/lib/i386-linux-gnu/libpthread.so.0(+0x6d4c)[0xb7706d4c]
/lib/i386-linux-gnu/libc.so.6(clone+0x5e)[0xb7515ace]
 
Trying to get some variables.
Some pointers may be invalid and cause the dump to abort.
Query (0xb0f05618): select NAME, TYPE, INSTRUMENTED, PROCESSLIST_USER, PROCESSLIST_HOST from performance_schema.threads where PROCESSLIST_ID = connection_id()
Connection ID (thread ID): 567
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-------------
 
 
 - skipping '/mnt/buildbot/build/mariadb-10.1.15/mysql-test/var/3/log/perfschema.setup_actors/'
 
Retrying test perfschema.setup_actors, attempt(2/3)...
 
worker[3] > Restart  - not started
***Warnings generated in error logs during shutdown after running tests: perfschema.dml_performance_timers perfschema.ddl_ews_by_instance perfschema.ddl_esms_by_host_by_event_name perfschema.connection perfschema.ddl_fs_by_instance main.func_misc perfschema.ddl_socket_summary_by_event_name main.func_crypt perfschema.dml_setup_instruments perfschema.ddl_file_instances main.fulltext_left_join main.key main.func_default perfschema.ddl_esms_by_user_by_event_name perfschema.dml_accounts perfschema.ddl_accounts main.fulltext_order_by perfschema.dml_fs_by_instance main.func_math perfschema.ddl_rwlock_instances perfschema.ddl_events_statements_history_long perfschema.func_file_io perfschema.checksum main.gis perfschema.ddl_events_stages_current main.kill_processlist-6619 perfschema.dml_tlws_by_table main.fulltext_derived_4257 perfschema.csv_table_io main.func_sapdb perfschema.dml_esms_global_by_event_name perfschema.dml_host_cache main.insert_select main.join_nested perfschema.dml_ews_by_account_by_event_name perfschema.dml_ews_by_user_by_event_name perfschema.ddl_esms_by_account_by_event_name main.metadata main.func_time_hires main.func_encrypt_nossl perfschema.ddl_hosts perfschema.ddl_events_stages_history_long main.func_weight_string main.function_defaults_notembedded main.merge_debug perfschema.dml_events_waits_history main.join perfschema.dml_session_account_connect_attrs perfschema.dml_mutex_instances perfschema.dml_events_statements_history_long main.locale main.func_str main.mdev375 main.func_equal perfschema.dml_socket_summary_by_instance perfschema.dml_socket_instances perfschema.dml_esgs_global_by_event_name perfschema.connect_attrs main.func_date_add perfschema.dml_file_instances perfschema.dml_esms_by_thread_by_event_name perfschema.dml_tiws_by_index_usage main.func_concat perfschema.ddl_users perfschema.ddl_setup_timers main.gcc296 main.func_group perfschema.bad_option_2 perfschema.dml_ews_by_instance main.mix2_myisam main.kill_query-6728 perfschema.dml_events_statements_current perfschema.dml_esgs_by_account_by_event_name main.mrr_icp_extra main.mix2_myisam_ucs2 perfschema.hostcache_ipv4_ssl perfschema.ddl_setup_instruments perfschema.read_only main.fulltext_var main.func_like main.get_diagnostics main.insert_update_autoinc-7150 perfschema.ddl_os_global_by_type main.func_isnull perfschema.privilege_table_io main.lock_multi perfschema.bad_option_3 main.func_des_encrypt perfschema.ddl_esgs_by_user_by_event_name perfschema.hostcache_ipv4_addrinfo_again_deny main.gis-precise main.function_defaults perfschema.global_read_lock perfschema.dml_esgs_by_thread_by_event_name perfschema.ddl_threads perfschema.ddl_ews_by_account_by_event_name perfschema.ddl_esgs_by_thread_by_event_name main.last_value main.limit_rows_examined perfschema.hostcache_ipv4_addrinfo_good_deny perfschema.dml_setup_actors main.frm_bad_row_type-7333 perfschema.hostcache_ipv4_addrinfo_good_allow perfschema.ddl_esgs_by_host_by_event_name perfschema.ddl_setup_actors main.keywords perfschema.ddl_tiws_by_table perfschema.setup_actors perfschema.column_privilege perfschema.ddl_esgs_by_account_by_event_name main.gis-debug main.join_crash perfschema.dml_events_stages_history perfschema.ddl_events_waits_history perfschema.ddl_ews_by_user_by_event_name perfschema.hostcache_ipv4_nameinfo_noname_allow main.func_timestamp perfschema.ddl_cond_instances perfschema.dml_esms_by_digest main.join_nested_jcl6 main.insert_notembedded
 
160619 23:38:23 [ERROR] mysqld got signal 11 ;
Attempting backtrace. You can use the following information to find out



 Comments   
Comment by Michael Widenius [ 2018-05-25 ]

Crash happened because in discover, table->work_part_info was not properly
reset before execution.
Fixed by resetting before calling execute alter table, create table or
mysql_create_frm_image.

Comment by Michael Widenius [ 2018-05-26 ]

Fix was in itself trivial, but I didn't like how the original code used thd->work_part_info, so I
cleaned up the usage of this a bit.

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