[MDEV-19374] innodb.table_flags failed in buildbot with Server failed to restart Created: 2019-04-30  Updated: 2022-07-27  Resolved: 2022-07-26

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

Type: Bug Priority: Major
Reporter: Elena Stepanova Assignee: Marko Mäkelä
Resolution: Fixed Votes: 0
Labels: None

Issue Links:
Relates
relates to MDEV-12699 Improve crash recovery of corrupted d... Closed

 Description   

http://buildbot.askmonty.org/buildbot/builders/kvm-bintar-trusty-amd64/builds/10560

10.1 f4b27400

 
innodb.table_flags '32k,release,xtradb'  w3 [ fail ]
 
        Test ended at 2019-04-19 18:57:10
 
 
 
CURRENT_TEST: innodb.table_flags
 
mysqltest: In included file "./include/wait_until_connected_again.inc": 
included from ./include/start_mysqld.inc at line 18:
 
included from /usr/local/mariadb-10.1.39-linux-x86_64/mysql-test/suite/innodb/t/table_flags.test at line 162:
 
At line 26: Server failed to restart
 
 
 
The result from queries just before the failure was:
 
< snip >
 
 SPACE=0x00000004)
 
header=0x060008030000 (NAME=0x73757072656d756d00)
 
SHOW CREATE TABLE tr;
 
Table	Create Table
 
tr	CREATE TABLE `tr` (
 
  `a` int(11) NOT NULL,
 
  PRIMARY KEY (`a`)
 
) ENGINE=InnoDB DEFAULT CHARSET=latin1 ROW_FORMAT=REDUNDANT
 
INSERT INTO tr VALUES(42);
 
SHOW CREATE TABLE tc;
 
ERROR 42S02: Table 'test.tc' doesn't exist in engine
 
SHOW CREATE TABLE td;
 
ERROR 42S02: Table 'test.td' doesn't exist in engine
 
SHOW CREATE TABLE tz;
 
ERROR 42S02: Table 'test.tz' doesn't exist in engine
 
SHOW CREATE TABLE tp;
 
ERROR 42S02: Table 'test.tp' doesn't exist in engine
 
FOUND /InnoDB: Table '.test.\..t[cdzp].' in InnoDB data dictionary has unknown type (81|f21|121|302[13])\b/ in mysqld.1.err
 
FOUND /InnoDB: Cannot open table test/t[cdzp] from the internal data dictionary of InnoDB/ in mysqld.1.err
 
Restoring SYS_TABLES clustered index root page (8)



 Comments   
Comment by Marko Mäkelä [ 2019-05-02 ]

It looks like the reason could be a hung startup. The root cause of that might be shared with MDEV-12699. Here is an excerpt from the server error log:

2019-04-19 18:48:35 7ffabd8b7700  InnoDB: Error: table 'test/tp'
 
InnoDB: in InnoDB data dictionary has unknown type 121.
 
2019-04-19 18:48:35 7ffabd8b7700  InnoDB: incorrect flags in SYS_TABLES
 
2019-04-19 18:48:35 140714898585344 [Warning] InnoDB: Cannot open table test/tp from the internal data dictionary of InnoDB though the .frm file for the table exists. See http://dev.mysql.com/doc/refman/5.6/en/innodb-troubleshooting.html for how you can resolve the problem.
 
2019-04-19 18:48:35 140714898282240 [Note] /usr/local/mariadb-10.1.39-linux-x86_64/bin/mysqld: Normal shutdown
 
2019-04-19 18:48:35 140714898282240 [Note] Event Scheduler: Purging the queue. 0 events
 
2019-04-19 18:48:35 140714583254784 [Note] InnoDB: FTS optimize thread exiting.
 
2019-04-19 18:48:35 140714898282240 [Note] InnoDB: Starting shutdown...
 
2019-04-19 18:48:36 140714898282240 [Note] InnoDB: Waiting for page_cleaner to finish flushing of buffer pool
 
2019-04-19 18:48:38 140714898282240 [Note] InnoDB: Shutdown completed; log sequence number 3103569
 
2019-04-19 18:48:38 140714898282240 [Note] /usr/local/mariadb-10.1.39-linux-x86_64/bin/mysqld: Shutdown complete
 
 
 
2019-04-19 18:48:39 140071161219008 [Note] /usr/local/mariadb-10.1.39-linux-x86_64/bin/mysqld (mysqld 10.1.39-MariaDB) starting as process 1022 ...
 
2019-04-19 18:48:39 140071161219008 [Warning] Could not increase number of max_open_files to more than 1024 (request: 4186)
 
2019-04-19 18:48:39 140071161219008 [Note] Plugin 'SEQUENCE' is disabled.
 
2019-04-19 18:48:39 140071161219008 [Note] Plugin 'partition' is disabled.
 
2019-04-19 18:48:39 140071161219008 [Note] InnoDB:  innodb-page-size has been changed from the default value 16384 to 32768 .
 
2019-04-19 18:48:39 140071161219008 [Note] InnoDB: innodb_empty_free_list_algorithm has been changed to legacy because of small buffer pool size. In order to use backoff, increase buffer pool at least up to 20MB.
 
 
 
2019-04-19 18:48:39 140071161219008 [Note] InnoDB: Using mutexes to ref count buffer pool pages
 
2019-04-19 18:48:39 140071161219008 [Note] InnoDB: The InnoDB memory heap is disabled
 
2019-04-19 18:48:39 140071161219008 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
 
2019-04-19 18:48:39 140071161219008 [Note] InnoDB: GCC builtin __atomic_thread_fence() is used for memory barrier
 
2019-04-19 18:48:39 140071161219008 [Note] InnoDB: Compressed tables use zlib 1.2.11
 
2019-04-19 18:48:39 140071161219008 [Note] InnoDB: Using Linux native AIO
 
2019-04-19 18:48:39 140071161219008 [Note] InnoDB: Using generic crc32 instructions
 
2019-04-19 18:48:39 140071161219008 [Note] InnoDB: Initializing buffer pool, size = 24.0M
 
2019-04-19 18:48:39 140071161219008 [Note] InnoDB: Completed initialization of buffer pool
 
2019-04-19 18:48:39 140071161219008 [Note] InnoDB: Highest supported file format is Barracuda.
 
CURRENT_TEST: innodb.table_flags
 
2019-04-19 18:57:14 139926318532544 [Note] /usr/local/mariadb-10.1.39-linux-x86_64/bin/mysqld (mysqld 10.1.39-MariaDB) starting as process 13626 ...

The startup was hung at 18:48:39, and the server was restarted at 18:57:14, which is 4 seconds after the timestamp in the client log.

Comment by Marko Mäkelä [ 2022-07-26 ]

The last matching failure that I found for this test was for 10.1:
kvm-rpm-centos74-aarch64 Normal run, no --ps-protocol 2018-07-18 18:28:30

10.1 4d06b7e1bd3b825da32c9200e6f5ca60

 
innodb.table_flags '8k,xtradb'           w3 [ fail ]
 
        Test ended at 2018-07-18 19:27:55
 
 
 
CURRENT_TEST: innodb.table_flags
 
mysqltest: In included file "./include/wait_until_connected_again.inc": 
included from ./include/restart_mysqld.inc at line 52:
 
included from /usr/share/mysql-test/suite/innodb/t/table_flags.test at line 27:
 
At line 26: Server failed to restart
 
 
 
 - skipping '/dev/shm/var/3/log/innodb.table_flags-8k,xtradb/'
 
 
 
Retrying test innodb.table_flags, attempt(2/3)...
 
 
 
worker[3] > Restart  - not started

The test does occasionally fail for other reasons, most notably on Valgrind (most likely something related to its internal single-threaded execution).

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