[MDEV-12549] Sudden crash on query Created: 2017-04-21  Updated: 2017-06-12  Resolved: 2017-06-12

Status: Closed
Project: MariaDB Server
Component/s: Data Manipulation - Subquery, Storage Engine - InnoDB
Affects Version/s: 10.1.21
Fix Version/s: N/A

Type: Bug Priority: Major
Reporter: Dmitriy Rabotyagov Assignee: Unassigned
Resolution: Incomplete Votes: 0
Labels: need_feedback
Environment:

CloudLinux Server release 6.9
mysql Ver 15.1 Distrib 10.1.21-MariaDB, for Linux (x86_64) using readline 5.1
kernel: 2.6.32-673.8.1.lve1.4.3.1.el6.x86_64


Attachments: Text File log-error.txt     File schema.sql    

 Description   

MariaDB suddenly crashes with [ERROR] mysqld got signal 11 ; during the request:

*************************** 8. row ***************************
      Id: 121063
    User: comua120_usr
    Host: localhost
      db: comua120_back_09-03-2017
 Command: Query
    Time: 5
   State: statistics
    Info: SELECT fl.name feature_name, fp.id_feature, fv.id_feature_value, fvl.value,
                    COUNT(DISTINCT p.id_product) nbr,
                    lifl.url_name name_url_name, lifl.meta_title name_meta_title, lifvl.url_name value_url_name, lifvl.meta_title value_meta_title , psi.price_min, psi.price_max
 
                    FROM ps_feature_product fp
                    INNER JOIN ps_product p ON (p.id_product = fp.id_product)
                    LEFT JOIN ps_feature_lang fl ON (fl.id_feature = fp.id_feature AND fl.id_lang = 2)
                    INNER JOIN ps_feature_value fv ON (fv.id_feature_value = fp.id_feature_value AND (fv.custom IS NULL OR fv.custom = 0))
                    LEFT JOIN ps_feature_value_lang fvl ON (fvl.id_feature_value = fp.id_feature_value AND fvl.id_lang = 2)
                    LEFT JOIN ps_layered_indexable_feature_lang_value lifl
                    ON (lifl.id_feature = fp.id_feature AND lifl.id_lang = 2)
                    LEFT JOIN ps_layered_indexable_feature_value_lang_value lifvl
                    ON (lifvl.id_feature_value = fp.id_feature_value AND lifvl.id_lang = 2)  INNER JOIN ps_product_shop product_shop
        ON (product_shop.id_product = p.id_product AND product_shop.id_shop = 1)
 
            INNER JOIN `ps_layered_price_index` psi ON (psi.id_product = p.id_product AND psi.id_currency = 1
            AND psi.price_min <= 16000 AND psi.price_max >= 0) 
WHERE product_shop.`active` = 1 AND fp.id_feature = 9
                    AND p.id_product IN (
                    SELECT id_product
                    FROM ps_category_product cp
                    INNER JOIN ps_category c ON (c.id_category = cp.id_category AND
                    c.nleft >= 25
                    AND c.nright <= 50
                    AND c.active = 1))  AND p.id_product IN (SELECT id_product FROM ps_feature_product fp WHERE fp.`id_feature_value` = 92)  AND p.id_product IN (SELECT id_product FROM ps_feature_product fp WHERE fp.`id_feature_value` = 37)  AND p.id_product IN (SELECT id_product FROM ps_feature_product fp WHERE fp.`id_feature_value` = 31)  AND p.id_product IN (SELECT id_product FROM ps_feature_product fp WHERE fp.`id_feature_value` = 59) 
GROUP BY fv.id_feature_value
Progress: 0.000

As a workaround we had to dump and restore database into the new db. This process (dump/restore) should be made every 10-14 days, as in the other case we are facing this bug again.

my.cnf:

[mysqld]
max_connections              = 300
max_user_connections         = 30
 
innodb_file_per_table        = 1
innodb_corrupt_table_action  = assert
local-infile                 = 0
 
key_buffer_size              = 512M
query_cache_size             = 96M
query_cache_limit            = 1M
query_cache_min_res_unit     = 2048
 
table_open_cache             = 7000   
innodb_open_files            = 7000
open_files_limit=50000
 
tmp_table_size               = 16M
max_heap_table_size          = 16M
 
join_buffer_size             = 32M
max_join_size                = 100000000
 
thread_cache_size            = 20
 
innodb_buffer_pool_size      = 8000M
innodb_buffer_pool_instances = 8
innodb_flush_log_at_trx_commit = 2
innodb_log_buffer_size       = 16M
innodb_additional_mem_pool_size = 24M
innodb_log_file_size         = 512M
innodb_io_capacity           = 200
 
max_allowed_packet           = 268435456
 
tmpdir=/var/lib/mysql/tmp_table



 Comments   
Comment by Elena Stepanova [ 2017-04-21 ]

Please also attach the error log. It can be either in a separate file, or in syslog.
If possible, the database dump (or at least the schema dump, structures for all involved objects without data) could be a great help. Dumps can be uploaded to ftp.askmonty.org/private, in this case only MariaDB developers will have access to them.

Why did you have to dump/restore, did your database get corrupted after the crash?

Comment by Dmitriy Rabotyagov [ 2017-04-21 ]

Hi,

Sorry, it seems that we've forgotten to enable log-error. But I've attached database schema to the thread. If full database dump is important - please let us know.

We decided to make dump/restore as after migrating this DB to the another server, we couldn't reproduce the problem. But on the target host this request caused crash in 100% cases. So we've created dump and localy restored DB to itself, after which this request didn't crashed the server. However the problem returns every 9-11 days, which is pretty annoying.
We've checked database integrity and didn't found any problems with it.

Comment by Elena Stepanova [ 2017-04-21 ]

Thanks.
Normally the error log in some form is enabled by default, it rather takes an effort to disable it. If you didn't set the variable, it is either written to a default file <datadir>/host_name.err or to a syslog (or its analogue in the system).

If you don't have an error log from the previous crash, could you please check that it's created by the next time? It's very important to see the stack trace there. Even better if you have a coredump and can get the stack trace from it.

Comment by Dmitriy Rabotyagov [ 2017-04-21 ]

Sorry, my fault - found it.
I've attached log file for one day only, but I suppose that it should be enough.

These crashes were just after the mentioned query:
170319 12:01:31 [ERROR] mysqld got signal 11 ;
170319 12:44:57 [ERROR] mysqld got signal 11 ;

Comment by Daniel Black [ 2017-04-22 ]

2017-03-19 21:11:45 Assertion failure too

Comment by Elena Stepanova [ 2017-05-12 ]

Most of crash reports in the log don't have any stack trace at all, below are those that have at least something.

170319 16:08:18 (note that it happened on KILL_CONNECTION)

/usr/sbin/mysqld(handle_fatal_signal+0x522)[0x7faea45a9da2]
/lib64/libpthread.so.0(+0xf7e0)[0x7faea3bb27e0]
/usr/sbin/mysqld(_ZN10Field_long5storeExb+0x53)[0x7faea4598eb3]
/usr/sbin/mysqld(_ZN15store_key_field10copy_innerEv+0x24)[0x7faea446a9d4]
/usr/sbin/mysqld(_Z18cp_buffer_from_refP3THDP5TABLEP12st_table_ref+0x92)[0x7faea4436822]
/usr/sbin/mysqld(_Z14join_read_key2P3THDP13st_join_tableP5TABLEP12st_table_ref+0xce)[0x7faea4442c7e]
/usr/sbin/mysqld(_Z10sub_selectP4JOINP13st_join_tableb+0x158)[0x7faea444a578]
/usr/sbin/mysqld(+0x460a2f)[0x7faea4442a2f]
/usr/sbin/mysqld(_Z10sub_selectP4JOINP13st_join_tableb+0x18a)[0x7faea444a5aa]
/usr/sbin/mysqld(+0x460a2f)[0x7faea4442a2f]
/usr/sbin/mysqld(_Z10sub_selectP4JOINP13st_join_tableb+0x18a)[0x7faea444a5aa]
/usr/sbin/mysqld(+0x460a2f)[0x7faea4442a2f]
/usr/sbin/mysqld(_Z10sub_selectP4JOINP13st_join_tableb+0x18a)[0x7faea444a5aa]
/usr/sbin/mysqld(+0x460a2f)[0x7faea4442a2f]
/usr/sbin/mysqld(_Z10sub_selectP4JOINP13st_join_tableb+0x18a)[0x7faea444a5aa]
/usr/sbin/mysqld(+0x460a2f)[0x7faea4442a2f]
/usr/sbin/mysqld(_Z10sub_selectP4JOINP13st_join_tableb+0x18a)[0x7faea444a5aa]
/usr/sbin/mysqld(+0x46cee5)[0x7faea444eee5]
2017-03-19 16:09:27 140377801071360 [Note] /usr/sbin/mysqld: Normal shutdown
 
2017-03-19 16:09:27 140377801071360 [Note] Event Scheduler: Purging the queue. 0 events
2017-03-19 16:09:47 140377801071360 [Warning] /usr/sbin/mysqld: Forcing close of thread 140217  user: 'comua120_usr'
 
2017-03-19 16:09:47 140377801071360 [ERROR] mysqld: Got an error writing communication packets
/usr/sbin/mysqld(_ZN4JOIN10exec_innerEv+0x8e0)[0x7faea4466620]
/usr/sbin/mysqld(_ZN4JOIN4execEv+0x5d)[0x7faea446864d]
/usr/sbin/mysqld(_Z12mysql_selectP3THDPPP4ItemP10TABLE_LISTjR4ListIS1_ES2_jP8st_orderSB_S2_SB_yP13select_resultP18st_select_lex_unitP13st_select_lex+0x12a)[0x7faea44687fa]
/usr/sbin/mysqld(_Z13handle_selectP3THDP3LEXP13select_resultm+0x266)[0x7faea44695f6]
/usr/sbin/mysqld(+0x4263ff)[0x7faea44083ff]
/usr/sbin/mysqld(_Z21mysql_execute_commandP3THD+0x6077)[0x7faea44128c7]
/usr/sbin/mysqld(_Z11mysql_parseP3THDPcjP12Parser_state+0x3a0)[0x7faea44156c0]
/usr/sbin/mysqld(_Z16dispatch_command19enum_server_commandP3THDPcj+0x2413)[0x7faea4418933]
/usr/sbin/mysqld(_Z10do_commandP3THD+0x178)[0x7faea4419188]
/usr/sbin/mysqld(_Z24do_handle_one_connectionP3THD+0x19f)[0x7faea44e579f]
/usr/sbin/mysqld(handle_one_connection+0x47)[0x7faea44e5947]
/lib64/libpthread.so.0(+0x7aa1)[0x7faea3baaaa1]
/lib64/libc.so.6(clone+0x6d)[0x7faea22c2aad]
 
Trying to get some variables.
Some pointers may be invalid and cause the dump to abort.
Query (0x7faa54274f20): SELECT fl.name feature_name, fp.id_feature, fv.id_feature_value, fvl.value,      COUNT(DISTINCT p.id_product) nbr,      lifl.url_name name_url_name, lifl.meta_title name_meta_title, lifvl.url_name value_url_name, lifvl.meta_title value_meta_title , psi.price_min, psi.price_max       FROM ps_feature_product fp      INNER JOIN ps_product p ON (p.id_product = fp.id_product)      LEFT JOIN ps_feature_lang fl ON (fl.id_feature = fp.id_feature AND fl.id_lang = 1)      INNER JOIN ps_feature_value fv ON (fv.id_feature_value = fp.id_feature_value AND (fv.custom IS NULL OR fv.custom = 0))      LEFT JOIN ps_feature_value_lang fvl ON (fvl.id_feature_value = fp.id_feature_value AND fvl.id_lang = 1)      LEFT JOIN ps_layered_indexable_feature_lang_value lifl      ON (lifl.id_feature = fp.id_feature AND lifl.id_lang = 1)      LEFT JOIN ps_layered_indexable_feature_value_lang_value lifvl      ON (lifvl.id_feature_value = fp.id_feature_value AND lifvl.id_lang = 1)  INNER JOIN ps_product_shop product_shop   ON (product_shop.id_product = p.id_product AND product_shop.id_shop = 1)     INNER JOIN `ps_layered_price_index` psi     ON (psi.id_product = p.id_product AND psi.id_currency = 1)  WHERE product_shop.`active` = 1 AND fp.id_feature = 25      AND p.id_product IN (      SELECT id_product      FROM ps_category_product cp      INNER JOIN ps_category c ON (c.id_category = cp.id_category AND      c.nleft >= 25      AND c.nright <= 50      AND c.active = 1))  AND p.id_product IN (SELECT id_product FROM ps_feature_product fp WHERE fp.`id_feature_value` = 32 OR fp.`id_feature_value` = 34 OR fp.`id_feature_value` = 35 OR fp.`id_feature_value` = 36 OR fp.`id_feature_value` = 38 OR fp.`id_feature_value` = 39 OR fp.`id_feature_value` = 86)  AND p.id_product IN (SELECT id_product FROM ps_feature_product fp WHERE fp.`id_feature_value` = 54 OR fp.`id_feature_value` = 55)  AND p.id_product IN (SELECT id_product FROM ps_feature_product fp WHERE fp.`id_feature_value` = 20 OR fp.`id_feature_value` = 21)  AND p.id_product IN (SELECT id_product FROM ps_feature_product fp WHERE fp.`id_feature_value` = 22 OR fp.`id_feature_value` = 30 OR fp.`id_feature_value` = 61)  AND p.id_product IN (SELECT id_product FROM ps_feature_product fp WHERE fp.`id_feature_value` = 47 OR fp.`id_feature_value` = 52)  AND p.id_product IN (SELECT id_product FROM ps_feature_product fp WHERE fp.`id_feature_value` = 63)  GROUP BY fv.id_feature_value
Connection ID (thread ID): 140217
Status: KILL_CONNECTION
 
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

2017-03-19 21:21:32

InnoDB: Warning: Index PRIMARY points to table  and ib_table photonai_wp653/wpck_options statistics is initialized 1  but index table  initialized 0  mysql table is wpck_options. Have you mixed up .frm files from different installations? See http://dev.mysql.com/doc/refman/5.6/en/innodb-troubleshooting.html
2017-03-19 21:21:32 7f2dc8de4b00  InnoDB: Assertion failure in thread 139834620267264 in file dict0stats.cc line 3292
InnoDB: Failing assertion: strchr(table->name, '/') != NULL

2017-03-19 21:21:32

InnoDB: Warning: Index PRIMARY points to table  and ib_table photonai_wp653/wpck_options statistics is initialized 1  but index table  initialized 0  mysql table is wpck_options. Have you mixed up .frm files from different installations? See http://dev.mysql.com/doc/refman/5.6/en/innodb-troubleshooting.html
2017-03-19 21:21:32 7f2dc8de4b00  InnoDB: Assertion failure in thread 139834620267264 in file dict0stats.cc line 3292
InnoDB: Failing assertion: strchr(table->name, '/') != NULL

Comment by Elena Stepanova [ 2017-05-12 ]

noonedeadpunk,

Once it has started happening, does it happen every time when you execute this query?
I see from the log that you are using a custom build, could you please share the build options and the compiler version?
Please also attach your cnf file(s).
Thanks.

Comment by Sergei Golubchik [ 2017-06-12 ]

No feedback for a month, closing.

If you have some information to add, please, don't hesitate to add a it in a comment and the bug can be reopened.

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