[MDEV-8634] abort in calculate_cond_selectivity_for_table Created: 2015-08-17  Updated: 2015-10-23  Resolved: 2015-10-17

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

Type: Bug Priority: Major
Reporter: Daniel Black Assignee: Unassigned
Resolution: Fixed Votes: 0
Labels: None
Environment:

AWS, ubuntu-14.04, Drupal 7, x86_64

Issue Links:
Relates
relates to MDEV-8779 mysqld got signal 11 in sql/opt_range... Closed

 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.

 Comments   
Comment by Elena Stepanova [ 2015-08-19 ]

danblack, 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.

Comment by Elena Stepanova [ 2015-09-17 ]

Meanwhile, we got a new report MDEV-8779 with a test case, it looks very similar, including the broken stack trace.
danblack, what do you think, does i look like the same problem?

Comment by Daniel Black [ 2015-09-18 ]

It definitely is a stack overrun like svoj 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.

Comment by Elena Stepanova [ 2015-10-17 ]

danblack, any news on this one?

Comment by Daniel Black [ 2015-10-17 ]

I've seen no further crashes however the client has done a lot of re-engineering of the code, one of the tables mentioned in the query log is no longer in use. I don't think I'll see any further info here. I still have core-file-size = unlimited just in case however. eits is currently in use with innodb so it could of been MDEV-8779.

Comment by Elena Stepanova [ 2015-10-17 ]

Then I suggest to be optimistic for now and consider it fixed in the scope of MDEV-8779. If it is encountered later again, please re-open the bug.

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