[MDEV-9115] The Mysql server is gone when impoting a sql file Created: 2015-11-10  Updated: 2018-06-12  Resolved: 2018-06-12

Status: Closed
Project: MariaDB Server
Component/s: Server
Affects Version/s: 5.5.42, 10.1.8
Fix Version/s: N/A

Type: Bug Priority: Critical
Reporter: Steinar Gravem Assignee: Elena Stepanova
Resolution: Incomplete Votes: 0
Labels: innodb, need_feedback
Environment:

Windows server 2012


 Description   

We are moving a database from MySQL version 5.1.40sp1-enterprise-gpl-pro-log , to MariaDB 10.1.8, by using Mysqldump and the command 'mysql --password=xxx -u mybackup ik_db < e:\sqldump\ik_db_bu.sql' to move to the new database.
The old Mysql server use Encoding UTF-8 (65001), Database character set :latin 1--cp1252 Western European, Collation: latin1_swedish_ci.
The new Mariadb server use Encoding UTF-8 (65001),Database:character set : utf8 – UTF-8 Unicode, Collation: utf8_general_ci.
Most tables is transferred ok, however one table (Innodb) give the error: ERROR 2006 (HY000) at line 481: MySQL server has gone away.
The field where it stops is of type longblob.
By importing the sql dump to a new database on the old Mysql server, it runs ok without error messages.

 Comments   
Comment by Elena Stepanova [ 2015-11-11 ]

Are you using otherwise the same config file? Importantly, what are max_allowed_packet values for the old and the new server?
Can you provide SHOW VARIABLES output from both servers?

Comment by Elena Stepanova [ 2015-12-13 ]

Please comment to re-open if you have additional information

Comment by Aaron Greenspan [ 2018-02-07 ]

I am also having this problem with MariaDB Server 5.5.40-MariaDB-wsrep.

I have a script that generates INSERT statements with multiple segments (e.g. "INSERT INTO `table` VALUES ('a', 'b', 'c'), ('d', 'e', 'f'), ('g', 'h', 'i);")

SHOW VARIABLES LIKE 'max_allowed_packet';

says:

"Value: 1073741824"

So I should be able to execute any valid query up to 1GB in length.

When I try to run this INSERT query that has 374,129 segments and is 39,332,956 bytes in length (39MB, much less than 1GB), MariaDB says:

MySQL server has gone away

Then I have to wait for InnoDB to recover from the crash, wait for it to delete however many hundreds of thousands of rows that have been inserted already (which takes about an hour for 200,000 rows), and then wait for MariaDB to restart. I used to run this script on MySQL 5.7 Community Edition (and prior MySQL versions) and did not have this problem.

INSERT segments that do seem to work:

3,680 segments / 427,007 bytes
221,194 segments / 23,222,128 bytes

This leads me to believe that the problem is query size or memory related, but based on my understanding, it should still work so long as the query is less than max_packet_size.

Comment by Aaron Greenspan [ 2018-02-07 ]

I forgot to mention, here's what mariadb.log shows at the time that the MySQL server "goes away":

180206 19:25:30 mysqld_safe Number of processes running now: 0
 
180206 19:25:31 mysqld_safe mysqld restarted
 
180206 19:25:31 mysqld_safe WSREP: Running position recovery with --log_error='/var/lib/mysql/wsrep_recovery.EWCiJv' --pid-file='/var/lib/mysql/x.y.com-recover.pid'
 
180206 20:24:07 mysqld_safe WSREP: Recovered position 00000000-0000-0000-0000-000000000000:-1
 
180206 20:24:07 [Note] WSREP: wsrep_start_position var submitted: '00000000-0000-0000-0000-000000000000:-1'
 
180206 20:24:07 InnoDB: Mutexes and rw_locks use GCC atomic builtins
 
180206 20:24:07 InnoDB: Compressed tables use zlib 1.2.7
 
180206 20:24:07 InnoDB: Using Linux native AIO
 
180206 20:24:07 InnoDB: Initializing buffer pool, size = 16.0G
 
180206 20:24:07 InnoDB: Completed initialization of buffer pool
 
180206 20:24:07 InnoDB: highest supported file format is Barracuda.
 
180206 20:24:09  InnoDB: Waiting for the background threads to start
 
180206 20:24:10 Percona XtraDB (http://www.percona.com) 5.5.40-MariaDB-36.1 started; log sequence number 244480819686
 
180206 20:24:10 [Note] Plugin 'FEEDBACK' is disabled.
 
180206 20:24:10 [Note] Server socket created on IP: '0.0.0.0'.
 
180206 20:24:11 [Note] Event Scheduler: Loaded 0 events
 
180206 20:24:11 [Note] WSREP: Read nil XID from storage engines, skipping position init
 
180206 20:24:11 [Note] WSREP: wsrep_load(): loading provider library 'none'
 
180206 20:24:11 [Note] /usr/libexec/mysqld: ready for connections.
 
Version: '5.5.40-MariaDB-wsrep'  socket: '/var/lib/mysql/mysql.sock'  port: 3306  MariaDB Server, wsrep_25.11.r4026

And /var/lib/mysql/wsrep_recovery.EWCiJv:

180206 19:25:32 InnoDB: Mutexes and rw_locks use GCC atomic builtins
 
180206 19:25:32 InnoDB: Compressed tables use zlib 1.2.7
 
180206 19:25:32 InnoDB: Using Linux native AIO
 
180206 19:25:32 InnoDB: Initializing buffer pool, size = 16.0G
 
180206 19:25:33 InnoDB: Completed initialization of buffer pool
 
180206 19:25:33 InnoDB: highest supported file format is Barracuda.
 
InnoDB: Log scan progressed past the checkpoint lsn 244441858916
 
180206 19:25:33  InnoDB: Database was not shut down normally!
 
InnoDB: Starting crash recovery.
 
InnoDB: Reading tablespace information from the .ibd files...
 
InnoDB: Restoring possible half-written data pages from the doublewrite
 
InnoDB: buffer...
 
InnoDB: Doing recovery: scanned up to log sequence number 244447101440
 
InnoDB: Doing recovery: scanned up to log sequence number 244448908031
 
InnoDB: 25 transaction(s) which must be rolled back or cleaned up
 
InnoDB: in total 237662 row operations to undo
 
InnoDB: Trx id counter is 25CFF900
 
180206 19:25:41  InnoDB: Starting an apply batch of log records to the database...
 
InnoDB: Progress in percents: 0 1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 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
 
InnoDB: Starting in background the rollback of uncommitted transactions
 
180206 19:25:50  InnoDB: Rolling back trx with id 25CFF7C1, 1 rows to undo
 
180206 19:25:50  InnoDB: Waiting for the background threads to start
 
180206 19:25:51 Percona XtraDB (http://www.percona.com) 5.5.40-MariaDB-36.1 started; log sequence number 244448908031
 
180206 19:25:51 [Note] Plugin 'FEEDBACK' is disabled.
 
180206 19:25:51 [Note] Server socket created on IP: '0.0.0.0'.
 
180206 19:25:51 [Note] WSREP: Recovered position: 00000000-0000-0000-0000-000000000000:-1
 
180206 19:25:52  InnoDB: Starting shutdown...
 
 
 
InnoDB: Rolling back of trx id 25CFF7C1 completed
 
180206 19:25:52  InnoDB: Rolling back trx with id 25CFF7C0, 1 rows to undo
 
 
 
InnoDB: Rolling back of trx id 25CFF7C0 completed
 
180206 19:25:52  InnoDB: Rolling back trx with id 25CFF7BE, 1 rows to undo
 
 
 
InnoDB: Rolling back of trx id 25CFF7BE completed
 
180206 19:25:52  InnoDB: Rolling back trx with id 25CFF7BD, 1 rows to undo
 
 
 
InnoDB: Rolling back of trx id 25CFF7BD completed
 
180206 19:25:52  InnoDB: Rolling back trx with id 25CFF7B9, 1 rows to undo
 
 
 
InnoDB: Rolling back of trx id 25CFF7B9 completed
 
180206 19:25:52  InnoDB: Rolling back trx with id 25CFF7B8, 1 rows to undo
 
 
 
InnoDB: Rolling back of trx id 25CFF7B8 completed
 
180206 19:25:52  InnoDB: Rolling back trx with id 25CFF7B7, 1 rows to undo
 
 
 
InnoDB: Rolling back of trx id 25CFF7B7 completed
 
180206 19:25:52  InnoDB: Rolling back trx with id 25CFF7B6, 1 rows to undo
 
 
 
InnoDB: Rolling back of trx id 25CFF7B6 completed
 
180206 19:25:53  InnoDB: Rolling back trx with id 25CFF7B5, 1 rows to undo
 
 
 
InnoDB: Rolling back of trx id 25CFF7B5 completed
 
180206 19:25:53  InnoDB: Rolling back trx with id 25CFF7B4, 1 rows to undo
 
 
 
InnoDB: Rolling back of trx id 25CFF7B4 completed
 
180206 19:25:53  InnoDB: Rolling back trx with id 25CFF7B3, 1 rows to undo
 
 
 
InnoDB: Rolling back of trx id 25CFF7B3 completed
 
180206 19:25:53  InnoDB: Rolling back trx with id 25CFF7B2, 1 rows to undo
 
 
 
InnoDB: Rolling back of trx id 25CFF7B2 completed
 
180206 19:25:53  InnoDB: Rolling back trx with id 25CFF7B1, 1 rows to undo
 
 
 
InnoDB: Rolling back of trx id 25CFF7B1 completed
 
180206 19:25:53  InnoDB: Rolling back trx with id 25CFF7B0, 1 rows to undo
 
 
 
InnoDB: Rolling back of trx id 25CFF7B0 completed
 
180206 19:25:53  InnoDB: Rolling back trx with id 25CFF7AF, 1 rows to undo
 
 
 
InnoDB: Rolling back of trx id 25CFF7AF completed
 
180206 19:25:53  InnoDB: Rolling back trx with id 25CFF7AE, 1 rows to undo
 
 
 
InnoDB: Rolling back of trx id 25CFF7AE completed
 
180206 19:25:53  InnoDB: Rolling back trx with id 25CFF7AD, 1 rows to undo
 
 
 
InnoDB: Rolling back of trx id 25CFF7AD completed
 
180206 19:25:53  InnoDB: Rolling back trx with id 25CFF7AC, 1 rows to undo
 
 
 
InnoDB: Rolling back of trx id 25CFF7AC completed
 
180206 19:25:53  InnoDB: Rolling back trx with id 25CFF7AB, 1 rows to undo
 
 
 
InnoDB: Rolling back of trx id 25CFF7AB completed
 
180206 19:25:53  InnoDB: Rolling back trx with id 25CFF7AA, 1 rows to undo
 
 
 
InnoDB: Rolling back of trx id 25CFF7AA completed
 
180206 19:25:53  InnoDB: Rolling back trx with id 25CFF7A9, 1 rows to undo
 
 
 
InnoDB: Rolling back of trx id 25CFF7A9 completed
 
180206 19:25:53  InnoDB: Rolling back trx with id 25CFF7A8, 1 rows to undo
 
 
 
InnoDB: Rolling back of trx id 25CFF7A8 completed
 
180206 19:25:53  InnoDB: Rolling back trx with id 25CFF7A7, 1 rows to undo
 
 
 
InnoDB: Rolling back of trx id 25CFF7A7 completed
 
180206 19:25:53  InnoDB: Rolling back trx with id 25CFF7A6, 1 rows to undo
 
 
 
InnoDB: Rolling back of trx id 25CFF7A6 completed
 
180206 19:25:53  InnoDB: Rolling back trx with id 25CF6F83, 237638 rows to undo
 
 
 
InnoDB: Progress in percents: 1 2 3 4180206 19:26:52  InnoDB: Waiting for 1 active transactions to finish
 
 5 6180206 19:27:52  InnoDB: Waiting for 1 active transactions to finish
 
 7180206 19:28:52  InnoDB: Waiting for 1 active transactions to finish
 
 8 9180206 19:29:52  InnoDB: Waiting for 1 active transactions to finish
 
 10180206 19:30:53  InnoDB: Waiting for 1 active transactions to finish
 
 11180206 19:31:53  InnoDB: Waiting for 1 active transactions to finish
 
 12180206 19:32:53  InnoDB: Waiting for 1 active transactions to finish
 
 13180206 19:33:53  InnoDB: Waiting for 1 active transactions to finish
 
 14180206 19:34:53  InnoDB: Waiting for 1 active transactions to finish
 
 15180206 19:35:53  InnoDB: Waiting for 1 active transactions to finish
 
 16180206 19:36:54  InnoDB: Waiting for 1 active transactions to finish
 
 17180206 19:37:54  InnoDB: Waiting for 1 active transactions to finish
 
 18 19180206 19:38:54  InnoDB: Waiting for 1 active transactions to finish
 
 20180206 19:39:54  InnoDB: Waiting for 1 active transactions to finish
 
 21180206 19:40:54  InnoDB: Waiting for 1 active transactions to finish
 
180206 19:41:54  InnoDB: Waiting for 1 active transactions to finish
 
 22180206 19:42:55  InnoDB: Waiting for 1 active transactions to finish
 
 23180206 19:43:55  InnoDB: Waiting for 1 active transactions to finish
 
 24180206 19:44:55  InnoDB: Waiting for 1 active transactions to finish
 
 25180206 19:45:55  InnoDB: Waiting for 1 active transactions to finish
 
 26180206 19:46:56  InnoDB: Waiting for 1 active transactions to finish
 
 27180206 19:47:56  InnoDB: Waiting for 1 active transactions to finish
 
 28180206 19:48:56  InnoDB: Waiting for 1 active transactions to finish
 
 29180206 19:49:56  InnoDB: Waiting for 1 active transactions to finish
 
 30180206 19:50:57  InnoDB: Waiting for 1 active transactions to finish
 
 31 32180206 19:51:57  InnoDB: Waiting for 1 active transactions to finish
 
 33180206 19:52:57  InnoDB: Waiting for 1 active transactions to finish
 
 34180206 19:53:57  InnoDB: Waiting for 1 active transactions to finish
 
 35 36180206 19:54:57  InnoDB: Waiting for 1 active transactions to finish
 
 37180206 19:55:57  InnoDB: Waiting for 1 active transactions to finish
 
 38180206 19:56:58  InnoDB: Waiting for 1 active transactions to finish
 
 39180206 19:57:58  InnoDB: Waiting for 1 active transactions to finish
 
 40180206 19:58:58  InnoDB: Waiting for 1 active transactions to finish
 
 41 42180206 19:59:58  InnoDB: Waiting for 1 active transactions to finish
 
 43180206 20:00:58  InnoDB: Waiting for 1 active transactions to finish
 
 44180206 20:01:58  InnoDB: Waiting for 1 active transactions to finish
 
 45180206 20:02:59  InnoDB: Waiting for 1 active transactions to finish
 
 46180206 20:03:59  InnoDB: Waiting for 1 active transactions to finish
 
 47180206 20:04:59  InnoDB: Waiting for 1 active transactions to finish
 
 48 49180206 20:05:59  InnoDB: Waiting for 1 active transactions to finish
 
 50 51180206 20:06:59  InnoDB: Waiting for 1 active transactions to finish
 
 52180206 20:08:00  InnoDB: Waiting for 1 active transactions to finish
 
 53180206 20:09:00  InnoDB: Waiting for 1 active transactions to finish
 
 54180206 20:10:00  InnoDB: Waiting for 1 active transactions to finish
 
 55180206 20:11:00  InnoDB: Waiting for 1 active transactions to finish
 
 56 57180206 20:12:00  InnoDB: Waiting for 1 active transactions to finish
 
 58180206 20:13:00  InnoDB: Waiting for 1 active transactions to finish
 
 59180206 20:14:01  InnoDB: Waiting for 1 active transactions to finish
 
 60180206 20:15:01  InnoDB: Waiting for 1 active transactions to finish
 
180206 20:16:01  InnoDB: Waiting for 1 active transactions to finish
 
 61180206 20:17:01  InnoDB: Waiting for 1 active transactions to finish
 
 62 63 64 65 66 67 68 69 70 71 72 73 74 75180206 20:18:01  InnoDB: Waiting for 1 active transactions to finish
 
 76 77 78 79 80 81 82 83 84180206 20:19:01  InnoDB: Waiting for 1 active transactions to finish
 
 85 86 87 88180206 20:20:02  InnoDB: Waiting for 1 active transactions to finish
 
 89 90 91180206 20:21:02  InnoDB: Waiting for 1 active transactions to finish
 
 92 93 94 95180206 20:22:02  InnoDB: Waiting for 1 active transactions to finish
 
 96 97 98 99180206 20:23:02  InnoDB: Waiting for 1 active transactions to finish
 
 100
 
InnoDB: Rolling back of trx id 25CF6F83 completed
 
180206 20:23:14  InnoDB: Rollback of non-prepared transactions completed
 
180206 20:23:15  InnoDB: Waiting for 200 pages to be flushed

Comment by Elena Stepanova [ 2018-06-12 ]

SOG, thinkcomp,

these cases seem completely different, unfortunately the confusion happens a lot due to the ambiguous "MySQL server has gone away" error produced by the client. It can happen when the server crashes during execution of the query, or when it just dropped the connection on some reason.
They can be distinguished by looking at the error log (either in a separate file or in syslog, depending on configuration). In case of a crash, there will be (hopefully) a crash report, and there will always be server restart.

So, in SOG's case, we don't have the error log, but given the circumstances, by far the most likely reason is the size of max_allowed_packet which doesn't allow the big blob to be inserted. Try to increase it to the maximum value and load the dump.

In thinkcomp's case, the error log shows that there was a forced server restart and crash recovery, which typically means a real server crash (the differential diagnosis includes somebody SIGKILL-ing the server, but it's unlikely). So, if you still have the problem, please file a separate bug report, and importantly please include the part of the server log preceding restart, that's where the actual information about the crash should be.

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