Details
-
Type:
Bug
-
Status: Open
-
Priority:
Major
-
Resolution: Unresolved
-
Affects Version/s: 10.0.21
-
Fix Version/s: None
-
Component/s: Optimizer
-
Labels:
-
Environment:AWS, ubuntu-14.04, Drupal 7, x86_64
Description
Aug 16 23:33:50 db2 mysqld: *** stack smashing detected ***: /usr/sbin/mysqld terminated Aug 16 23:33:50 db2 mysqld: 150816 23:33:50 [ERROR] mysqld got signal 6 ; Aug 16 23:33:50 db2 mysqld: This could be because you hit a bug. It is also possible that this binary Aug 16 23:33:50 db2 mysqld: or one of the libraries it was linked against is corrupt, improperly built, Aug 16 23:33:50 db2 mysqld: or misconfigured. This error can also be caused by malfunctioning hardware. Aug 16 23:33:50 db2 mysqld: Aug 16 23:33:50 db2 mysqld: To report this bug, see http://kb.askmonty.org/en/reporting-bugs Aug 16 23:33:50 db2 mysqld: Aug 16 23:33:50 db2 mysqld: We will try our best to scrape up some info that will hopefully help Aug 16 23:33:50 db2 mysqld: diagnose the problem, but since we have already crashed, Aug 16 23:33:50 db2 mysqld: something is definitely wrong and this may fail. Aug 16 23:33:50 db2 mysqld: Aug 16 23:33:50 db2 mysqld: Server version: 10.0.21-MariaDB-1~trusty-log Aug 16 23:33:50 db2 mysqld: key_buffer_size=33554432 Aug 16 23:33:50 db2 mysqld: read_buffer_size=2097152 Aug 16 23:33:50 db2 mysqld: max_used_connections=78 Aug 16 23:33:50 db2 mysqld: max_threads=52 Aug 16 23:33:50 db2 mysqld: thread_count=2 Aug 16 23:33:50 db2 mysqld: It is possible that mysqld could use up to Aug 16 23:33:50 db2 mysqld: key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 353263 K bytes of memory Aug 16 23:33:50 db2 mysqld: Hope that's ok; if not, decrease some variables in the equation. Aug 16 23:33:50 db2 mysqld: Aug 16 23:33:50 db2 mysqld: Thread pointer: 0x0x7f7bb5c0b008 Aug 16 23:33:50 db2 mysqld: Attempting backtrace. You can use the following information to find out Aug 16 23:33:50 db2 mysqld: where mysqld died. If you see no messages after this, something went Aug 16 23:33:50 db2 mysqld: terribly wrong... Aug 16 23:33:50 db2 mysqld: stack_bottom = 0x7f7c32da7e00 thread_stack 0x48000 Aug 16 23:33:50 db2 mysqld: /usr/sbin/mysqld(my_print_stacktrace+0x2e)[0x7f7d8670c12e] Aug 16 23:33:50 db2 mysqld: /usr/sbin/mysqld(handle_fatal_signal+0x457)[0x7f7d86248a17] Aug 16 23:33:50 db2 mysqld: /lib/x86_64-linux-gnu/libpthread.so.0(+0x10340)[0x7f7d8524f340] Aug 16 23:33:50 db2 mysqld: /lib/x86_64-linux-gnu/libc.so.6(gsignal+0x39)[0x7f7d84068cc9] Aug 16 23:33:50 db2 mysqld: /lib/x86_64-linux-gnu/libc.so.6(abort+0x148)[0x7f7d8406c0d8] Aug 16 23:33:50 db2 mysqld: /lib/x86_64-linux-gnu/libc.so.6(+0x73394)[0x7f7d840a5394] Aug 16 23:33:50 db2 mysqld: /lib/x86_64-linux-gnu/libc.so.6(__fortify_fail+0x5c)[0x7f7d8413cc9c] Aug 16 23:33:50 db2 mysqld: /lib/x86_64-linux-gnu/libc.so.6(__fortify_fail+0x0)[0x7f7d8413cc40] Aug 16 23:33:50 db2 mysqld: /usr/sbin/mysqld(_Z36calculate_cond_selectivity_for_tableP3THDP5TABLEP4Item+0x159b)[0x7f7d8635a14b] Aug 16 23:33:50 db2 mysqld: Aug 16 23:33:50 db2 mysqld: Trying to get some variables. Aug 16 23:33:50 db2 mysqld: Some pointers may be invalid and cause the dump to abort. Aug 16 23:33:50 db2 mysqld: Query (0x7f7bb5f5d020): is an invalid pointer Aug 16 23:33:50 db2 mysqld: Connection ID (thread ID): 55997 Aug 16 23:33:50 db2 mysqld: Status: NOT_KILLED Aug 16 23:33:50 db2 mysqld: Aug 16 23:33:50 db2 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=on,mrr_cost_based=off,mrr_sort_keys=on,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=on,table_elimination=on,extended_keys=on,exists_to_in=on Aug 16 23:33:50 db2 mysqld: Aug 16 23:33:50 db2 mysqld: The manual page at http://dev.mysql.com/doc/mysql/en/crashing.html contains Aug 16 23:33:50 db2 mysqld: information that should help you find out what is causing the crash. Aug 16 23:33:50 db2 mysqld_safe: Number of processes running now: 0 Aug 16 23:33:50 db2 mysqld_safe: mysqld restarted
This occurred 4 times in a row.
demangle _Z36calculate_cond_selectivity_for_tableP3THDP5TABLEP4Item calculate_cond_selectivity_for_table(THD*, TABLE*, Item*)
[mariadb] # # * Character sets # # Default is Latin1, if you need UTF-8 set all this (also in client section) # # Basic datadir = /srv/mysqldata character-set-server = utf8 collation-server = utf8_general_ci character_set_server = utf8 collation_server = utf8_general_ci default_storage_engine = InnoDB sql_mode = NO_ENGINE_SUBSTITUTION log_warnings = 2 performance_schema = ON # Connections skip-name-resolve # logins are determined by IP address, not hostname. max_allowed_packet = 64M # account for the largest blob/text retrieved max_connections = 50 thread_cache_size = 50 # # Tuning table_open_cache = 5000 table_definition_cache = 5000 read_buffer_size = 2M read_rnd_buffer_size = 1M sort_buffer_size = 4M query_cache_limit = 128K query_cache_strip_comments = ON query_cache_size = 64M max_heap_table_size = 32M tmp_table_size = 32M # Query Planner use_stat_tables = complementary histogram_size =255 join_cache_level =8 optimizer_use_condition_selectivity =4 optimizer_switch = mrr=on,mrr_sort_keys=on,optimize_join_buffer_size=on innodb_stats_traditional = false # Slow Log log-output = FILE slow_query_log = 1 slow_query_log_file = /var/log/mysql/slow.log # separate spindle from data, if possible - not datadir if you want logrotate/selinux to work long_query_time = 2 log_slow_verbosity = innodb,query_plan,explain # 10.0+ log-queries-not-using-indexes min-examined-row-limit = 5000 # set to appropriate value to avoid small table scans being logged log_slow_admin_statements # Myisam key_buffer = 32M myisam-recover = QUICK,BACKUP #Innodb innodb_data_file_path = ibdata1:10M:autoextend innodb_file_per_table = 1 innodb_file_format = Barracuda innodb_log_group_home_dir = /srv/mysqldata innodb_log_files_in_group = 4 innodb_log_file_size = 50M innodb_flush_method = O_DIRECT innodb_buffer_pool_size = 4500M innodb_log_buffer_size = 4M innodb_io_capacity = 1000 innodb_buffer_pool_dump_at_shutdown =ON innodb_buffer_pool_load_at_startup =ON # Binary Logs log-bin = /srv/mysqllog/mariadb-bin log_bin_index = /srv/mysqllog/mariadb-bin.index relay_log_space_limit = 40G relay_log = /srv/mysqllog/mysqld-relay-bin expire_logs_days = 10 max_binlog_size = 100M log-slave-updates sync_binlog = 1 binlog_format = MIXED binlog_annotate_row_events = ON # 10+ to make comments continue to be retained in RBR replication - e.g. audit replicate_annotate_row_events = ON # 10+ as above #binlog_commit_wait_count 20 #binlog_commit_wait_usec 10000 # Relay Logs relay_log_space_limit = 250M # Multi-master setup auto-increment-increment = 2 # multi-threaded replication (MariaDB 10.0) https://mariadb.com/kb/en/parallel-replication/ #slave_domain_parallel_threads 8 #slave-parallel-threads = 20 slave_transaction_retries = 20
682bb0 + 159b = 0x68414B
objdump -d /usr/sbin/mysqld > /tmp/mysqld.objdump
0000000000682bb0 <_Z36calculate_cond_selectivity_for_tableP3THDP5TABLEP4Item>: .... 68410d: 0f 85 b3 00 00 00 jne 6841c6 <_Z36calculate_cond_selectivity_for_tableP3THDP5TABLEP4Item+0x1616> 684113: 41 0f b6 7f 03 movzbl 0x3(%r15),%edi 684118: 40 80 ff 40 cmp $0x40,%dil 68411c: 0f 84 a4 00 00 00 je 6841c6 <_Z36calculate_cond_selectivity_for_tableP3THDP5TABLEP4Item+0x1616> 684122: 44 0f b6 40 03 movzbl 0x3(%rax),%r8d 684127: 83 c7 01 add $0x1,%edi 68412a: 41 39 f8 cmp %edi,%r8d 68412d: 0f 85 93 00 00 00 jne 6841c6 <_Z36calculate_cond_selectivity_for_tableP3THDP5TABLEP4Item+0x1616> 684133: f6 c2 05 test $0x5,%dl 684136: 0f 85 8a 00 00 00 jne 6841c6 <_Z36calculate_cond_selectivity_for_tableP3THDP5TABLEP4Item+0x1616> 68413c: 41 01 cc add %ecx,%r12d 68413f: 89 d7 mov %edx,%edi 684141: e9 0a ff ff ff jmpq 684050 <_Z36calculate_cond_selectivity_for_tableP3THDP5TABLEP4Item+0x14a0> 684146: e8 55 f7 ca ff callq 3338a0 <__stack_chk_fail@plt> 68414b: 31 c9 xor %ecx,%ecx 68414d: 31 f6 xor %esi,%esi 68414f: eb a2 jmp 6840f3 <_Z36calculate_cond_selectivity_for_tableP3THDP5TABLEP4Item+0x1543> 684151: 49 8b 45 00 mov 0x0(%r13),%rax 684155: 0f b7 d1 movzwl %cx,%edx 684158: 31 f6 xor %esi,%esi 68415a: 83 ea 01 sub $0x1,%edx 68415d: f2 0f 11 95 78 d5 ff movsd %xmm2,-0x2a88(%rbp) 684164: ff 684165: 89 8d 98 d5 ff ff mov %ecx,-0x2a68(%rbp) 68416b: c6 00 01 movb $0x1,(%rax) 68416e: 49 8b 45 00 mov 0x0(%r13),%rax 684172: 48 8d 78 01 lea 0x1(%rax),%rdi 684176: e8 a5 f7 ca ff callq 333920 <memset@plt> 68410d: 0f 85 b3 00 00 00 jne 6841c6 <_Z36calculate_cond_selectivity_for_tableP3THDP5TABLEP4Item+0x1616> 684113: 41 0f b6 7f 03 movzbl 0x3(%r15),%edi 684118: 40 80 ff 40 cmp $0x40,%dil 68411c: 0f 84 a4 00 00 00 je 6841c6 <_Z36calculate_cond_selectivity_for_tableP3THDP5TABLEP4Item+0x1616> 684122: 44 0f b6 40 03 movzbl 0x3(%rax),%r8d 684127: 83 c7 01 add $0x1,%edi 68412a: 41 39 f8 cmp %edi,%r8d 68412d: 0f 85 93 00 00 00 jne 6841c6 <_Z36calculate_cond_selectivity_for_tableP3THDP5TABLEP4Item+0x1616> 684133: f6 c2 05 test $0x5,%dl 684136: 0f 85 8a 00 00 00 jne 6841c6 <_Z36calculate_cond_selectivity_for_tableP3THDP5TABLEP4Item+0x1616> 68413c: 41 01 cc add %ecx,%r12d 68413f: 89 d7 mov %edx,%edi 684141: e9 0a ff ff ff jmpq 684050 <_Z36calculate_cond_selectivity_for_tableP3THDP5TABLEP4Item+0x14a0> 684146: e8 55 f7 ca ff callq 3338a0 <__stack_chk_fail@plt> 68414b: 31 c9 xor %ecx,%ecx 68414d: 31 f6 xor %esi,%esi 68414f: eb a2 jmp 6840f3 <_Z36calculate_cond_selectivity_for_tableP3THDP5TABLEP4Item+0x1543> 684151: 49 8b 45 00 mov 0x0(%r13),%rax 684155: 0f b7 d1 movzwl %cx,%edx 684158: 31 f6 xor %esi,%esi 68415a: 83 ea 01 sub $0x1,%edx 68415d: f2 0f 11 95 78 d5 ff movsd %xmm2,-0x2a88(%rbp) 684164: ff 684165: 89 8d 98 d5 ff ff mov %ecx,-0x2a68(%rbp) 68416b: c6 00 01 movb $0x1,(%rax) 68416e: 49 8b 45 00 mov 0x0(%r13),%rax 684172: 48 8d 78 01 lea 0x1(%rax),%rdi 684176: e8 a5 f7 ca ff callq 333920 <memset@plt> 68417b: 8b 8d 98 d5 ff ff mov -0x2a68(%rbp),%ecx 684181: f2 0f 10 95 78 d5 ff movsd -0x2a88(%rbp),%xmm2 684188: ff 684189: 0f b7 c9 movzwl %cx,%ecx 68418c: e9 4c ff ff ff jmpq 6840dd <_Z36calculate_cond_selectivity_for_tableP3THDP5TABLEP4Item+0x152d> 684191: 49 8b 75 e0 mov -0x20(%r13),%rsi 684195: 29 fa sub %edi,%edx 684197: f2 0f 11 95 98 d5 ff movsd %xmm2,-0x2a68(%rbp) 68419e: ff 68419f: e8 1c 09 cb ff callq 334ac0 <memcmp@plt> 6841a4: 85 c0 test %eax,%eax 6841a6: f2 0f 10 95 98 d5 ff movsd -0x2a68(%rbp),%xmm2 6841ad: ff 6841ae: 0f 85 fa fa ff ff jne 683cae <_Z36calculate_cond_selectivity_for_tableP3THDP5TABLEP4Item+0x10fe> 6841b4: 66 83 3b 00 cmpw $0x0,(%rbx) 6841b8: 0f 85 f0 fa ff ff jne 683cae <_Z36calculate_cond_selectivity_for_tableP3THDP5TABLEP4Item+0x10fe> 6841be: 4c 89 f3 mov %r14,%rbx 6841c1: e9 99 f6 ff ff jmpq 68385f <_Z36calculate_cond_selectivity_for_tableP3THDP5TABLEP4Item+0xcaf> 6841c6: 44 01 e6 add %r12d,%esi 6841c9: 4c 8b a5 c8 d6 ff ff mov -0x2938(%rbp),%r12 6841d0: 41 01 75 18 add %esi,0x18(%r13) 6841d4: e9 e7 fa ff ff jmpq 683cc0 <_Z36calculate_cond_selectivity_for_tableP3THDP5TABLEP4Item+0x1110> 6841d9: 0f 1f 80 00 00 00 00 nopl 0x0(%rax) 00000000006841e0 <_Z16prune_partitionsP3THDP5TABLEP4Item>:
Yes, debug symbols would make this a lot easier - MDEV-658.
Engine independent stats where generated with ANALYZE TABLE x PERSISTENT FOR ALL; over entire dataset.
I've enabled the general query log to attempt to gather a query.
Gliffy Diagrams
Attachments
Activity
- All
- Comments
- Work Log
- History
- Activity
- Transitions
Meanwhile, we got a new report MDEV-8779 with a test case, it looks very similar, including the broken stack trace.
Daniel Black, what do you think, does i look like the same problem?
It definitely is a stack overrun like Sergey Vojtovich describes in MDEV-8779 however without finding/tracing a query it won't be possible to be definite that is is the same case.
I did a bit more digging on the server. It occurred again on the following day and a bunch of time on Sept 11 and nothing since. I've asked the client's webdev to take a look at specific times.
Daniel Black, any luck?
I've been running optimizer tests with your config, but haven't got the crash so far.
We had a number of issues in calculate_cond_selectivity_for_table, but they have all been fixed long time ago, so this one either is new or was not caught before.