[MDEV-8388] MariaDB crashed Created: 2015-06-27  Updated: 2015-10-22  Resolved: 2015-10-22

Status: Closed
Project: MariaDB Server
Component/s: Optimizer, Storage Engine - InnoDB
Affects Version/s: 10.0.20
Fix Version/s: N/A

Type: Bug Priority: Major
Reporter: Mikhail Gavrilov Assignee: Unassigned
Resolution: Cannot Reproduce Votes: 0
Labels: None

Attachments: File appl_profile_doc.ibd     File appl_profile_doc.sql     File mariadb.log     File mariadb.log     File mysqlcheck.log     Text File variables.txt     File vmi25208.contabo.net.err    

 Description   

150625 21:40:52 [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 http://kb.askmonty.org/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.0.19-MariaDB
key_buffer_size=134217728
read_buffer_size=131072
max_used_connections=1
max_threads=153
thread_count=1
It is possible that mysqld could use up to 
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 467005 K  bytes of memory
Hope that's ok; if not, decrease some variables in the equation.
 
Thread pointer: 0x0x7ff6bd068e88
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 = 0x7ff6bb7d9dc0 thread_stack 0x48000
/usr/libexec/mysqld(my_print_stacktrace+0x3d)[0x7ff6bb28e37d]
/usr/libexec/mysqld(handle_fatal_signal+0x33d)[0x7ff6bae06e3d]
/lib64/libpthread.so.0(+0x3775a10430)[0x7ff6ba4a9430]
/usr/libexec/mysqld(+0x8688a4)[0x7ff6bb1408a4]
/usr/libexec/mysqld(+0x7b51b2)[0x7ff6bb08d1b2]
/usr/libexec/mysqld(_ZN7handler27multi_range_read_info_constEjP15st_range_seq_ifPvjPjS3_P13Cost_estimate+0x17c)[0x7ff6bad9b74c]
/usr/libexec/mysqld(_ZN10DsMrr_impl16dsmrr_info_constEjP15st_range_seq_ifPvjPjS3_P13Cost_estimate+0x50)[0x7ff6bad9db30]
/usr/libexec/mysqld(+0x602a8f)[0x7ff6baedaa8f]
/usr/libexec/mysqld(+0x602f3d)[0x7ff6baedaf3d]
/usr/libexec/mysqld(_ZN10SQL_SELECT17test_quick_selectEP3THD6BitmapILj64EEyybb+0x828)[0x7ff6baeecff8]
/usr/libexec/mysqld(_Z12mysql_updateP3THDP10TABLE_LISTR4ListI4ItemES6_PS4_jP8st_ordery15enum_duplicatesbPySB_+0x6ba)[0x7ff6bad3f82a]
/usr/libexec/mysqld(_Z21mysql_execute_commandP3THD+0x3694)[0x7ff6baca8d64]
/usr/libexec/mysqld(_Z11mysql_parseP3THDPcjP12Parser_state+0x203)[0x7ff6bacaccd3]
/usr/libexec/mysqld(_Z16dispatch_command19enum_server_commandP3THDPcj+0x19d1)[0x7ff6bacae701]
/usr/libexec/mysqld(_Z24do_handle_one_connectionP3THD+0x1e2)[0x7ff6bad72b82]
/usr/libexec/mysqld(handle_one_connection+0x40)[0x7ff6bad72c20]
/lib64/libpthread.so.0(+0x3775a07555)[0x7ff6ba4a0555]
/lib64/libc.so.6(clone+0x6d)[0x7ff6b8a37f3d]
 
Trying to get some variables.
Some pointers may be invalid and cause the dump to abort.
Query (0x7ff678004c60): update `taganka-demo`.`appl_profile_doc` set `series` = '1' , `number` = '1' , `date_of_issue` = '2015-06-12' where `id_doc` = '6b5cb828-e89e-11e4-a546-0050563c3a6d' and `id_profile` = '6b4183ee-e89e-11e4-a546-0050563c3a6d' and `id_doc_type` = '1' and `series` is null and `number` is null and `date_of_issue` is null and `date_of_expire` is null and `authority` is null and `subdivision_code` is null and `priority_type` is null and `ldate` is null and `mdate` = '2015-04-22 05:19:43'
Connection ID (thread ID): 3
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



 Comments   
Comment by Mikhail Gavrilov [ 2015-06-27 ]

This crash unreproduceable on database copy on same server.

Comment by Elena Stepanova [ 2015-06-29 ]

mikhail,

The "database copy on same server" – do you mean another instance of MariaDB (another mysqld process) on the same physical server, or another schema inside the same MariaDB instance? If you mean the first variant, did you make sure you were using the same exact config?
Can you please attach the config file(s) and paste the output of

SHOW CREATE TABLE `taganka-demo`.`appl_profile_addr`;
SHOW INDEX IN `taganka-demo`.`appl_profile_addr`;
SHOW TABLE STATUS IN `taganka-demo` LIKE 'appl_profile_addr';

If the output appears to be confidential, you can upload it to our ftp.askmonty.org/private.
Even better if you can upload the complete dump of this table.
Thanks.

Comment by Mikhail Gavrilov [ 2015-06-29 ]

@Also, the "database copy on same server" – do you mean another instance of MariaDB (another mysqld process) on the same physical server, or another schema inside the same MariaDB instance? If you mean the first variant, did you make sure you were using the same exact config?

I means another schema inside the same MariaDB instance.
Ok, I demonstrate it:

$ mysql -uroot
MariaDB [(none)]> UPDATE 
    ->   `taganka-demo`.`appl_profile_doc` 
    -> SET
    ->   `series` = '7'
    -> WHERE `id_doc` = '6b5cb828-e89e-11e4-a546-0050563c3a6d' 
    ->   AND `id_profile` = '6b4183ee-e89e-11e4-a546-0050563c3a6d';
ERROR 2013 (HY000): Lost connection to MySQL server during query
MariaDB [(none)]> CREATE TABLE   `taganka-demo`.`appl_profile_doc_temp` SELECT * FROM  `taganka-demo`.`appl_profile_doc`;
ERROR 2006 (HY000): MySQL server has gone away
No connection. Trying to reconnect...
Connection id:    3
Current database: *** NONE ***
 
Query OK, 9 rows affected, 1 warning (0.04 sec)
Records: 9  Duplicates: 0  Warnings: 1
MariaDB [(none)]> UPDATE 
    ->   `taganka-demo`.`appl_profile_doc_temp` 
    -> SET
    ->   `series` = '7'
    -> WHERE `id_doc` = '6b5cb828-e89e-11e4-a546-0050563c3a6d' 
    ->   AND `id_profile` = '6b4183ee-e89e-11e4-a546-0050563c3a6d';
Query OK, 1 row affected (0.00 sec)
Rows matched: 1  Changed: 1  Warnings: 0
MariaDB [(none)]> quit;

1. Copy of table wich ireated with CREATE TABLE ... SELECT * FROM ... ; no reproduceable
Let's try reproduce on database restored from SQL dump:

$ mysqldump -u root -R taganka-demo > dump.sql
$ mysql -uroot
MariaDB [(none)]>   CREATE DATABASE `taganka-demo3`;
Query OK, 1 row affected (0.07 sec)
MariaDB [(none)]> quit;
$ mysql -u root taganka-demo3 < dump.sql
$ mysql -uroot
MariaDB [(none)]> UPDATE 
    ->   `taganka-demo3`.`appl_profile_doc` 
    -> SET
    ->   `series` = '7'
    -> WHERE `id_doc` = '6b5cb828-e89e-11e4-a546-0050563c3a6d' 
    ->   AND `id_profile` = '6b4183ee-e89e-11e4-a546-0050563c3a6d';
Query OK, 1 row affected (0.01 sec)
Rows matched: 1  Changed: 1  Warnings: 0

Works fine.

@Can you please attach the config file(s) and paste the output of

MariaDB [(none)]> SHOW CREATE TABLE `taganka-demo`.`appl_profile_doc`
    -> ;
+------------------+------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
| Table            | Create Table                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                               |
+------------------+------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
| appl_profile_doc | CREATE TABLE `appl_profile_doc` (
  `id_doc` varbinary(36) NOT NULL,
  `id_profile` varbinary(36) NOT NULL,
  `id_doc_type` int(10) unsigned NOT NULL,
  `series` varchar(15) NOT NULL,
  `number` varchar(15) NOT NULL,
  `date_of_issue` date NOT NULL,
  `date_of_expire` date DEFAULT NULL,
  `authority` varchar(150) DEFAULT NULL,
  `subdivision_code` varchar(15) DEFAULT NULL,
  `priority_type` varchar(40) DEFAULT NULL,
  `ldate` timestamp NULL DEFAULT NULL COMMENT 'время загрузки из агент модуля',
  `mdate` timestamp NOT NULL DEFAULT CURRENT_TIMESTAMP ON UPDATE CURRENT_TIMESTAMP COMMENT 'время последнего обновления',
  UNIQUE KEY `id_doc` (`id_doc`),
  KEY `id_doc_type` (`id_doc_type`),
  KEY `crm_profile_doc_ibfk_1` (`id_profile`)
) ENGINE=InnoDB DEFAULT CHARSET=utf8                                                    |
+------------------+------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
1 row in set (0.00 sec)
 
MariaDB [(none)]> SHOW INDEX IN `taganka-demo`.`appl_profile_doc`;
+------------------+------------+------------------------+--------------+-------------+-----------+-------------+----------+--------+------+------------+---------+---------------+
| Table            | Non_unique | Key_name               | Seq_in_index | Column_name | Collation | Cardinality | Sub_part | Packed | Null | Index_type | Comment | Index_comment |
+------------------+------------+------------------------+--------------+-------------+-----------+-------------+----------+--------+------+------------+---------+---------------+
| appl_profile_doc |          0 | id_doc                 |            1 | id_doc      | A         |           9 |     NULL | NULL   |      | BTREE      |         |               |
| appl_profile_doc |          1 | id_doc_type            |            1 | id_doc_type | A         |           2 |     NULL | NULL   |      | BTREE      |         |               |
| appl_profile_doc |          1 | crm_profile_doc_ibfk_1 |            1 | id_profile  | A         |           9 |     NULL | NULL   |      | BTREE      |         |               |
+------------------+------------+------------------------+--------------+-------------+-----------+-------------+----------+--------+------+------------+---------+---------------+
3 rows in set (0.00 sec)
 
MariaDB [(none)]> SHOW TABLE STATUS IN `taganka-demo` LIKE 'appl_profile_doc';
+------------------+--------+---------+------------+------+----------------+-------------+-----------------+--------------+-----------+----------------+---------------------+-------------+------------+-----------------+----------+----------------+---------+
| Name             | Engine | Version | Row_format | Rows | Avg_row_length | Data_length | Max_data_length | Index_length | Data_free | Auto_increment | Create_time         | Update_time | Check_time | Collation       | Checksum | Create_options | Comment |
+------------------+--------+---------+------------+------+----------------+-------------+-----------------+--------------+-----------+----------------+---------------------+-------------+------------+-----------------+----------+----------------+---------+
| appl_profile_doc | InnoDB |      10 | Compact    |    9 |           1820 |       16384 |               0 |        49152 |         0 |           NULL | 2015-06-25 22:42:22 | NULL        | NULL       | utf8_general_ci |     NULL |                |         |
+------------------+--------+---------+------------+------+----------------+-------------+-----------------+--------------+-----------+----------------+---------------------+-------------+------------+-----------------+----------+----------------+---------+
1 row in set (0.07 sec)

@Even better if you can upload the complete dump of this table.
Are you means SQL dump? Or appl_profile_doc.ibd file from /var/lib/mysql/taganka@002ddemo?

Comment by Elena Stepanova [ 2015-06-29 ]

You cannot experiment with CREATE TABLE ... AS SELECT, it makes no sense. This way the table won't have any indexes, the execution path will be completely different.
Instead, you need to do CREATE TABLE .. LIKE ..; INSERT INTO ... SELECT * FROM ....

And yes, I meant the SQL dump. But I see that it's a really tiny table, if you can, just copy the output of {{SELECT * FROM }} and put it either here or in ftp.askmonty.org/private.
And please don't forget the cnf file (or the output of SHOW VARIABLES if it's easier for you).

Comment by Elena Stepanova [ 2015-06-29 ]

Thanks for the data.

Sorry I didn't see it before, your error log is full of errors and warnings about this table being corrupted:

150627  7:47:03 [Warning] Table ./taganka@002ddemo/appl_profile_addr key_used_on_scan is 0 even though there is no primary key inside InnoDB.
150627  7:47:03 [ERROR] Table ./taganka@002ddemo/appl_profile_contact has no primary key in InnoDB data dictionary, but has one in MySQL! If you created the table with a MySQL version < 3.23.54 and did not define a primary key, but defined a unique key with all non-NULL columns, then MySQL internally treats that key as the primary key. You can fix this error by dump + DROP + CREATE + reimport of the table.

I don't suppose you actually created the table with MySQL < 3.23.54 as the error text suggests, but is it possible that you moved the ibd file around, used it as a backup, something like that, and ended up using it on a table with a different structure?

Comment by Mikhail Gavrilov [ 2015-06-29 ]

No, I never restored from backup this ibd file, and I am see this message too.
I am try also fix this with

  1. mysqlcheck --auto-repair taganka-demo
    but without success.

P.S. After each database upgrade I run # mysql_upgrade

Comment by Elena Stepanova [ 2015-06-29 ]

The easiest way to restore the table would be to use the SQL dump that you provided – you can check it in a different schema first, and if it works all right, just drop the corrupted table and use the new one.
There is no surprise that an update fails on the corrupted table, I also get various crashes (although not the exact same one) while trying to use your ibd file instead of mine.

It would be very interesting to find out how the inconsistency started, do you have any idea when it began, and what happened right before that?

Comment by Mikhail Gavrilov [ 2015-06-29 ]

@It would be very interesting to find out how the inconsistency started, do you have any idea when it began, and what happened right before that?

I understand, but very difficult to say when it broke.
Because that in real life application server only uses id_doc to update this table.
This deadly combination found SQLyog. If the table has no PK, then this program writes all columns in the condition if you try to edit the contents of the table through the grid.

Comment by Elena Stepanova [ 2015-07-29 ]

mikhail,

Did you manage to fix/restore the table? Have you experienced the problem since then?

Comment by Mikhail Gavrilov [ 2015-08-07 ]

Which utility can fix/restore table?

When I launch first time mysqlcheck -A --auto-repair show warnings:

taganka-demo.appl_profile_account
Warning  : InnoDB: Table ./taganka@002ddemo/appl_profile_account has no primary key in InnoDB data dictionary, but has one in MySQL!
status   : OK
taganka-demo.appl_profile_addr
Warning  : InnoDB: Table ./taganka@002ddemo/appl_profile_addr has no primary key in InnoDB data dictionary, but has one in MySQL!
status   : OK
taganka-demo.appl_profile_contact
Warning  : InnoDB: Table ./taganka@002ddemo/appl_profile_contact has no primary key in InnoDB data dictionary, but has one in MySQL!
status   : OK
taganka-demo.appl_profile_doc
Warning  : InnoDB: Table ./taganka@002ddemo/appl_profile_doc has no primary key in InnoDB data dictionary, but has one in MySQL!
status   : OK

after second run this messages is gone, but after restart mariadb they returned again

Comment by Elena Stepanova [ 2015-08-07 ]

mikhail,

As said above, in this case the easiest way to restore the table would be to use the SQL dump that you provided – you can check it in a different schema first, and if it works all right, just drop the corrupted table and use the new one.

Comment by Mikhail Gavrilov [ 2015-08-07 ]

In comment comment-72914 I am said that already doing this. (create and restore from dump, after it problem is gone, means became non reproducible)

I thought it would be interesting to understand why the server is crashed, because is not really good when all running parallel queries terminated when it occurs. (for experiments I make copy database folder and restore on my home computer for investigation)

Comment by Elena Stepanova [ 2015-08-07 ]

mikhail,

In comment comment-72914 I am said that already doing this. (create and restore from dump, after it problem is gone, means became non reproducible)

Yes, I know. What I meant was, I assume you have been using the restored table for a while now, did you have any problems since then? Did the table become corrupted again, or did you see any error messages in the error log, etc.?

I thought it would be interesting to understand why the server is crashed, because is not really good when all running parallel queries terminated when it occurs. (for experiments I make copy database folder and restore on my home computer for investigation)

Yes, indeed, it is very interesting and important, too, but as you correctly pointed out in the comment-72933, it's going to be difficult since we don't know when the problem started and how the table got corrupted.
Still, even though the table is corrupted, it's no good that the server actually crashes. It could have been acceptable if it gracefully went down, but crashes could cause further corruption. I will try to imitate it by tampering with the data, and if I manage to do it, we'll see if anything can be done about it.

Comment by Elena Stepanova [ 2015-10-22 ]

I cannot reproduce this exact crash.

In any case, I suppose it's reasonable to expect that the server can crash randomly on a corrupted data.

It's easy enough to corrupt data in a similar fashion and make InnoDB throw errors about the missing key by tampering with ibdata and ibd files: create a table with an ordinary non-unique key, store ibdata/ibd, then create the table with the unique key, shutdown server, replace ibdata/ibd with the stored ones, start server. But then the server either works or goes down with InnoDB assertion failures.

The question how the data got corrupted in the first place remains open. If it were about one table only, we could suspect that at some point the server crashed on some ALTER TABLE, and left the data in an inconsistent state; but according to the logs, several tables are similarly affected (and updates on them crash in the similar fashion):

50625 22:56:44 [ERROR] Table ./taganka@002ddemo/appl_profile_account has no primary key in InnoDB data dictionary, but has one in MySQL! If you created the table with a MySQL version < 3.23.54 and did not define a primary key, but defined a unique key with all non-NULL columns, then MySQL internally treats that key as the primary key. You can fix this error by dump + DROP + CREATE + reimport of the table.
150625 22:56:44 [Warning] Table ./taganka@002ddemo/appl_profile_account key_used_on_scan is 0 even though there is no primary key inside InnoDB.
150625 22:56:44 [ERROR] Table ./taganka@002ddemo/appl_profile_addr has no primary key in InnoDB data dictionary, but has one in MySQL! If you created the table with a MySQL version < 3.23.54 and did not define a primary key, but defined a unique key with all non-NULL columns, then MySQL internally treats that key as the primary key. You can fix this error by dump + DROP + CREATE + reimport of the table.
150625 22:56:44 [Warning] Table ./taganka@002ddemo/appl_profile_addr key_used_on_scan is 0 even though there is no primary key inside InnoDB.
150625 22:56:44 [ERROR] Table ./taganka@002ddemo/appl_profile_contact has no primary key in InnoDB data dictionary, but has one in MySQL! If you created the table with a MySQL version < 3.23.54 and did not define a primary key, but defined a unique key with all non-NULL columns, then MySQL internally treats that key as the primary key. You can fix this error by dump + DROP + CREATE + reimport of the table.
150625 22:56:44 [Warning] Table ./taganka@002ddemo/appl_profile_contact key_used_on_scan is 0 even though there is no primary key inside InnoDB.
150625 22:56:44 [ERROR] Table ./taganka@002ddemo/appl_profile_doc has no primary key in InnoDB data dictionary, but has one in MySQL! If you created the table with a MySQL version < 3.23.54 and did not define a primary key, but defined a unique key with all non-NULL columns, then MySQL internally treats that key as the primary key. You can fix this error by dump + DROP + CREATE + reimport of the table.
150625 22:56:44 [Warning] Table ./taganka@002ddemo/appl_profile_doc key_used_on_scan is 0 even though there is no primary key inside InnoDB.

There are too many tables here to think that it was a runtime crash or a hardware failure. Besides, there are other oddities, e.g. updates have many is null conditions for columns which are not-nullable in the current table structure, so these updates should be void (with "impossible where"), yet they apparently attempt to do something.

The most viable theory would be a flaw in backup/restore process, when InnoDB files were overwritten erroneously, but it was declined in earlier comments, so I'm afraid the reason why it happened is going to stay a mystery, at least for now.
The only thing we can assume is that it happened some time between 11.05.2015 (that's where vmi25208.contabo.net.err ends), and 25.06.2015 – that's when the attached fragments of mysql.log start.

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