Bug #87282 WL#9499 can cause extra warnings on every crashing testcase
Submitted: 2 Aug 2017 10:40 Modified: 4 Oct 2017 8:52
Reporter: Laurynas Biveinis Email Updates:
Status: Verified Impact on me:
None 
Category:Tests: Server Severity:S3 (Non-critical)
Version:8.0.2 OS:Any
Assigned to: CPU Architecture:Any
Tags: crash recovery, innodb, mtr

[2 Aug 2017 10:40] Laurynas Biveinis
Description:
On 8.0.2, some testcases randomly and very intermittently fail their warning checks, e.g.

binlog_gtid.binlog_gtid_exhausted 'stmt' w1 [ fail ]  Found warnings/errors in server log file!
        Test ended at 2017-08-01 06:36:09
line
2017-08-01T06:36:06.805163Z 1 [Warning] InnoDB: File '/mnt/workspace/mysql-5.7-param/BUILD_TYPE/debug/Host/debian-jessie-64bit/build/mysql-test/var/1/mysqld.1/data/tablespaces.open.1' size is 0 bytes. Must be at least 12 bytes
.... repeated 1 times: [Warning] InnoDB: File '/mnt/workspace/mysql-5.7-param/BUILD_TYPE/debug/Host/debian-jessie-64bit/build/mysql-test/var/1/mysqld.1/data/tablespaces.open.1' size is 0 bytes. Must be at least 12 bytes
^ Found warnings in /mnt/workspace/mysql-5.7-param/BUILD_TYPE/debug/Host/debian-jessie-64bit/build/mysql-test/var/1/log/mysqld.1.err
ok

The only common thing between the randomly failing testcases seems to be that they are all crashing ones, and tend to be in rpl suites.

How to repeat:
Not sure. Host being slow seems to raise the occurrence rate. Testcase being a replication one might help with host being slow

Suggested fix:
An IMHO plausible explanation is InnoDB master thread making checkpoints in the background. Each log checkpoint with WL#9499 now calls fil_tablespace_open_sync_to_disk, which calls fil_system->m_open.to_file(), which writes the tablespace maps for crash recovery. The write is done in steps, and one of the steps is truncating the file to zero. If another thread hits the testcase crash between the truncate and the tablespace map write/flush, the crash recovery will hit this warning, intended or not.

This is a bit hard to confirm as it needs saving the server stacktraces at the crash injection time.

If the above is correct, then it should be fixed by suppressing the warning. Adding a suppression to the global MTR list does not look correct as it would cover non-crashing testcases too. Perhaps include/not_crashrep.inc could be repurposed to hold this mtr.add_suppression call.
[5 Aug 2017 7:31] Laurynas Biveinis
Bug 87282 fix for 8.0.2

(*) I confirm the code being submitted is offered under the terms of the OCA, and that I am authorized to contribute it.

Contribution: bug87282-8.0.2.patch (application/octet-stream, text), 3.47 KiB.

[5 Aug 2017 7:32] Laurynas Biveinis
I hope I got the suppression regexp right; all I know is that with the patch, the only occurrences of this error were on the testcases with missing not_crashrep.inc so far (the patch adds a few)
[7 Aug 2017 4:40] Erlend Dahl
This is a known issue in internal testing.
[7 Aug 2017 4:46] Erlend Dahl
Discussed with Sunny Bains (developer), the code producing the warning is slated for removal in an upcoming WL.
[4 Oct 2017 8:52] Laurynas Biveinis
The warning has been removed by WL#9535/WL#9536 in 8.0.3 [1], this bug has been fixed.

[1]:

commit 34526482834a8c3deb05bdf831321d93ce225ccd
Author: Jimmy Yang <jimmy.yang@oracle.com>
Date:   Thu Aug 17 00:34:24 2017 +0200

    InnoDB NewDD worklogs(WL#9535 and WL#9536) to support Atomic DDL and
    completely remove old InnoDB system tables:
    
        1. WL#9535: InnoDB_New_DD: Remove InnoDB System Table and modify the
        view of their I_S counterparts
    
        This worklog obsoletes all InnoDB System tables, which are no longer
        used and could only be accessed by upgrade. All metadata is now
        persisted and read from DD system tables in "mysql tablespace"
        instead of "old" InnoDB System Tables.
    
        All corresponding information_schema.innodb_sys_* tables are replaced
        by new internal system views.
        These new views have the name similar to the names of old system tables,
        just removing the 'SYS_' from the middle of the names.
    
        2. WL#9536: InnoDB_New_DD: Support crash-safe DDL
    
        This worklog starts to support crash-safe DDL for InnoDB. DDLs like
        CREATE TABLE, DROP TABLE, RENAME TABLE, TRUNCATE TABLE, ALTER TABLE,
        CREATE TABLESPACE and DROP TABLESPACE are covered by this worklog.
        DDLs operations including DD system table updates and corresponding
        file changes(create, delete, rename etc.) are atomic.
    
        Physical data files would be synchronized with the transaction for DDL,
        thus there should be no physical data files for temporary tables or FTS
        auxiliary tables, etc. left after recovery.