Bug #74400 | MySQL server has gone away on query | ||
---|---|---|---|
Submitted: | 15 Oct 2014 12:19 | Modified: | 16 Oct 2014 13:52 |
Reporter: | Jean-François CUINET | Email Updates: | |
Status: | Can't repeat | Impact on me: | |
Category: | MySQL Server | Severity: | S1 (Critical) |
Version: | 5.6.21-log | OS: | Any |
Assigned to: | CPU Architecture: | Any |
[15 Oct 2014 12:19]
Jean-François CUINET
[15 Oct 2014 12:31]
Peter Laursen
No problem here when executing against a local Win7/64 5.6.21 server. And I get the expected result as well. -- Peter -- Not a MySQL person
[15 Oct 2014 13:56]
MySQL Verification Team
I could not repeat: c:\Program Files\MySQL\MySQL Server 5.6>bin\mysql -uroot -p Enter password: ****** Welcome to the MySQL monitor. Commands end with ; or \g. Your MySQL connection id is 1 Server version: 5.6.21-log MySQL Community Server (GPL) Copyright (c) 2000, 2014, Oracle and/or its affiliates. All rights reserved. Oracle is a registered trademark of Oracle Corporation and/or its affiliates. Other names may be trademarks of their respective owners. Type 'help;' or '\h' for help. Type '\c' to clear the current input statement. mysql> USE test Database changed mysql> CREATE TABLE IF NOT EXISTS `st_fcon` ( -> `cd_typc` char(1) COLLATE cp850_bin NOT NULL COMMENT 'Code C=Client/F=Fournisseur', -> `cd_prov` char(10) COLLATE cp850_bin NOT NULL COMMENT 'Code Client / Fournisseur', -> `cd_cont` char(10) COLLATE cp850_bin NOT NULL COMMENT 'Code du contact', -> `nm_cont` char(30) CHARACTER SET cp850 NOT NULL COMMENT 'Nom du contact', -> PRIMARY KEY (`cd_typc`,`cd_prov`,`cd_cont`), -> FULLTEXT KEY `ksfcon01` (`nm_cont`) -> ) ENGINE=InnoDB DEFAULT CHARSET=cp850 COLLATE=cp850_bin; Query OK, 0 rows affected (1.61 sec) mysql> mysql> INSERT INTO `st_fcon` (`cd_typc`, `cd_prov`, `cd_cont`, `nm_cont`) VALUES('C', '0000000025', 'AKA78', 'A.PILIN'); Query OK, 1 row affected (0.03 sec) mysql> INSERT INTO `st_fcon` (`cd_typc`, `cd_prov`, `cd_cont`, `nm_cont`) VALUES('P', '0000000002', 'ARC45', 'ARCOS'); Query OK, 1 row affected (0.02 sec) mysql> INSERT INTO `st_fcon` (`cd_typc`, `cd_prov`, `cd_cont`, `nm_cont`) VALUES('P', '0000000002', 'RP45', 'P.RESPINGOS Query OK, 1 row affected (0.04 sec) mysql> INSERT INTO `st_fcon` (`cd_typc`, `cd_prov`, `cd_cont`, `nm_cont`) VALUES('P', '0000000003', 'BELU4', 'BELUGA'); Query OK, 1 row affected (0.02 sec) mysql> INSERT INTO `st_fcon` (`cd_typc`, `cd_prov`, `cd_cont`, `nm_cont`) VALUES('P', '0000000006', 'ALBR49', 'ALBERTUS' Query OK, 1 row affected (0.04 sec) mysql> mysql> CREATE TABLE IF NOT EXISTS `st_pros` ( -> `strProspectCode` char(10) COLLATE cp850_bin NOT NULL COMMENT 'Code prospect', -> `strProspectName` char(35) CHARACTER SET cp850 NOT NULL COMMENT 'Nom du prospect', -> PRIMARY KEY (`strProspectCode`) -> ) ENGINE=InnoDB DEFAULT CHARSET=cp850 COLLATE=cp850_bin; Query OK, 0 rows affected (0.25 sec) mysql> mysql> INSERT INTO `st_pros` (`strProspectCode`, `strProspectName`) VALUES('0000000001', 'IRIS'); Query OK, 1 row affected (0.01 sec) mysql> INSERT INTO `st_pros` (`strProspectCode`, `strProspectName`) VALUES('0000000002', 'BELIN'); Query OK, 1 row affected (0.02 sec) mysql> INSERT INTO `st_pros` (`strProspectCode`, `strProspectName`) VALUES('0000000003', 'PHILIPPE'); Query OK, 1 row affected (0.03 sec) mysql> INSERT INTO `st_pros` (`strProspectCode`, `strProspectName`) VALUES('0000000004', 'SAMSOS'); Query OK, 1 row affected (0.03 sec) mysql> mysql> SELECT st_pros.strProspectCode -> FROM st_pros -> LEFT JOIN st_fcon ON st_fcon.cd_typc = 'P' AND st_fcon.cd_prov = st_pros.strProspectCode -> WHERE st_fcon.nm_cont LIKE 'A%' -> AND MATCH st_fcon.nm_cont AGAINST ('A*' IN BOOLEAN MODE) -> ORDER BY st_pros.strProspectName; +-----------------+ | strProspectCode | +-----------------+ | 0000000002 | +-----------------+ 1 row in set (0.03 sec) mysql>
[15 Oct 2014 14:48]
Jean-François CUINET
Without order, MySQL don't crash but the result is empty : SELECT st_pros.strProspectCode FROM st_pros LEFT JOIN st_fcon ON st_fcon.cd_typc = 'P' AND st_fcon.cd_prov = st_pros.strProspectCode WHERE st_fcon.nm_cont LIKE 'A%' AND MATCH st_fcon.nm_cont AGAINST ('A*' IN BOOLEAN MODE) I think there is a problem with null data in join.
[15 Oct 2014 14:53]
Peter Laursen
Then the optimizer switch setting may matter (my best idea). Mine is (default I think)"index_merge=on,index_merge_union=on,index_merge_sort_union=on,index_merge_intersection=on,engine_condition_pushdown=on,index_condition_pushdown=on,mrr=on,mrr_cost_based=on,block_nested_loop=on,batched_key_access=off,materialization=on,semijoin=on,loosescan=on,firstmatch=on,subquery_materialization_cost_based=on,use_index_extensions=on" (as returned by "SHOW VARIABLES LIKE 'optimizer_switch';")
[15 Oct 2014 15:02]
Jean-François CUINET
Thank's for your response. The value for optimizer_switch is : index_merge=on,index_merge_union=on,index_merge_sort_union=on,index_merge_intersection=on,engine_condition_pushdown=on,index_condition_pushdown=on,mrr=on,mrr_cost_based=on,block_nested_loop=on,batched_key_access=off,materialization=on,semijoin=on,loosescan=on,firstmatch=on,subquery_materialization_cost_based=on,use_index_extensions=on
[15 Oct 2014 15:10]
Jean-François CUINET
Another example : SELECT st_pros.strProspectCode, st_fcon.nm_cont FROM st_pros left JOIN st_fcon ON st_fcon.cd_typc = 'P' AND st_fcon.cd_prov = st_pros.strProspectCode The result is (it's good) : strProspectCode nm_cont 0000000001 NULL 0000000002 ARCOS 0000000002 P.RESPINGOS 0000000003 BELUGA 0000000004 NULL With where condition on field nm_cont : SELECT st_pros.strProspectCode, st_fcon.nm_cont FROM st_pros left JOIN st_fcon ON st_fcon.cd_typc = 'P' AND st_fcon.cd_prov = st_pros.strProspectCode where st_fcon.nm_cont like 'A%' MySQL don't crash but the result is empty. It's not good, the result should be : strProspectCode nm_cont 0000000002 ARCOS
[15 Oct 2014 16:01]
MySQL Verification Team
I also couldn't repeat any problems. can we see the mysql error log crash info and my.cnf? is there a fulltext stopfile in use?
[15 Oct 2014 16:19]
Jean-François CUINET
For simplicity, I removed the full text index and i removed the match clause in query. The result is empty. CREATE TABLE IF NOT EXISTS `st_fcon` ( `cd_typc` char(1) COLLATE cp850_bin NOT NULL COMMENT 'Code C=Client/F=Fournisseur', `cd_prov` char(10) COLLATE cp850_bin NOT NULL COMMENT 'Code Client / Fournisseur', `cd_cont` char(10) COLLATE cp850_bin NOT NULL COMMENT 'Code du contact', `nm_cont` char(30) CHARACTER SET cp850 NOT NULL COMMENT 'Nom du contact', PRIMARY KEY (`cd_typc`,`cd_prov`,`cd_cont`) ) ENGINE=InnoDB DEFAULT CHARSET=cp850 COLLATE=cp850_bin COMMENT='Contacts'; INSERT INTO `st_fcon` (`cd_typc`, `cd_prov`, `cd_cont`, `nm_cont`) VALUES ('C', '0000000025', 'AKA78', 'A.PILIN'), ('P', '0000000002', 'ARC45', 'ARCOS'), ('P', '0000000002', 'RP45', 'P.RESPINGOS'), ('P', '0000000003', 'BELU4', 'BELUGA'), ('P', '0000000006', 'ALBR49', 'ALBERTUS'); CREATE TABLE IF NOT EXISTS `st_pros` ( `strProspectCode` char(10) COLLATE cp850_bin NOT NULL COMMENT 'Code prospect', `strProspectName` char(35) CHARACTER SET cp850 NOT NULL COMMENT 'Nom du prospect', PRIMARY KEY (`strProspectCode`) ) ENGINE=InnoDB DEFAULT CHARSET=cp850 COLLATE=cp850_bin COMMENT='Prospects'; INSERT INTO `st_pros` (`strProspectCode`, `strProspectName`) VALUES ('0000000001', 'IRIS'), ('0000000002', 'BELIN'), ('0000000003', 'PHILIPPE'), ('0000000004', 'SAMSOS'); SELECT st_pros.strProspectCode, st_fcon.nm_cont FROM st_pros left JOIN st_fcon ON st_fcon.cd_typc = 'P' AND st_fcon.cd_prov = st_pros.strProspectCode where st_fcon.nm_cont like 'A%'
[15 Oct 2014 16:20]
Jean-François CUINET
[mysqld] innodb_buffer_pool_size=3G innodb_log_file_size=1G innodb_file_per_table=1 innodb_flush_log_at_trx_commit=0 myisam-recover-options=BACKUP,FORCE ft_min_word_len=3 ft_stopword_file= join_buffer_size=50M key_buffer_size=512M max_connections=300 max_allowed_packet=32M max_sort_length=65536 max_prepared_stmt_count=32764 table_definition_cache=4096 table_open_cache=4096 max_tmp_tables=32M max_heap_table_size=32M thread_cache_size=100 slow_query_log=1 long_query_time=1 query_cache_size=64M
[15 Oct 2014 16:32]
Jean-François CUINET
The log when MySQL has gone away : 141015 18:24:20 mysqld_safe mysqld restarted 2014-10-15 18:24:21 0 [Warning] TIMESTAMP with implicit DEFAULT value is deprecated. Please use --explicit_defaults_for_timestamp server option (see documentation for more details). 2014-10-15 18:24:21 274472 [Note] Plugin 'FEDERATED' is disabled. 2014-10-15 18:24:21 274472 [Note] InnoDB: Using atomics to ref count buffer pool pages 2014-10-15 18:24:21 274472 [Note] InnoDB: The InnoDB memory heap is disabled 2014-10-15 18:24:21 274472 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins 2014-10-15 18:24:21 274472 [Note] InnoDB: GCC builtin __atomic_thread_fence() is used for memory barrier 2014-10-15 18:24:21 274472 [Note] InnoDB: Compressed tables use zlib 1.2.3 2014-10-15 18:24:21 274472 [Note] InnoDB: Not using CPU crc32 instructions 2014-10-15 18:24:21 274472 [Note] InnoDB: Initializing buffer pool, size = 3.0G 2014-10-15 18:24:23 274472 [Note] InnoDB: Completed initialization of buffer pool 2014-10-15 18:24:23 274472 [Note] InnoDB: Highest supported file format is Barracuda. 2014-10-15 18:24:23 274472 [Note] InnoDB: Log scan progressed past the checkpoint lsn 2899287452 2014-10-15 18:24:23 274472 [Note] InnoDB: Database was not shutdown normally! 2014-10-15 18:24:23 274472 [Note] InnoDB: Starting crash recovery. 2014-10-15 18:24:23 274472 [Note] InnoDB: Reading tablespace information from the .ibd files... 2014-10-15 18:24:24 274472 [Note] InnoDB: Restoring possible half-written data pages 2014-10-15 18:24:24 274472 [Note] InnoDB: from the doublewrite buffer... InnoDB: Doing recovery: scanned up to log sequence number 2899343683 2014-10-15 18:24:25 274472 [Note] InnoDB: Starting an apply batch of log records to the database... InnoDB: Progress in percent: 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 57 58 59 60 61 62 63 64 65 66 67 68 69 70 71 72 73 74 75 76 77 78 79 80 81 82 83 84 85 86 87 88 89 90 91 92 93 94 95 96 97 98 99 InnoDB: Apply batch completed 2014-10-15 18:24:26 274472 [Note] InnoDB: 128 rollback segment(s) are active. 2014-10-15 18:24:26 274472 [Note] InnoDB: 5.6.21 started; log sequence number 2899343683 2014-10-15 18:24:26 274472 [Note] Server hostname (bind-address): '*'; port: 3306 2014-10-15 18:24:26 274472 [Note] IPv6 is available. 2014-10-15 18:24:26 274472 [Note] - '::' resolves to '::'; 2014-10-15 18:24:26 274472 [Note] Server socket created on IP: '::'. 2014-10-15 18:24:26 274472 [Note] Event Scheduler: Loaded 0 events 2014-10-15 18:24:26 274472 [Note] /opt/freeware/mysql/bin/mysqld: ready for connections. Version: '5.6.21-log' socket: '/tmp/mysql.sock' port: 3306 MySQL Community Server (GPL)
[15 Oct 2014 16:58]
MySQL Verification Team
Sorry, I still cannot repeat it ;) My only guess is mysqld runs out of memory and kernel kills it (check /var/log/messages* for anything about that).
[16 Oct 2014 8:03]
Jean-François CUINET
There are only MySql running on this server and it has 8 GB of memory. No luck, I am the only one with this problem ?
[16 Oct 2014 8:13]
MySQL Verification Team
Was there any useful information in the mysql error log about a crash? The part you pasted is from after a restart already happened, however we need the previous lines to check if a crash happened. If mysqld is silently quitting without any crash info, it could be getting killed by something else.
[16 Oct 2014 8:35]
Jean-François CUINET
I tried to see the stack with gdb and core file generated when mysql crashed but it does not work very interesting. Core was generated by `mysqld'. Program terminated with signal 11, Segmentation fault. #0 0x000000010006cee8 in ?? () (gdb) bt #0 0x000000010006cee8 in ?? () #1 0x0000000100019c00 in ?? () #2 0x0000000100509ae4 in ?? () #3 0x0000000100509cb0 in ?? () #4 0x0000000100509cb0 in ?? () #5 0x0000000100509cb0 in ?? () #6 0x0000000100509cb0 in ?? () #7 0x0000000100509cb0 in ?? () #8 0x0000000100509cb0 in ?? () #9 0x0000000100509cb0 in ?? () #10 0x0000000100509cb0 in ?? () #11 0x0000000100509cb0 in ?? () #12 0x0000000100509cb0 in ?? () #13 0x0000000100509cb0 in ?? () #14 0x0000000100509cb0 in ?? () #15 0x0000000100509cb0 in ?? () #16 0x0000000100509cb0 in ?? () #17 0x0000000100509cb0 in ?? () #18 0x0000000100509cb0 in ?? () #19 0x0000000100509cb0 in ?? () #20 0x0000000100509cb0 in ?? () #21 0x0000000100509cb0 in ?? () #22 0x0000000100509cb0 in ?? () #23 0x0000000100509cb0 in ?? () #24 0x0000000100509cb0 in ?? () #25 0x0000000100509cb0 in ?? ()
[16 Oct 2014 8:51]
Jean-François CUINET
Shane, there is absolutely nothing in the log between the initial startup and reboot. If I execute the sql commands from the mysql client, I have the following messages on the screen (just after executing the sql commands): ERROR 2013 (HY000): Lost connection to MySQL server during query mysql> ./bin/mysqld_safe[20]: 208906 Memory fault(coredump) 141016 10:43:50 mysqld_safe mysqld restarted Is there a way to make more verbose mysql ?
[16 Oct 2014 9:50]
MySQL Verification Team
You could run mysqld inside gdb: gdb /opt/freeware/mysql/bin/mysqld set arg --defaults-file=/path/to/my.cnf --gdb --console run Then let it crash in debugger and see if stack trace is visible. Is there anything obscure about the OS or build? You can try putting "thread-stack=2M" into my.cnf and check if it survives the query without crashing?
[16 Oct 2014 13:52]
Jean-François CUINET
Ok, i've changed to unlimited the stack value (ulimit) and put "thread-stack=2M" into my.cnf Now MySql survives with example but the result is always empty. With the complete base, MySql still dies with signal 11. With mysqld inside gdb, the sql query run indefinitely.