[MDEV-17679] innodb.undo_truncate_recover failed in buildbot with MySQL server has gone away on SHOW VARIABLES Created: 2018-11-12  Updated: 2022-11-11  Resolved: 2022-11-11

Status: Closed
Project: MariaDB Server
Component/s: Storage Engine - InnoDB, Tests
Affects Version/s: 10.2, 10.3, 10.4
Fix Version/s: 10.3.14

Type: Bug Priority: Major
Reporter: Elena Stepanova Assignee: Marko Mäkelä
Resolution: Cannot Reproduce Votes: 0
Labels: need_rr

Issue Links:
Relates
relates to MDEV-17780 innodb.truncate_recover crashes in re... Closed
relates to MDEV-17049 Enable --suite=innodb_undo on buildbot Closed

 Description   

http://buildbot.askmonty.org/buildbot/builders/win32-debug/builds/10757

innodb.undo_truncate_recover '16k,2,innodb' w2 [ fail ]
 
        Test ended at 2018-10-11 20:49:09
 
 
 
CURRENT_TEST: innodb.undo_truncate_recover
 
mysqltest: In included file "./include/shutdown_mysqld.inc": 
included from D:/win32-debug/build/src/mysql-test/suite/innodb/t/undo_truncate_recover.test at line 45:
 
At line 40: 'SHOW VARIABLES LIKE 'pid_file'' failed: 2006 MySQL server has gone away
 
 
 
The result from queries just before the failure was:
 
SET GLOBAL innodb_undo_logs = 4;
 
SET GLOBAL innodb_undo_log_truncate = 1;
 
SET GLOBAL innodb_purge_rseg_truncate_frequency = 1;
 
create table t1(keyc int primary key, c char(100)) engine = innodb;
 
begin;
 
commit;
 
begin;
 
update t1 set c = 'MariaDB';
 
update t1 set c = 'InnoDB';
 
set global debug_dbug = '+d,ib_undo_trunc';
 
commit;
 
call mtr.add_suppression("InnoDB: The transaction log size is too large");
 
SET GLOBAL innodb_fast_shutdown=0;



 Comments   
Comment by Marko Mäkelä [ 2018-11-12 ]

As far as I can tell, the statement ought to be part of the following in shutdown_mysqld.inc:

--shutdown_server $server_shutdown_timeout


void do_shutdown_server(struct st_command *command)
 
{
 
…
 
  if (query_get_string(mysql, "SHOW VARIABLES LIKE 'pid_file'", 1,
 
                       &ds_pidfile_name))
 
    die("Failed to get pid_file from server");

Apparently, the server was killed due to some reason while the shutdown as about to be initiated. Here is an excerpt from the server error log:

10.2 81a5b6ccd531e802bbb0f2034189095d2196de8b

 
Version: '10.2.19-MariaDB-debug-log'  socket: ''  port: 16020  Source distribution
 
2018-10-11 20:48:58 2080 [Note] InnoDB: Truncating UNDO tablespace 1
 
2018-10-11 20:48:59 2080 [Warning] InnoDB: The transaction log size is too large for innodb_log_buffer_size (1389258 >= 1048576 / 2). Trying to extend it.
 
2018-10-11 20:48:59 2080 [Note] InnoDB: innodb_log_buffer_size was extended to 1392640.
 
2018-10-11 20:48:59 2080 [Note] InnoDB: ib_undo_trunc
 
CURRENT_TEST: innodb.undo_truncate_recover

The last message is a suicide note from trx_purge_initiate_truncate():

	DBUG_EXECUTE_IF("ib_undo_trunc",
 
			ib::info() << "ib_undo_trunc";
 
			log_write_up_to(LSN_MAX, true);
 
			DBUG_SUICIDE(););

This looks like a race condition in the test.
We do expect the server to commit suicide during the slow shutdown, but not already during the initial step of shutdown_server.

Comment by Marko Mäkelä [ 2022-11-11 ]

Last occurrence:

10.2 acb4a872049e0ac23a1fdf7a1aaf12ed

 
innodb.undo_truncate_recover '16k,2,innodb' w4 [ fail ]
 
        Test ended at 2019-03-11 22:29:32
 
 
 
CURRENT_TEST: innodb.undo_truncate_recover
 
mysqltest: In included file "./include/shutdown_mysqld.inc": 
included from D:/winx64-debug/build/src/mysql-test/suite/innodb/t/undo_truncate_recover.test at line 46:
 
At line 40: 'SHOW VARIABLES LIKE 'pid_file'' failed: 2006 MySQL server has gone away

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