Test innodb.percona_changed_page_bmp fails with --repeat=2

[Laurynas Biveinis]

On 5.6 trunk, with --repeat=2, both release and debug builds:

http://jenkins.percona.com/job/percona-server-5.6-repeat/13/BUILD_TYPE=release,Host=amd64,MTR_REPEAT=2/consoleText
http://jenkins.percona.com/job/percona-server-5.6-repeat/13/BUILD_TYPE=debug,Host=amd64,MTR_REPEAT=2/consoleText

innodb.percona_changed_page_bmp w4 [ pass ] 113222
...
innodb.percona_changed_page_bmp w4 [ fail ]
        Test ended at 2017-02-25 14:33:09

CURRENT_TEST: innodb.percona_changed_page_bmp
mysqltest: In included file "./include/assert.inc":
included from ./include/assert.inc at line 75:
At line 74: Test assertion failed in assert.inc

The result from queries just before the failure was:
RESET CHANGED_PAGE_BITMAPS;
DROP TABLE IF EXISTS t1, t2;
CREATE TABLE t1 (x INT) ENGINE=InnoDB;
INSERT INTO t1 VALUES (1),(2),(3),(4),(5);
ib_modified_log_1
1st restart
INSERT INTO t1 VALUES (1),(2),(3),(4),(5);
include/assert.inc [There should not be a hole in the tracked LSN range]
ib_modified_log_1
ib_modified_log_2
2nd restart
INSERT INTO t1 VALUES (1),(2),(3),(4),(5);
include/assert.inc [There should not be a hole in the tracked LSN range]
ib_modified_log_1
ib_modified_log_2
ib_modified_log_3
call mtr.add_suppression("last tracked LSN in");
3rd restart
include/assert.inc [There should not be a hole in the tracked LSN range]
######## Test assertion failed: There should not be a hole in the tracked LSN range ########
Dumping debug info:
Assertion text: 'There should not be a hole in the tracked LSN range'
Assertion condition: 'COUNT(*) FROM INFORMATION_SCHEMA.INNODB_CHANGED_PAGES'
Assertion condition, interpolated: 'COUNT(*) FROM INFORMATION_SCHEMA.INNODB_CHANGED_PAGES'
Assertion result: '0'
safe_process[14434]: Child process: 14435, exit: 1

Server [mysqld.1 - pid: 14664, winpid: 14664] log:
Server log from this test:
----------SERVER LOG START-----------
2017-02-25 22:32:50 14386 [Note] /mnt/workspace/percona-server-5.6-repeat/BUILD_TYPE/debug/Host/amd64/MTR_REPEAT/2/build/sql/mysqld-debug: Normal shutdown

2017-02-25 22:32:50 14386 [Note] Giving 0 client threads a chance to die gracefully
2017-02-25 22:32:50 14386 [Note] Event Scheduler: Purging the queue. 0 events
2017-02-25 22:32:50 14386 [Note] Shutting down slave threads
2017-02-25 22:32:50 14386 [Note] Forcefully disconnecting 0 remaining clients
2017-02-25 22:32:50 14386 [Note] Binlog end
2017-02-25 22:32:50 14386 [Note] Shutting down plugin 'partition'
2017-02-25 22:32:50 14386 [Note] Shutting down plugin 'INNODB_CHANGED_PAGES'
2017-02-25 22:32:50 14386 [Note] Shutting down plugin 'INNODB_SYS_DATAFILES'
2017-02-25 22:32:50 14386 [Note] Shutting down plugin 'INNODB_SYS_TABLESPACES'
2017-02-25 22:32:50 14386 [Note] Shutting down plugin 'INNODB_SYS_FOREIGN_COLS'
2017-02-25 22:32:50 14386 [Note] Shutting down plugin 'INNODB_SYS_FOREIGN'
2017-02-25 22:32:50 14386 [Note] Shutting down plugin 'INNODB_SYS_FIELDS'
2017-02-25 22:32:50 14386 [Note] Shutting down plugin 'INNODB_SYS_COLUMNS'
2017-02-25 22:32:50 14386 [Note] Shutting down plugin 'INNODB_SYS_INDEXES'
2017-02-25 22:32:50 14386 [Note] Shutting down plugin 'INNODB_SYS_TABLESTATS'
2017-02-25 22:32:50 14386 [Note] Shutting down plugin 'INNODB_SYS_TABLES'
2017-02-25 22:32:50 14386 [Note] Shutting down plugin 'INNODB_FT_INDEX_TABLE'
2017-02-25 22:32:50 14386 [Note] Shutting down plugin 'INNODB_FT_INDEX_CACHE'
2017-02-25 22:32:50 14386 [Note] Shutting down plugin 'INNODB_FT_CONFIG'
2017-02-25 22:32:50 14386 [Note] Shutting down plugin 'INNODB_FT_BEING_DELETED'
2017-02-25 22:32:50 14386 [Note] Shutting down plugin 'INNODB_FT_DELETED'
2017-02-25 22:32:50 14386 [Note] Shutting down plugin 'INNODB_FT_DEFAULT_STOPWORD'
2017-02-25 22:32:50 14386 [Note] Shutting down plugin 'INNODB_METRICS'
2017-02-25 22:32:50 14386 [Note] Shutting down plugin 'INNODB_BUFFER_POOL_STATS'
2017-02-25 22:32:50 14386 [Note] Shutting down plugin 'INNODB_BUFFER_PAGE_LRU'
2017-02-25 22:32:50 14386 [Note] Shutting down plugin 'INNODB_BUFFER_PAGE'
2017-02-25 22:32:50 14386 [Note] Shutting down plugin 'INNODB_CMP_PER_INDEX_RESET'
2017-02-25 22:32:50 14386 [Note] Shutting down plugin 'INNODB_CMP_PER_INDEX'
2017-02-25 22:32:50 14386 [Note] Shutting down plugin 'INNODB_CMPMEM_RESET'
2017-02-25 22:32:50 14386 [Note] Shutting down plugin 'INNODB_CMPMEM'
2017-02-25 22:32:50 14386 [Note] Shutting down plugin 'INNODB_CMP_RESET'
2017-02-25 22:32:50 14386 [Note] Shutting down plugin 'INNODB_CMP'
2017-02-25 22:32:50 14386 [Note] Shutting down plugin 'INNODB_LOCK_WAITS'
2017-02-25 22:32:50 14386 [Note] Shutting down plugin 'INNODB_LOCKS'
2017-02-25 22:32:50 14386 [Note] Shutting down plugin 'INNODB_TRX'
2017-02-25 22:32:50 14386 [Note] Shutting down plugin 'XTRADB_ZIP_DICT_COLS'
2017-02-25 22:32:50 14386 [Note] Shutting down plugin 'XTRADB_ZIP_DICT'
2017-02-25 22:32:50 14386 [Note] Shutting down plugin 'XTRADB_RSEG'
2017-02-25 22:32:50 14386 [Note] Shutting down plugin 'XTRADB_INTERNAL_HASH_TABLES'
2017-02-25 22:32:50 14386 [Note] Shutting down plugin 'XTRADB_READ_VIEW'
2017-02-25 22:32:50 14386 [Note] Shutting down plugin 'ARCHIVE'
2017-02-25 22:32:50 14386 [Note] Shutting down plugin 'BLACKHOLE'
2017-02-25 22:32:50 14386 [Note] Shutting down plugin 'PERFORMANCE_SCHEMA'
2017-02-25 22:32:50 14386 [Note] Shutting down plugin 'MEMORY'
2017-02-25 22:32:50 14386 [Note] Shutting down plugin 'CSV'
2017-02-25 22:32:50 14386 [Note] Shutting down plugin 'MyISAM'
2017-02-25 22:32:50 14386 [Note] Shutting down plugin 'MRG_MYISAM'
2017-02-25 22:32:50 14386 [Note] Shutting down plugin 'sha256_password'
2017-02-25 22:32:50 14386 [Note] Shutting down plugin 'mysql_old_password'
2017-02-25 22:32:50 14386 [Note] Shutting down plugin 'mysql_native_password'
2017-02-25 22:32:50 14386 [Note] Shutting down plugin 'binlog'
2017-02-25 22:32:50 14386 [Note] Shutting down plugin 'InnoDB'
2017-02-25 22:32:50 14386 [Note] InnoDB: FTS optimize thread exiting.
2017-02-25 22:32:50 14386 [Note] InnoDB: Starting shutdown...
2017-02-25 22:32:51 14386 [Note] InnoDB: Waiting for page_cleaner to finish flushing of buffer pool
2017-02-25 22:32:53 14386 [Note] InnoDB: Shutdown completed; log sequence number 29660182
2017-02-25 22:32:53 14386 [Note] Debug sync points hit: 11485
2017-02-25 22:32:53 14386 [Note] Debug sync points executed: 0
2017-02-25 22:32:53 14386 [Note] Debug sync points max active per thread: 0
2017-02-25 22:32:53 14386 [Note] /mnt/workspace/percona-server-5.6-repeat/BUILD_TYPE/debug/Host/amd64/MTR_REPEAT/2/build/sql/mysqld-debug: Shutdown complete

2017-02-25 22:32:54 0 [Warning] TIMESTAMP with implicit DEFAULT value is deprecated. Please use --explicit_defaults_for_timestamp server option (see documentation for more details).
2017-02-25 22:32:54 0 [Warning] Insecure configuration for --secure-file-priv: Data directory is accessible through --secure-file-priv. Consider choosing a different directory.
2017-02-25 22:32:54 0 [Warning] Insecure configuration for --secure-file-priv: Location is accessible to all OS users. Consider choosing a different directory.
2017-02-25 22:32:54 0 [Note] /mnt/workspace/percona-server-5.6-repeat/BUILD_TYPE/debug/Host/amd64/MTR_REPEAT/2/build/sql/mysqld-debug (mysqld 5.6.35-80.0-debug-log) starting as process 14474 ...
2017-02-25 22:32:54 14474 [Note] Plugin 'FEDERATED' is disabled.
2017-02-25 22:32:54 7ffb39feb720 InnoDB: Warning: Using innodb_additional_mem_pool_size is DEPRECATED. This option may be removed in future releases, together with the option innodb_use_sys_malloc and with the InnoDB's internal memory allocator.
2017-02-25 22:32:54 14474 [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.

2017-02-25 22:32:54 14474 [Note] InnoDB: Using atomics to ref count buffer pool pages
2017-02-25 22:32:54 7ffb39feb720 InnoDB: !!!!!!!! UNIV_DEBUG switched on !!!!!!!!!
2017-02-25 22:32:54 7ffb39feb720 InnoDB: !!!!!!!! UNIV_SYNC_DEBUG switched on !!!!!!!!!
2017-02-25 22:32:54 14474 [Note] InnoDB: The InnoDB memory heap is disabled
2017-02-25 22:32:54 14474 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
2017-02-25 22:32:54 14474 [Note] InnoDB: Memory barrier is not used
2017-02-25 22:32:54 14474 [Note] InnoDB: Compressed tables use zlib 1.2.3
2017-02-25 22:32:54 14474 [Note] InnoDB: Using Linux native AIO
2017-02-25 22:32:54 14474 [Note] InnoDB: Using CPU crc32 instructions
2017-02-25 22:32:54 14474 [Note] InnoDB: Initializing buffer pool, size = 8.0M
2017-02-25 22:32:54 14474 [Note] InnoDB: Completed initialization of buffer pool
2017-02-25 22:32:54 14474 [Note] InnoDB: Highest supported file format is Barracuda.
2017-02-25 22:32:54 14474 [Note] InnoDB: starting tracking changed pages from LSN 29660182
2017-02-25 22:32:55 14474 [Note] InnoDB: 128 rollback segment(s) are active.
2017-02-25 22:32:55 14474 [Note] InnoDB: Waiting for purge to start
2017-02-25 22:32:55 14474 [Note] InnoDB: Percona XtraDB (http://www.percona.com) 5.6.35-80.0 started; log sequence number 29660182
2017-02-25 22:32:55 14474 [Note] RSA private key file not found: /mnt/workspace/percona-server-5.6-repeat/BUILD_TYPE/debug/Host/amd64/MTR_REPEAT/2/build/mysql-test/var/4/mysqld.1/data//private_key.pem. Some authentication plugins will not work.
2017-02-25 22:32:55 14474 [Note] RSA public key file not found: /mnt/workspace/percona-server-5.6-repeat/BUILD_TYPE/debug/Host/amd64/MTR_REPEAT/2/build/mysql-test/var/4/mysqld.1/data//public_key.pem. Some authentication plugins will not work.
2017-02-25 22:32:55 14474 [Note] Server hostname (bind-address): '*'; port: 13031
2017-02-25 22:32:55 14474 [Note] IPv6 is available.
2017-02-25 22:32:55 14474 [Note] - '::' resolves to '::';
2017-02-25 22:32:55 14474 [Note] Server socket created on IP: '::'.
2017-02-25 22:32:55 14474 [Note] Event Scheduler: Loaded 0 events
2017-02-25 22:32:55 14474 [Note] /mnt/workspace/percona-server-5.6-repeat/BUILD_TYPE/debug/Host/amd64/MTR_REPEAT/2/build/sql/mysqld-debug: ready for connections.
Version: '5.6.35-80.0-debug-log' socket: '/tmp/UK38Bwj7kw/4/mysqld.1.sock' port: 13031 MySQL Community Server (GPL)
2017-02-25 22:32:55 14474 [Note] /mnt/workspace/percona-server-5.6-repeat/BUILD_TYPE/debug/Host/amd64/MTR_REPEAT/2/build/sql/mysqld-debug: Normal shutdown

2017-02-25 22:32:55 14474 [Note] Giving 0 client threads a chance to die gracefully
2017-02-25 22:32:55 14474 [Note] Event Scheduler: Purging the queue. 0 events
2017-02-25 22:32:55 14474 [Note] Shutting down slave threads
2017-02-25 22:32:55 14474 [Note] Forcefully disconnecting 0 remaining clients
2017-02-25 22:32:55 14474 [Note] Binlog end
2017-02-25 22:32:55 14474 [Note] Shutting down plugin 'partition'
2017-02-25 22:32:55 14474 [Note] Shutting down plugin 'INNODB_CHANGED_PAGES'
2017-02-25 22:32:55 14474 [Note] Shutting down plugin 'INNODB_SYS_DATAFILES'
2017-02-25 22:32:55 14474 [Note] Shutting down plugin 'INNODB_SYS_TABLESPACES'
2017-02-25 22:32:55 14474 [Note] Shutting down plugin 'INNODB_SYS_FOREIGN_COLS'
2017-02-25 22:32:55 14474 [Note] Shutting down plugin 'INNODB_SYS_FOREIGN'
2017-02-25 22:32:55 14474 [Note] Shutting down plugin 'INNODB_SYS_FIELDS'
2017-02-25 22:32:55 14474 [Note] Shutting down plugin 'INNODB_SYS_COLUMNS'
2017-02-25 22:32:55 14474 [Note] Shutting down plugin 'INNODB_SYS_INDEXES'
2017-02-25 22:32:55 14474 [Note] Shutting down plugin 'INNODB_SYS_TABLESTATS'
2017-02-25 22:32:55 14474 [Note] Shutting down plugin 'INNODB_SYS_TABLES'
2017-02-25 22:32:55 14474 [Note] Shutting down plugin 'INNODB_FT_INDEX_TABLE'
2017-02-25 22:32:55 14474 [Note] Shutting down plugin 'INNODB_FT_INDEX_CACHE'
2017-02-25 22:32:55 14474 [Note] Shutting down plugin 'INNODB_FT_CONFIG'
2017-02-25 22:32:55 14474 [Note] Shutting down plugin 'INNODB_FT_BEING_DELETED'
2017-02-25 22:32:55 14474 [Note] Shutting down plugin 'INNODB_FT_DELETED'
2017-02-25 22:32:55 14474 [Note] Shutting down plugin 'INNODB_FT_DEFAULT_STOPWORD'
2017-02-25 22:32:55 14474 [Note] Shutting down plugin 'INNODB_METRICS'
2017-02-25 22:32:55 14474 [Note] Shutting down plugin 'INNODB_BUFFER_POOL_STATS'
2017-02-25 22:32:55 14474 [Note] Shutting down plugin 'INNODB_BUFFER_PAGE_LRU'
2017-02-25 22:32:55 14474 [Note] Shutting down plugin 'INNODB_BUFFER_PAGE'
2017-02-25 22:32:55 14474 [Note] Shutting down plugin 'INNODB_CMP_PER_INDEX_RESET'
2017-02-25 22:32:55 14474 [Note] Shutting down plugin 'INNODB_CMP_PER_INDEX'
2017-02-25 22:32:55 14474 [Note] Shutting down plugin 'INNODB_CMPMEM_RESET'
2017-02-25 22:32:55 14474 [Note] Shutting down plugin 'INNODB_CMPMEM'
2017-02-25 22:32:55 14474 [Note] Shutting down plugin 'INNODB_CMP_RESET'
2017-02-25 22:32:55 14474 [Note] Shutting down plugin 'INNODB_CMP'
2017-02-25 22:32:55 14474 [Note] Shutting down plugin 'INNODB_LOCK_WAITS'
2017-02-25 22:32:55 14474 [Note] Shutting down plugin 'INNODB_LOCKS'
2017-02-25 22:32:55 14474 [Note] Shutting down plugin 'INNODB_TRX'
2017-02-25 22:32:55 14474 [Note] Shutting down plugin 'XTRADB_ZIP_DICT_COLS'
2017-02-25 22:32:55 14474 [Note] Shutting down plugin 'XTRADB_ZIP_DICT'
2017-02-25 22:32:55 14474 [Note] Shutting down plugin 'XTRADB_RSEG'
2017-02-25 22:32:55 14474 [Note] Shutting down plugin 'XTRADB_INTERNAL_HASH_TABLES'
2017-02-25 22:32:55 14474 [Note] Shutting down plugin 'XTRADB_READ_VIEW'
2017-02-25 22:32:55 14474 [Note] Shutting down plugin 'ARCHIVE'
2017-02-25 22:32:55 14474 [Note] Shutting down plugin 'BLACKHOLE'
2017-02-25 22:32:55 14474 [Note] Shutting down plugin 'PERFORMANCE_SCHEMA'
2017-02-25 22:32:55 14474 [Note] Shutting down plugin 'MEMORY'
2017-02-25 22:32:55 14474 [Note] Shutting down plugin 'CSV'
2017-02-25 22:32:55 14474 [Note] Shutting down plugin 'MyISAM'
2017-02-25 22:32:55 14474 [Note] Shutting down plugin 'MRG_MYISAM'
2017-02-25 22:32:55 14474 [Note] Shutting down plugin 'sha256_password'
2017-02-25 22:32:55 14474 [Note] Shutting down plugin 'mysql_old_password'
2017-02-25 22:32:55 14474 [Note] Shutting down plugin 'mysql_native_password'
2017-02-25 22:32:55 14474 [Note] Shutting down plugin 'binlog'
2017-02-25 22:32:55 14474 [Note] Shutting down plugin 'InnoDB'
2017-02-25 22:32:55 14474 [Note] InnoDB: FTS optimize thread exiting.
2017-02-25 22:32:55 14474 [Note] InnoDB: Starting shutdown...
2017-02-25 22:32:56 14474 [Note] InnoDB: Waiting for page_cleaner to finish flushing of buffer pool
2017-02-25 22:32:58 14474 [Note] InnoDB: Shutdown completed; log sequence number 29665621
2017-02-25 22:32:58 14474 [Note] Debug sync points hit: 2498
2017-02-25 22:32:58 14474 [Note] Debug sync points executed: 0
2017-02-25 22:32:58 14474 [Note] Debug sync points max active per thread: 0
2017-02-25 22:32:58 14474 [Note] /mnt/workspace/percona-server-5.6-repeat/BUILD_TYPE/debug/Host/amd64/MTR_REPEAT/2/build/sql/mysqld-debug: Shutdown complete

2017-02-25 22:32:58 0 [Warning] TIMESTAMP with implicit DEFAULT value is deprecated. Please use --explicit_defaults_for_timestamp server option (see documentation for more details).
2017-02-25 22:32:58 0 [Warning] Insecure configuration for --secure-file-priv: Data directory is accessible through --secure-file-priv. Consider choosing a different directory.
2017-02-25 22:32:58 0 [Warning] Insecure configuration for --secure-file-priv: Location is accessible to all OS users. Consider choosing a different directory.
2017-02-25 22:32:58 0 [Note] /mnt/workspace/percona-server-5.6-repeat/BUILD_TYPE/debug/Host/amd64/MTR_REPEAT/2/build/sql/mysqld-debug (mysqld 5.6.35-80.0-debug-log) starting as process 14550 ...
2017-02-25 22:32:58 14550 [Note] Plugin 'FEDERATED' is disabled.
2017-02-25 22:32:58 7faae4cdf720 InnoDB: Warning: Using innodb_additional_mem_pool_size is DEPRECATED. This option may be removed in future releases, together with the option innodb_use_sys_malloc and with the InnoDB's internal memory allocator.
2017-02-25 22:32:58 14550 [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.

2017-02-25 22:32:58 14550 [Note] InnoDB: Using atomics to ref count buffer pool pages
2017-02-25 22:32:58 7faae4cdf720 InnoDB: !!!!!!!! UNIV_DEBUG switched on !!!!!!!!!
2017-02-25 22:32:58 7faae4cdf720 InnoDB: !!!!!!!! UNIV_SYNC_DEBUG switched on !!!!!!!!!
2017-02-25 22:32:58 14550 [Note] InnoDB: The InnoDB memory heap is disabled
2017-02-25 22:32:58 14550 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
2017-02-25 22:32:58 14550 [Note] InnoDB: Memory barrier is not used
2017-02-25 22:32:58 14550 [Note] InnoDB: Compressed tables use zlib 1.2.3
2017-02-25 22:32:58 14550 [Note] InnoDB: Using Linux native AIO
2017-02-25 22:32:58 14550 [Note] InnoDB: Using CPU crc32 instructions
2017-02-25 22:32:58 14550 [Note] InnoDB: Initializing buffer pool, size = 8.0M
2017-02-25 22:32:58 14550 [Note] InnoDB: Completed initialization of buffer pool
2017-02-25 22:32:58 14550 [Note] InnoDB: Highest supported file format is Barracuda.
2017-02-25 22:32:58 14550 [Note] InnoDB: starting tracking changed pages from LSN 29665621
2017-02-25 22:32:59 14550 [Note] InnoDB: 128 rollback segment(s) are active.
2017-02-25 22:32:59 14550 [Note] InnoDB: Waiting for purge to start
2017-02-25 22:32:59 14550 [Note] InnoDB: Percona XtraDB (http://www.percona.com) 5.6.35-80.0 started; log sequence number 29665621
2017-02-25 22:32:59 14550 [Note] RSA private key file not found: /mnt/workspace/percona-server-5.6-repeat/BUILD_TYPE/debug/Host/amd64/MTR_REPEAT/2/build/mysql-test/var/4/mysqld.1/data//private_key.pem. Some authentication plugins will not work.
2017-02-25 22:32:59 14550 [Note] RSA public key file not found: /mnt/workspace/percona-server-5.6-repeat/BUILD_TYPE/debug/Host/amd64/MTR_REPEAT/2/build/mysql-test/var/4/mysqld.1/data//public_key.pem. Some authentication plugins will not work.
2017-02-25 22:32:59 14550 [Note] Server hostname (bind-address): '*'; port: 13031
2017-02-25 22:32:59 14550 [Note] IPv6 is available.
2017-02-25 22:32:59 14550 [Note] - '::' resolves to '::';
2017-02-25 22:32:59 14550 [Note] Server socket created on IP: '::'.
2017-02-25 22:32:59 14550 [Note] Event Scheduler: Loaded 0 events
2017-02-25 22:32:59 14550 [Note] /mnt/workspace/percona-server-5.6-repeat/BUILD_TYPE/debug/Host/amd64/MTR_REPEAT/2/build/sql/mysqld-debug: ready for connections.
Version: '5.6.35-80.0-debug-log' socket: '/tmp/UK38Bwj7kw/4/mysqld.1.sock' port: 13031 MySQL Community Server (GPL)
2017-02-25 22:33:00 14550 [Note] /mnt/workspace/percona-server-5.6-repeat/BUILD_TYPE/debug/Host/amd64/MTR_REPEAT/2/build/sql/mysqld-debug: Normal shutdown

2017-02-25 22:33:00 14550 [Note] Giving 0 client threads a chance to die gracefully
2017-02-25 22:33:00 14550 [Note] Event Scheduler: Purging the queue. 0 events
2017-02-25 22:33:00 14550 [Note] Shutting down slave threads
2017-02-25 22:33:00 14550 [Note] Forcefully disconnecting 0 remaining clients
2017-02-25 22:33:00 14550 [Note] Binlog end
2017-02-25 22:33:00 14550 [Note] Shutting down plugin 'partition'
2017-02-25 22:33:00 14550 [Note] Shutting down plugin 'INNODB_CHANGED_PAGES'
2017-02-25 22:33:00 14550 [Note] Shutting down plugin 'INNODB_SYS_DATAFILES'
2017-02-25 22:33:00 14550 [Note] Shutting down plugin 'INNODB_SYS_TABLESPACES'
2017-02-25 22:33:00 14550 [Note] Shutting down plugin 'INNODB_SYS_FOREIGN_COLS'
2017-02-25 22:33:00 14550 [Note] Shutting down plugin 'INNODB_SYS_FOREIGN'
2017-02-25 22:33:00 14550 [Note] Shutting down plugin 'INNODB_SYS_FIELDS'
2017-02-25 22:33:00 14550 [Note] Shutting down plugin 'INNODB_SYS_COLUMNS'
2017-02-25 22:33:00 14550 [Note] Shutting down plugin 'INNODB_SYS_INDEXES'
2017-02-25 22:33:00 14550 [Note] Shutting down plugin 'INNODB_SYS_TABLESTATS'
2017-02-25 22:33:00 14550 [Note] Shutting down plugin 'INNODB_SYS_TABLES'
2017-02-25 22:33:00 14550 [Note] Shutting down plugin 'INNODB_FT_INDEX_TABLE'
2017-02-25 22:33:00 14550 [Note] Shutting down plugin 'INNODB_FT_INDEX_CACHE'
2017-02-25 22:33:00 14550 [Note] Shutting down plugin 'INNODB_FT_CONFIG'
2017-02-25 22:33:00 14550 [Note] Shutting down plugin 'INNODB_FT_BEING_DELETED'
2017-02-25 22:33:00 14550 [Note] Shutting down plugin 'INNODB_FT_DELETED'
2017-02-25 22:33:00 14550 [Note] Shutting down plugin 'INNODB_FT_DEFAULT_STOPWORD'
2017-02-25 22:33:00 14550 [Note] Shutting down plugin 'INNODB_METRICS'
2017-02-25 22:33:00 14550 [Note] Shutting down plugin 'INNODB_BUFFER_POOL_STATS'
2017-02-25 22:33:00 14550 [Note] Shutting down plugin 'INNODB_BUFFER_PAGE_LRU'
2017-02-25 22:33:00 14550 [Note] Shutting down plugin 'INNODB_BUFFER_PAGE'
2017-02-25 22:33:00 14550 [Note] Shutting down plugin 'INNODB_CMP_PER_INDEX_RESET'
2017-02-25 22:33:00 14550 [Note] Shutting down plugin 'INNODB_CMP_PER_INDEX'
2017-02-25 22:33:00 14550 [Note] Shutting down plugin 'INNODB_CMPMEM_RESET'
2017-02-25 22:33:00 14550 [Note] Shutting down plugin 'INNODB_CMPMEM'
2017-02-25 22:33:00 14550 [Note] Shutting down plugin 'INNODB_CMP_RESET'
2017-02-25 22:33:00 14550 [Note] Shutting down plugin 'INNODB_CMP'
2017-02-25 22:33:00 14550 [Note] Shutting down plugin 'INNODB_LOCK_WAITS'
2017-02-25 22:33:00 14550 [Note] Shutting down plugin 'INNODB_LOCKS'
2017-02-25 22:33:00 14550 [Note] Shutting down plugin 'INNODB_TRX'
2017-02-25 22:33:00 14550 [Note] Shutting down plugin 'XTRADB_ZIP_DICT_COLS'
2017-02-25 22:33:00 14550 [Note] Shutting down plugin 'XTRADB_ZIP_DICT'
2017-02-25 22:33:00 14550 [Note] Shutting down plugin 'XTRADB_RSEG'
2017-02-25 22:33:00 14550 [Note] Shutting down plugin 'XTRADB_INTERNAL_HASH_TABLES'
2017-02-25 22:33:00 14550 [Note] Shutting down plugin 'XTRADB_READ_VIEW'
2017-02-25 22:33:00 14550 [Note] Shutting down plugin 'ARCHIVE'
2017-02-25 22:33:00 14550 [Note] Shutting down plugin 'BLACKHOLE'
2017-02-25 22:33:00 14550 [Note] Shutting down plugin 'PERFORMANCE_SCHEMA'
2017-02-25 22:33:00 14550 [Note] Shutting down plugin 'MEMORY'
2017-02-25 22:33:00 14550 [Note] Shutting down plugin 'CSV'
2017-02-25 22:33:00 14550 [Note] Shutting down plugin 'MyISAM'
2017-02-25 22:33:00 14550 [Note] Shutting down plugin 'MRG_MYISAM'
2017-02-25 22:33:00 14550 [Note] Shutting down plugin 'sha256_password'
2017-02-25 22:33:00 14550 [Note] Shutting down plugin 'mysql_old_password'
2017-02-25 22:33:00 14550 [Note] Shutting down plugin 'mysql_native_password'
2017-02-25 22:33:00 14550 [Note] Shutting down plugin 'binlog'
2017-02-25 22:33:00 14550 [Note] Shutting down plugin 'InnoDB'
2017-02-25 22:33:00 14550 [Note] InnoDB: FTS optimize thread exiting.
2017-02-25 22:33:00 14550 [Note] InnoDB: Starting shutdown...
2017-02-25 22:33:01 14550 [Note] InnoDB: Waiting for page_cleaner to finish flushing of buffer pool
2017-02-25 22:33:02 14550 [Note] InnoDB: Shutdown completed; log sequence number 29667357
2017-02-25 22:33:02 14550 [Note] Debug sync points hit: 2674
2017-02-25 22:33:02 14550 [Note] Debug sync points executed: 0
2017-02-25 22:33:02 14550 [Note] Debug sync points max active per thread: 0
2017-02-25 22:33:02 14550 [Note] /mnt/workspace/percona-server-5.6-repeat/BUILD_TYPE/debug/Host/amd64/MTR_REPEAT/2/build/sql/mysqld-debug: Shutdown complete

2017-02-25 22:33:03 0 [Warning] TIMESTAMP with implicit DEFAULT value is deprecated. Please use --explicit_defaults_for_timestamp server option (see documentation for more details).
2017-02-25 22:33:03 0 [Warning] Insecure configuration for --secure-file-priv: Data directory is accessible through --secure-file-priv. Consider choosing a different directory.
2017-02-25 22:33:03 0 [Warning] Insecure configuration for --secure-file-priv: Location is accessible to all OS users. Consider choosing a different directory.
2017-02-25 22:33:03 0 [Note] /mnt/workspace/percona-server-5.6-repeat/BUILD_TYPE/debug/Host/amd64/MTR_REPEAT/2/build/sql/mysqld-debug (mysqld 5.6.35-80.0-debug-log) starting as process 14620 ...
2017-02-25 22:33:03 14620 [Note] Plugin 'FEDERATED' is disabled.
2017-02-25 22:33:03 7f916f118720 InnoDB: Warning: Using innodb_additional_mem_pool_size is DEPRECATED. This option may be removed in future releases, together with the option innodb_use_sys_malloc and with the InnoDB's internal memory allocator.
2017-02-25 22:33:03 14620 [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.

2017-02-25 22:33:03 14620 [Note] InnoDB: Using atomics to ref count buffer pool pages
2017-02-25 22:33:03 7f916f118720 InnoDB: !!!!!!!! UNIV_DEBUG switched on !!!!!!!!!
2017-02-25 22:33:03 7f916f118720 InnoDB: !!!!!!!! UNIV_SYNC_DEBUG switched on !!!!!!!!!
2017-02-25 22:33:03 14620 [Note] InnoDB: The InnoDB memory heap is disabled
2017-02-25 22:33:03 14620 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
2017-02-25 22:33:03 14620 [Note] InnoDB: Memory barrier is not used
2017-02-25 22:33:03 14620 [Note] InnoDB: Compressed tables use zlib 1.2.3
2017-02-25 22:33:03 14620 [Note] InnoDB: Using Linux native AIO
2017-02-25 22:33:03 14620 [Note] InnoDB: Using CPU crc32 instructions
2017-02-25 22:33:03 14620 [Note] InnoDB: Initializing buffer pool, size = 8.0M
2017-02-25 22:33:03 14620 [Note] InnoDB: Completed initialization of buffer pool
2017-02-25 22:33:03 14620 [Note] InnoDB: Highest supported file format is Barracuda.
2017-02-25 22:33:03 14620 [Note] InnoDB: starting tracking changed pages from LSN 29667357
2017-02-25 22:33:04 14620 [Note] InnoDB: 128 rollback segment(s) are active.
2017-02-25 22:33:04 14620 [Note] InnoDB: Waiting for purge to start
2017-02-25 22:33:04 14620 [Note] InnoDB: Percona XtraDB (http://www.percona.com) 5.6.35-80.0 started; log sequence number 29667357
2017-02-25 22:33:04 14620 [Note] RSA private key file not found: /mnt/workspace/percona-server-5.6-repeat/BUILD_TYPE/debug/Host/amd64/MTR_REPEAT/2/build/mysql-test/var/4/mysqld.1/data//private_key.pem. Some authentication plugins will not work.
2017-02-25 22:33:04 14620 [Note] RSA public key file not found: /mnt/workspace/percona-server-5.6-repeat/BUILD_TYPE/debug/Host/amd64/MTR_REPEAT/2/build/mysql-test/var/4/mysqld.1/data//public_key.pem. Some authentication plugins will not work.
2017-02-25 22:33:04 14620 [Note] Server hostname (bind-address): '*'; port: 13031
2017-02-25 22:33:04 14620 [Note] IPv6 is available.
2017-02-25 22:33:04 14620 [Note] - '::' resolves to '::';
2017-02-25 22:33:04 14620 [Note] Server socket created on IP: '::'.
2017-02-25 22:33:04 14620 [Note] Event Scheduler: Loaded 0 events
2017-02-25 22:33:04 14620 [Note] /mnt/workspace/percona-server-5.6-repeat/BUILD_TYPE/debug/Host/amd64/MTR_REPEAT/2/build/sql/mysqld-debug: ready for connections.
Version: '5.6.35-80.0-debug-log' socket: '/tmp/UK38Bwj7kw/4/mysqld.1.sock' port: 13031 MySQL Community Server (GPL)
2017-02-25 22:33:04 14620 [Note] /mnt/workspace/percona-server-5.6-repeat/BUILD_TYPE/debug/Host/amd64/MTR_REPEAT/2/build/sql/mysqld-debug: Normal shutdown

2017-02-25 22:33:04 14620 [Note] Giving 0 client threads a chance to die gracefully
2017-02-25 22:33:04 14620 [Note] Event Scheduler: Purging the queue. 0 events
2017-02-25 22:33:04 14620 [Note] Shutting down slave threads
2017-02-25 22:33:04 14620 [Note] Forcefully disconnecting 0 remaining clients
2017-02-25 22:33:04 14620 [Note] Binlog end
2017-02-25 22:33:04 14620 [Note] Shutting down plugin 'partition'
2017-02-25 22:33:04 14620 [Note] Shutting down plugin 'INNODB_CHANGED_PAGES'
2017-02-25 22:33:04 14620 [Note] Shutting down plugin 'INNODB_SYS_DATAFILES'
2017-02-25 22:33:04 14620 [Note] Shutting down plugin 'INNODB_SYS_TABLESPACES'
2017-02-25 22:33:04 14620 [Note] Shutting down plugin 'INNODB_SYS_FOREIGN_COLS'
2017-02-25 22:33:04 14620 [Note] Shutting down plugin 'INNODB_SYS_FOREIGN'
2017-02-25 22:33:04 14620 [Note] Shutting down plugin 'INNODB_SYS_FIELDS'
2017-02-25 22:33:04 14620 [Note] Shutting down plugin 'INNODB_SYS_COLUMNS'
2017-02-25 22:33:04 14620 [Note] Shutting down plugin 'INNODB_SYS_INDEXES'
2017-02-25 22:33:04 14620 [Note] Shutting down plugin 'INNODB_SYS_TABLESTATS'
2017-02-25 22:33:04 14620 [Note] Shutting down plugin 'INNODB_SYS_TABLES'
2017-02-25 22:33:04 14620 [Note] Shutting down plugin 'INNODB_FT_INDEX_TABLE'
2017-02-25 22:33:04 14620 [Note] Shutting down plugin 'INNODB_FT_INDEX_CACHE'
2017-02-25 22:33:04 14620 [Note] Shutting down plugin 'INNODB_FT_CONFIG'
2017-02-25 22:33:04 14620 [Note] Shutting down plugin 'INNODB_FT_BEING_DELETED'
2017-02-25 22:33:04 14620 [Note] Shutting down plugin 'INNODB_FT_DELETED'
2017-02-25 22:33:04 14620 [Note] Shutting down plugin 'INNODB_FT_DEFAULT_STOPWORD'
2017-02-25 22:33:04 14620 [Note] Shutting down plugin 'INNODB_METRICS'
2017-02-25 22:33:04 14620 [Note] Shutting down plugin 'INNODB_BUFFER_POOL_STATS'
2017-02-25 22:33:04 14620 [Note] Shutting down plugin 'INNODB_BUFFER_PAGE_LRU'
2017-02-25 22:33:04 14620 [Note] Shutting down plugin 'INNODB_BUFFER_PAGE'
2017-02-25 22:33:04 14620 [Note] Shutting down plugin 'INNODB_CMP_PER_INDEX_RESET'
2017-02-25 22:33:04 14620 [Note] Shutting down plugin 'INNODB_CMP_PER_INDEX'
2017-02-25 22:33:04 14620 [Note] Shutting down plugin 'INNODB_CMPMEM_RESET'
2017-02-25 22:33:04 14620 [Note] Shutting down plugin 'INNODB_CMPMEM'
2017-02-25 22:33:04 14620 [Note] Shutting down plugin 'INNODB_CMP_RESET'
2017-02-25 22:33:04 14620 [Note] Shutting down plugin 'INNODB_CMP'
2017-02-25 22:33:04 14620 [Note] Shutting down plugin 'INNODB_LOCK_WAITS'
2017-02-25 22:33:04 14620 [Note] Shutting down plugin 'INNODB_LOCKS'
2017-02-25 22:33:04 14620 [Note] Shutting down plugin 'INNODB_TRX'
2017-02-25 22:33:04 14620 [Note] Shutting down plugin 'XTRADB_ZIP_DICT_COLS'
2017-02-25 22:33:04 14620 [Note] Shutting down plugin 'XTRADB_ZIP_DICT'
2017-02-25 22:33:04 14620 [Note] Shutting down plugin 'XTRADB_RSEG'
2017-02-25 22:33:04 14620 [Note] Shutting down plugin 'XTRADB_INTERNAL_HASH_TABLES'
2017-02-25 22:33:04 14620 [Note] Shutting down plugin 'XTRADB_READ_VIEW'
2017-02-25 22:33:04 14620 [Note] Shutting down plugin 'ARCHIVE'
2017-02-25 22:33:04 14620 [Note] Shutting down plugin 'BLACKHOLE'
2017-02-25 22:33:04 14620 [Note] Shutting down plugin 'PERFORMANCE_SCHEMA'
2017-02-25 22:33:04 14620 [Note] Shutting down plugin 'MEMORY'
2017-02-25 22:33:04 14620 [Note] Shutting down plugin 'CSV'
2017-02-25 22:33:04 14620 [Note] Shutting down plugin 'MyISAM'
2017-02-25 22:33:04 14620 [Note] Shutting down plugin 'MRG_MYISAM'
2017-02-25 22:33:04 14620 [Note] Shutting down plugin 'sha256_password'
2017-02-25 22:33:04 14620 [Note] Shutting down plugin 'mysql_old_password'
2017-02-25 22:33:04 14620 [Note] Shutting down plugin 'mysql_native_password'
2017-02-25 22:33:04 14620 [Note] Shutting down plugin 'binlog'
2017-02-25 22:33:04 14620 [Note] Shutting down plugin 'InnoDB'
2017-02-25 22:33:04 14620 [Note] InnoDB: FTS optimize thread exiting.
2017-02-25 22:33:04 14620 [Note] InnoDB: Starting shutdown...
2017-02-25 22:33:05 14620 [Note] InnoDB: Waiting for page_cleaner to finish flushing of buffer pool
2017-02-25 22:33:07 14620 [Note] InnoDB: Shutdown completed; log sequence number 29669077
2017-02-25 22:33:07 14620 [Note] Debug sync points hit: 2735
2017-02-25 22:33:07 14620 [Note] Debug sync points executed: 0
2017-02-25 22:33:07 14620 [Note] Debug sync points max active per thread: 0
2017-02-25 22:33:07 14620 [Note] /mnt/workspace/percona-server-5.6-repeat/BUILD_TYPE/debug/Host/amd64/MTR_REPEAT/2/build/sql/mysqld-debug: Shutdown complete

2017-02-25 22:33:08 0 [Warning] TIMESTAMP with implicit DEFAULT value is deprecated. Please use --explicit_defaults_for_timestamp server option (see documentation for more details).
2017-02-25 22:33:08 0 [Warning] Insecure configuration for --secure-file-priv: Data directory is accessible through --secure-file-priv. Consider choosing a different directory.
2017-02-25 22:33:08 0 [Warning] Insecure configuration for --secure-file-priv: Location is accessible to all OS users. Consider choosing a different directory.
2017-02-25 22:33:08 0 [Note] /mnt/workspace/percona-server-5.6-repeat/BUILD_TYPE/debug/Host/amd64/MTR_REPEAT/2/build/sql/mysqld-debug (mysqld 5.6.35-80.0-debug-log) starting as process 14665 ...
2017-02-25 22:33:08 14665 [Note] Plugin 'FEDERATED' is disabled.
2017-02-25 22:33:08 7f7875ae3720 InnoDB: Warning: Using innodb_additional_mem_pool_size is DEPRECATED. This option may be removed in future releases, together with the option innodb_use_sys_malloc and with the InnoDB's internal memory allocator.
2017-02-25 22:33:08 14665 [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.

2017-02-25 22:33:08 14665 [Note] InnoDB: Using atomics to ref count buffer pool pages
2017-02-25 22:33:08 7f7875ae3720 InnoDB: !!!!!!!! UNIV_DEBUG switched on !!!!!!!!!
2017-02-25 22:33:08 7f7875ae3720 InnoDB: !!!!!!!! UNIV_SYNC_DEBUG switched on !!!!!!!!!
2017-02-25 22:33:08 14665 [Note] InnoDB: The InnoDB memory heap is disabled
2017-02-25 22:33:08 14665 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
2017-02-25 22:33:08 14665 [Note] InnoDB: Memory barrier is not used
2017-02-25 22:33:08 14665 [Note] InnoDB: Compressed tables use zlib 1.2.3
2017-02-25 22:33:08 14665 [Note] InnoDB: Using Linux native AIO
2017-02-25 22:33:08 14665 [Note] InnoDB: Using CPU crc32 instructions
2017-02-25 22:33:08 14665 [Note] InnoDB: Initializing buffer pool, size = 8.0M
2017-02-25 22:33:08 14665 [Note] InnoDB: Completed initialization of buffer pool
2017-02-25 22:33:08 14665 [Note] InnoDB: Highest supported file format is Barracuda.
2017-02-25 22:33:08 14665 [Warning] InnoDB: last tracked LSN in './ib_modified_log_1_0.xdb' is 8204, but the last checkpoint LSN is 29669077. This might be due to a server crash or a very fast shutdown.
2017-02-25 22:33:08 14665 [Warning] InnoDB: the age of last tracked LSN exceeds log capacity, tracking-based incremental backups will work only from the higher LSN!
2017-02-25 22:33:08 14665 [Note] InnoDB: starting tracking changed pages from LSN 29669077
2017-02-25 22:33:09 14665 [Note] InnoDB: 128 rollback segment(s) are active.
2017-02-25 22:33:09 14665 [Note] InnoDB: Waiting for purge to start
2017-02-25 22:33:09 14665 [Note] InnoDB: Percona XtraDB (http://www.percona.com) 5.6.35-80.0 started; log sequence number 29669077
2017-02-25 22:33:09 14665 [Note] RSA private key file not found: /mnt/workspace/percona-server-5.6-repeat/BUILD_TYPE/debug/Host/amd64/MTR_REPEAT/2/build/mysql-test/var/4/mysqld.1/data//private_key.pem. Some authentication plugins will not work.
2017-02-25 22:33:09 14665 [Note] RSA public key file not found: /mnt/workspace/percona-server-5.6-repeat/BUILD_TYPE/debug/Host/amd64/MTR_REPEAT/2/build/mysql-test/var/4/mysqld.1/data//public_key.pem. Some authentication plugins will not work.
2017-02-25 22:33:09 14665 [Note] Server hostname (bind-address): '*'; port: 13031
2017-02-25 22:33:09 14665 [Note] IPv6 is available.
2017-02-25 22:33:09 14665 [Note] - '::' resolves to '::';
2017-02-25 22:33:09 14665 [Note] Server socket created on IP: '::'.
2017-02-25 22:33:09 14665 [Note] Event Scheduler: Loaded 0 events
2017-02-25 22:33:09 14665 [Note] /mnt/workspace/percona-server-5.6-repeat/BUILD_TYPE/debug/Host/amd64/MTR_REPEAT/2/build/sql/mysqld-debug: ready for connections.
Version: '5.6.35-80.0-debug-log' socket: '/tmp/UK38Bwj7kw/4/mysqld.1.sock' port: 13031 MySQL Community Server (GPL)
----------SERVER LOG END-------------

[Sveta Smirnova (svetasmirnova)]

Repeatable with 5.7 as well

[Shahriyar Rzayev (rzayev-sehriyar)]

Percona now uses JIRA for bug reports so this bug report is migrated to: https://jira.percona.com/browse/PS-2239