[MDEV-18036] Mariadb 10.3 crashed with signal 11 Created: 2018-12-19  Updated: 2019-03-04  Resolved: 2019-03-04

Status: Closed
Project: MariaDB Server
Component/s: Data Definition - Temporary, Storage Engine - InnoDB, Stored routines
Affects Version/s: 10.3.8
Fix Version/s: 10.3.9

Type: Bug Priority: Major
Reporter: Dave Juntgen Assignee: Unassigned
Resolution: Fixed Votes: 0
Labels: None
Environment:

CentOS 7

Attachments: File wc_incident_lost_days.sql    

 Description   

Hello,

Below is a crash report from MariaDB 10.3.8, the report isn't much and does not give much direction. Anything I can do to help provide better next steps

181219  8:29:19 [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.3.8-MariaDB-log
 
key_buffer_size=134217728
 
read_buffer_size=131072
 
max_used_connections=73
 
max_threads=2002
 
thread_count=47
 
It is possible that mysqld could use up to
 
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 4532133 K  bytes of memory
 
Hope that's ok; if not, decrease some variables in the equation.
 
 
 
Thread pointer: 0x7ed3780008c8
 
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 = 0x7ed514473d30 thread_stack 0x49000
 
/usr/sbin/mysqld(my_print_stacktrace+0x2e)[0x56497058cece]
 
/usr/sbin/mysqld(handle_fatal_signal+0x357)[0x564970029577]



 Comments   
Comment by Elena Stepanova [ 2018-12-19 ]

Is it the very end of the report in the log?

Comment by Dave Juntgen [ 2018-12-19 ]

Hello - the crash report yes, the next few lines are the restart of the service and crash recovery.

Comment by Elena Stepanova [ 2018-12-19 ]

Is the crash reproducible? Can you enable the coredump and extract the stack trace next time it occurs?

Comment by Dave Juntgen [ 2018-12-19 ]

I will enable core dump according to https://mariadb.com/kb/en/library/enabling-core-dumps/ and report back when signal 11 triggers again if at all.

Comment by Dave Juntgen [ 2018-12-20 ]

I am continuing to have failures, and I believe that this may be an issue with a store function that creates a tempory table on disk. I'm still working on capturing a core dump...

Comment by Dave Juntgen [ 2018-12-21 ]

Hello Elena,

The crash seems to be taking place with temp tables executed within a SELECT statement that then calls a user-defined FUNCTION(). Below are two backtraces that did not produce core files. maybe config issue here.

181220 11:08:01 [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.3.8-MariaDB-log
 
key_buffer_size=134217728
 
read_buffer_size=131072
 
max_used_connections=28
 
max_threads=2002
 
thread_count=35
 
It is possible that mysqld could use up to
 
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 4532133 K  bytes of memory
 
Hope that's ok; if not, decrease some variables in the equation.
 
 
 
Thread pointer: 0x7f7bec0009a8
 
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 = 0x7f7c78d98d30 thread_stack 0x49000
 
*** buffer overflow detected ***: /usr/sbin/mysqld terminated
 
======= Backtrace: =========
 
/lib64/libc.so.6(__fortify_fail+0x37)[0x7fab85e886e7]
 
/lib64/libc.so.6(+0x116862)[0x7fab85e86862]
 
/lib64/libc.so.6(+0x118647)[0x7fab85e88647]
 
/usr/sbin/mysqld(my_addr_resolve+0xda)[0x55a5a0a819da]
 
/usr/sbin/mysqld(my_print_stacktrace+0x1c2)[0x55a5a0a6b062]
 
/usr/sbin/mysqld(handle_fatal_signal+0x357)[0x55a5a0507577]
 
/lib64/libpthread.so.0(+0xf6d0)[0x7fab87ad36d0]
 
/lib64/libc.so.6(+0x81261)[0x7fab85df1261]
 
/usr/sbin/mysqld(+0x95705f)[0x55a5a06e105f]
 
/usr/sbin/mysqld(_ZN7handler27multi_range_read_info_constEjP15st_range_seq_ifPvjPjS3_P13Cost_estimate+0xd6)[0x55a5a043a116]
 
/usr/sbin/mysqld(_ZN10DsMrr_impl16dsmrr_info_constEjP15st_range_seq_ifPvjPjS3_P13Cost_estimate+0x49)[0x55a5a043c1c9]
 
/usr/sbin/mysqld(+0x88e2c7)[0x55a5a06182c7]
 
/usr/sbin/mysqld(+0x88e637)[0x55a5a0618637]
 
/usr/sbin/mysqld(_ZN10SQL_SELECT17test_quick_selectEP3THD6BitmapILj64EEyybbb+0x9fb)[0x55a5a06258db]
 
/usr/sbin/mysqld(+0x5f7e80)[0x55a5a0381e80]
 
/usr/sbin/mysqld(_ZN4JOIN14optimize_innerEv+0x912)[0x55a5a038a412]
 
/usr/sbin/mysqld(_ZN4JOIN8optimizeEv+0x37)[0x55a5a038a667]
 
/usr/sbin/mysqld(_Z12mysql_selectP3THDP10TABLE_LISTjR4ListI4ItemEPS4_jP8st_orderS9_S7_S9_yP13select_resultP18st_select_lex_unitP13st_select_lex+0x94)[0x55a5a038bc34]
 
/usr/sbin/mysqld(_Z13handle_selectP3THDP3LEXP13select_resultm+0x1cc)[0x55a5a038c7cc]
 
/usr/sbin/mysqld(+0x4b96ef)[0x55a5a02436ef]
 
/usr/sbin/mysqld(_Z21mysql_execute_commandP3THD+0x6f0a)[0x55a5a0338a8a]
 
/usr/sbin/mysqld(_Z11mysql_parseP3THDPcjP12Parser_statebb+0x22b)[0x55a5a033b25b]
 
/usr/sbin/mysqld(_Z16dispatch_command19enum_server_commandP3THDPcjbb+0x1d25)[0x55a5a033de55]
 
/usr/sbin/mysqld(_Z10do_commandP3THD+0x13e)[0x55a5a033ecbe]
 
/usr/sbin/mysqld(_Z24do_handle_one_connectionP7CONNECT+0x1aa)[0x55a5a040f2ba]
 
/usr/sbin/mysqld(handle_one_connection+0x3d)[0x55a5a040f3dd]
 
/lib64/libpthread.so.0(+0x7e25)[0x7fab87acbe25]
 
/lib64/libc.so.6(clone+0x6d)[0x7fab85e6ebad]
 
 
 
 
 
2018-12-20 11:30:59 3666 [ERROR] InnoDB: Trying to read doublewrite buffer page [page id: space=0, page number=167]
 
*** buffer overflow detected ***: /usr/sbin/mysqld terminated
 
2018-12-20 11:30:59 3666 [ERROR] InnoDB: Trying to read doublewrite buffer page [page id: space=0, page number=167]
 
======= Backtrace: =========
 
2018-12-20 11:30:59 3666 [ERROR] InnoDB: Trying to read doublewrite buffer page [page id: space=0, page number=167]
 
2018-12-20 11:30:59 3666 [ERROR] InnoDB: Trying to read doublewrite buffer page [page id: space=0, page number=167]
 
2018-12-20 11:30:59 3666 [ERROR] InnoDB: Trying to read doublewrite buffer page [page id: space=0, page number=167]
 
2018-12-20 11:30:59 3666 [ERROR] InnoDB: Trying to read doublewrite buffer page [page id: space=0, page number=167]
 
2018-12-20 11:30:59 3666 [ERROR] InnoDB: Trying to read doublewrite buffer page [page id: space=0, page number=167]
 
/lib64/libc.so.6(__fortify_fail+0x37)[0x7f9ec07436e7]
 
2018-12-20 11:30:59 3666 [ERROR] InnoDB: Trying to read doublewrite buffer page [page id: space=0, page number=167]
 
2018-12-20 11:30:59 3666 [ERROR] InnoDB: Trying to read doublewrite buffer page [page id: space=0, page number=167]
 
2018-12-20 11:30:59 3666 [ERROR] InnoDB: Trying to read doublewrite buffer page [page id: space=0, page number=167]
 
2018-12-20 11:30:59 3666 [ERROR] InnoDB: Trying to read doublewrite buffer page [page id: space=0, page number=167]
 
2018-12-20 11:30:59 3666 [ERROR] InnoDB: Trying to read doublewrite buffer page [page id: space=0, page number=167]
 
2018-12-20 11:30:59 3666 [ERROR] InnoDB: Trying to read doublewrite buffer page [page id: space=0, page number=167]
 
/lib64/libc.so.6(+0x116862)[0x7f9ec0741862]
 
2018-12-20 11:30:59 3666 [ERROR] InnoDB: Trying to read doublewrite buffer page [page id: space=0, page number=167]
 
2018-12-20 11:30:59 3666 [ERROR] InnoDB: Trying to read doublewrite buffer page [page id: space=0, page number=167]
 
2018-12-20 11:30:59 3666 [ERROR] InnoDB: Trying to read doublewrite buffer page [page id: space=0, page number=167]
 
/lib64/libc.so.6(+0x118647)[0x7f9ec0743647]

Comment by Elena Stepanova [ 2018-12-21 ]

djuntgen,

If you found the statement which causes the problem, could you then please paste the statement itself and SHOW CREATE for all objects it uses, directly or indirectly (tables, views, functions, etc.)? You can obfuscate names of objects if needed, as long as the obfuscation is consistent (same fake names are used in SELECT and in SHOW CREATE etc.).

For tables, it might also be useful to have SHOW INDEX IN <table name>.

Please also attach or paste your cnf file(s).

Thanks.

Comment by Dave Juntgen [ 2018-12-21 ] 

*************************** 1. row ***************************
 
             ID: 62866
 
           USER: wc_dow
 
           HOST: wc-c1-b5.med-web.com:41028
 
             DB: wc_xxxxxx
 
        COMMAND: Query
 
           TIME: 472
 
          STATE: Sending data
 
           INFO: SELECT COALESCE(SUM((TO_DAYS(IF(`end_date` > DATE(NOW()), DATE(NOW()), `end_date`)) + 1) - TO_DAYS(`start_date`)), 0) INTO restricted_days
 
       FROM lost_time_condensed_ranges AS lcrt
 
       WHERE `inc_id`= NAME_CONST('in_inc_id',9496) AND `type` = 2 AND `start_date` <= DATE(NOW())
 
        TIME_MS: 472911.629
 
          STAGE: 0
 
      MAX_STAGE: 0
 
       PROGRESS: 0.000
 
    MEMORY_USED: 790096
 
MAX_MEMORY_USED: 2196264
 
  EXAMINED_ROWS: 0
 
       QUERY_ID: 6521990
 
    INFO_BINARY: SELECT COALESCE(SUM((TO_DAYS(IF(`end_date` > DATE(NOW()), DATE(NOW()), `end_date`)) + 1) - TO_DAYS(`start_date`)), 0) INTO restricted_days
 
       FROM lost_time_condensed_ranges AS lcrt
 
       WHERE `inc_id`= NAME_CONST('in_inc_id',9496) AND `type` = 2 AND `start_date` <= DATE(NOW())
 
            TID: 4889

Below is the function that called this query, the `lost_time_condensed_ranges` is a temporary table. Please note that encryption is enabled for tmporary tables.

wc_incident_lost_days.sql

Comment by Dave Juntgen [ 2018-12-21 ]

FYI - I disabled encrypt_tmp_disk_tables and encrypt_tmp_files to see if the server will run without crashing.

+--------------------------------------+-------+
 
| aria_encrypt_tables                  | ON    |
 
| encrypt_binlog                       | ON    |
 
| encrypt_tmp_disk_tables              | OFF   |
 
| encrypt_tmp_files                    | OFF   |
 
| innodb_buf_dump_status_frequency     | 0     |
 
| innodb_commit_concurrency            | 0     |
 
| innodb_concurrency_tickets           | 5000  |
 
| innodb_default_encryption_key_id     | 1     |
 
| innodb_defragment_frequency          | 40    |
 
| innodb_encrypt_log                   | ON    |
 
| innodb_encrypt_tables                | ON    |
 
| innodb_encryption_rotate_key_age     | 1     |
 
| innodb_encryption_rotation_iops      | 100   |
 
| innodb_encryption_threads            | 4     |
 
| innodb_purge_rseg_truncate_frequency | 128   |
 
| innodb_thread_concurrency            | 0     |
 
| thread_concurrency                   | 10    |
 
+--------------------------------------+-------+
 
17 rows in set (0.002 sec)

Comment by Elena Stepanova [ 2018-12-28 ]

djuntgen, are you still getting [ERROR] InnoDB: Trying to read doublewrite buffer page after you disabled encryption for temporary tables/files?
And could it be possible for you to try the latest 10.3 release?

We had a bug MDEV-16713 which is remarkably similar in some ways – stored procedures, temporary tables, the error messages, 10.3.8 affected, problems on both debug and non-debug builds. The difference is that there was no encryption there, and the non-debug build was hanging, not crashing. But SIGSEGV and buffer overflow depend on many factors, so this difference is not critical.

Comment by Dave Juntgen [ 2019-01-02 ]

Hello,

I just ran the test procedure from MDEV-16713, and the server hangs as described. I will attempt to upgrade and run again.

Comment by Elena Stepanova [ 2019-02-02 ]

djuntgen,
any luck with the upgrade?

Comment by Dave Juntgen [ 2019-03-04 ]

Crash has not appeared seens upgrade from 10.3.8, all looks well. Thanks!

Comment by Elena Stepanova [ 2019-03-04 ]

Based on the feedback, we assume that the problem was fixed in the scope of MDEV-16713.

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