| Summary: |
dev-db/percona-server-5.6.26.74.0 - Test innodb.percona_changed_page_bmp_flush fails with "File (unknown): 'read' returned OS error 122. Cannot continue operation" |
| Product: |
Gentoo Linux
|
Reporter: |
Thomas Deutschmann (RETIRED) <whissi> |
| Component: |
[OLD] Server | Assignee: |
Gentoo Linux MySQL bugs team <mysql-bugs> |
| Status: |
RESOLVED
UPSTREAM
|
|
|
| Severity: |
normal
|
|
|
| Priority: |
Normal
|
|
|
| Version: |
unspecified | |
|
| Hardware: |
All | |
|
| OS: |
Linux | |
|
| See Also: |
https://launchpad.net/bugs/1498891
|
| Whiteboard: |
|
|
Package list:
|
|
Runtime testing required:
|
---
|
|---|
Hi, dev-db/percona-server-5.6.26.74.0 test suite is failing with innodb.percona_changed_page_bmp_flush w4 [ fail ] Test ended at 2015-09-21 13:50:15 CURRENT_TEST: innodb.percona_changed_page_bmp_flush Server [mysqld.1 - pid: 102622, winpid: 102622, exit: 256] failed during test run Server log from this test: ----------SERVER LOG START----------- 2015-09-21 14:50:06 102119 [Note] /var/tmp/portage/dev-db/percona-server-5.6.26.74.0/work/mysql-abi_x86_64.amd64/sql/mysqld: Normal shutdown 2015-09-21 14:50:06 102119 [Note] Giving 0 client threads a chance to die gracefully 2015-09-21 14:50:06 102119 [Note] Event Scheduler: Purging the queue. 0 events 2015-09-21 14:50:06 102119 [Note] Shutting down slave threads 2015-09-21 14:50:06 102119 [Note] Forcefully disconnecting 0 remaining clients 2015-09-21 14:50:06 102119 [Note] Binlog end [...] 2015-09-21 14:50:08 102119 [Note] /var/tmp/portage/dev-db/percona-server-5.6.26.74.0/work/mysql-abi_x86_64.amd64/sql/mysqld: Shutdown complete 2015-09-21 14:50:08 0 [Warning] TIMESTAMP with implicit DEFAULT value is deprecated. Please use --explicit_defaults_for_timestamp server option (see documentation for more details). 2015-09-21 14:50:08 0 [Note] /var/tmp/portage/dev-db/percona-server-5.6.26.74.0/work/mysql-abi_x86_64.amd64/sql/mysqld (mysqld 5.6.26-74.0-log) starting as process 102277 ... 2015-09-21 14:50:08 102277 [Warning] Buffered warning: Could not increase number of max_open_files to more than 3000 (request: 4162) 2015-09-21 14:50:08 102277 [Warning] Buffered warning: Changed limits: table_open_cache: 1419 (requested 2000) 2015-09-21 14:50:08 7f19d60bd780 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. 2015-09-21 14:50:08 102277 [Note] InnoDB: Using atomics to ref count buffer pool pages 2015-09-21 14:50:08 102277 [Note] InnoDB: The InnoDB memory heap is disabled 2015-09-21 14:50:08 102277 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins 2015-09-21 14:50:08 102277 [Note] InnoDB: Memory barrier is not used 2015-09-21 14:50:08 102277 [Note] InnoDB: Compressed tables use zlib 1.2.8 2015-09-21 14:50:08 102277 [Note] InnoDB: Using Linux native AIO 2015-09-21 14:50:08 102277 [Note] InnoDB: Using CPU crc32 instructions 2015-09-21 14:50:08 102277 [Note] InnoDB: Initializing buffer pool, size = 8.0M 2015-09-21 14:50:08 102277 [Note] InnoDB: Completed initialization of buffer pool 2015-09-21 14:50:08 102277 [Note] InnoDB: Highest supported file format is Barracuda. 2015-09-21 14:50:08 102277 [Note] InnoDB: starting tracking changed pages from LSN 1630586 2015-09-21 14:50:08 102277 [Note] InnoDB: 128 rollback segment(s) are active. 2015-09-21 14:50:08 102277 [Note] InnoDB: Waiting for purge to start 2015-09-21 14:50:09 102277 [Note] InnoDB: Percona XtraDB (http://www.percona.com) 5.6.26-74.0 started; log sequence number 1630586 2015-09-21 14:50:09 102277 [Warning] /var/tmp/portage/dev-db/percona-server-5.6.26.74.0/work/mysql-abi_x86_64.amd64/sql/mysqld: unknown variable 'loose-debug-sync-timeout=600' 2015-09-21 14:50:09 102277 [Note] RSA private key file not found: /var/tmp/portage/dev-db/percona-server-5.6.26.74.0/temp/var-tests/4/mysqld.1/data//private_key.pem. Some authentication plugins will not work. 2015-09-21 14:50:09 102277 [Note] RSA public key file not found: /var/tmp/portage/dev-db/percona-server-5.6.26.74.0/temp/var-tests/4/mysqld.1/data//public_key.pem. Some authentication plugins will not work. 2015-09-21 14:50:09 102277 [Note] Server hostname (bind-address): '*'; port: 10161 2015-09-21 14:50:09 102277 [Note] IPv6 is available. 2015-09-21 14:50:09 102277 [Note] - '::' resolves to '::'; 2015-09-21 14:50:09 102277 [Note] Server socket created on IP: '::'. 2015-09-21 14:50:09 102277 [Note] Event Scheduler: Loaded 0 events 2015-09-21 14:50:09 102277 [Note] /var/tmp/portage/dev-db/percona-server-5.6.26.74.0/work/mysql-abi_x86_64.amd64/sql/mysqld: ready for connections. Version: '5.6.26-74.0-log' socket: '/var/tmp/portage/dev-db/percona-server-5.6.26.74.0/temp/var-tests/tmp/4/mysqld.1.sock' port: 10161 Source distribution 2015-09-21 14:50:09 102277 [Note] /var/tmp/portage/dev-db/percona-server-5.6.26.74.0/work/mysql-abi_x86_64.amd64/sql/mysqld: Normal shutdown 2015-09-21 14:50:09 102277 [Note] Giving 0 client threads a chance to die gracefully 2015-09-21 14:50:09 102277 [Note] Event Scheduler: Purging the queue. 0 events 2015-09-21 14:50:09 102277 [Note] Shutting down slave threads 2015-09-21 14:50:09 102277 [Note] Forcefully disconnecting 0 remaining clients 2015-09-21 14:50:09 102277 [Note] Binlog end [...] 2015-09-21 14:50:11 102277 [Note] /var/tmp/portage/dev-db/percona-server-5.6.26.74.0/work/mysql-abi_x86_64.amd64/sql/mysqld: Shutdown complete 2015-09-21 14:50:12 0 [Warning] TIMESTAMP with implicit DEFAULT value is deprecated. Please use --explicit_defaults_for_timestamp server option (see documentation for more details). 2015-09-21 14:50:12 0 [Note] /var/tmp/portage/dev-db/percona-server-5.6.26.74.0/work/mysql-abi_x86_64.amd64/sql/mysqld (mysqld 5.6.26-74.0-log) starting as process 102498 ... 2015-09-21 14:50:12 102498 [Warning] Buffered warning: Could not increase number of max_open_files to more than 3000 (request: 4162) 2015-09-21 14:50:12 102498 [Warning] Buffered warning: Changed limits: table_open_cache: 1419 (requested 2000) 2015-09-21 14:50:12 7fa276bbc780 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. 2015-09-21 14:50:12 102498 [Note] InnoDB: Using atomics to ref count buffer pool pages 2015-09-21 14:50:12 102498 [Note] InnoDB: The InnoDB memory heap is disabled 2015-09-21 14:50:12 102498 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins 2015-09-21 14:50:12 102498 [Note] InnoDB: Memory barrier is not used 2015-09-21 14:50:12 102498 [Note] InnoDB: Compressed tables use zlib 1.2.8 2015-09-21 14:50:12 102498 [Note] InnoDB: Using Linux native AIO 2015-09-21 14:50:12 102498 [Note] InnoDB: Using CPU crc32 instructions 2015-09-21 14:50:12 102498 [Note] InnoDB: Initializing buffer pool, size = 8.0M 2015-09-21 14:50:12 102498 [Note] InnoDB: Completed initialization of buffer pool 2015-09-21 14:50:12 102498 [Note] InnoDB: Highest supported file format is Barracuda. 2015-09-21 14:50:12 102498 [Note] InnoDB: starting tracking changed pages from LSN 1651551 2015-09-21 14:50:12 102498 [Note] InnoDB: 128 rollback segment(s) are active. 2015-09-21 14:50:12 102498 [Note] InnoDB: Waiting for purge to start 2015-09-21 14:50:12 102498 [Note] InnoDB: Percona XtraDB (http://www.percona.com) 5.6.26-74.0 started; log sequence number 1651551 2015-09-21 14:50:12 102498 [Warning] /var/tmp/portage/dev-db/percona-server-5.6.26.74.0/work/mysql-abi_x86_64.amd64/sql/mysqld: unknown variable 'loose-debug-sync-timeout=600' 2015-09-21 14:50:12 102498 [Note] RSA private key file not found: /var/tmp/portage/dev-db/percona-server-5.6.26.74.0/temp/var-tests/4/mysqld.1/data//private_key.pem. Some authentication plugins will not work. 2015-09-21 14:50:12 102498 [Note] RSA public key file not found: /var/tmp/portage/dev-db/percona-server-5.6.26.74.0/temp/var-tests/4/mysqld.1/data//public_key.pem. Some authentication plugins will not work. 2015-09-21 14:50:12 102498 [Note] Server hostname (bind-address): '*'; port: 10161 2015-09-21 14:50:12 102498 [Note] IPv6 is available. 2015-09-21 14:50:12 102498 [Note] - '::' resolves to '::'; 2015-09-21 14:50:12 102498 [Note] Server socket created on IP: '::'. 2015-09-21 14:50:12 102498 [Note] Event Scheduler: Loaded 0 events 2015-09-21 14:50:12 102498 [Note] /var/tmp/portage/dev-db/percona-server-5.6.26.74.0/work/mysql-abi_x86_64.amd64/sql/mysqld: ready for connections. Version: '5.6.26-74.0-log' socket: '/var/tmp/portage/dev-db/percona-server-5.6.26.74.0/temp/var-tests/tmp/4/mysqld.1.sock' port: 10161 Source distribution 2015-09-21 14:50:12 102498 [Note] /var/tmp/portage/dev-db/percona-server-5.6.26.74.0/work/mysql-abi_x86_64.amd64/sql/mysqld: Normal shutdown 2015-09-21 14:50:12 102498 [Note] Giving 0 client threads a chance to die gracefully 2015-09-21 14:50:12 102498 [Note] Event Scheduler: Purging the queue. 0 events 2015-09-21 14:50:12 102498 [Note] Shutting down slave threads 2015-09-21 14:50:12 102498 [Note] Forcefully disconnecting 0 remaining clients 2015-09-21 14:50:12 102498 [Note] Binlog end 2015-09-21 14:50:12 102498 [Note] Shutting down plugin 'partition' 2015-09-21 14:50:12 102498 [Note] Shutting down plugin 'ARCHIVE' 2015-09-21 14:50:12 102498 [Note] Shutting down plugin 'BLACKHOLE' 2015-09-21 14:50:12 102498 [Note] Shutting down plugin 'INNODB_CHANGED_PAGES' 2015-09-21 14:50:12 102498 [Note] Shutting down plugin 'INNODB_SYS_DATAFILES' 2015-09-21 14:50:12 102498 [Note] Shutting down plugin 'INNODB_SYS_TABLESPACES' 2015-09-21 14:50:12 102498 [Note] Shutting down plugin 'INNODB_SYS_FOREIGN_COLS' 2015-09-21 14:50:12 102498 [Note] Shutting down plugin 'INNODB_SYS_FOREIGN' 2015-09-21 14:50:12 102498 [Note] Shutting down plugin 'INNODB_SYS_FIELDS' 2015-09-21 14:50:12 102498 [Note] Shutting down plugin 'INNODB_SYS_COLUMNS' 2015-09-21 14:50:12 102498 [Note] Shutting down plugin 'INNODB_SYS_INDEXES' 2015-09-21 14:50:12 102498 [Note] Shutting down plugin 'INNODB_SYS_TABLESTATS' 2015-09-21 14:50:12 102498 [Note] Shutting down plugin 'INNODB_SYS_TABLES' 2015-09-21 14:50:12 102498 [Note] Shutting down plugin 'INNODB_FT_INDEX_TABLE' 2015-09-21 14:50:12 102498 [Note] Shutting down plugin 'INNODB_FT_INDEX_CACHE' 2015-09-21 14:50:12 102498 [Note] Shutting down plugin 'INNODB_FT_CONFIG' 2015-09-21 14:50:12 102498 [Note] Shutting down plugin 'INNODB_FT_BEING_DELETED' 2015-09-21 14:50:12 102498 [Note] Shutting down plugin 'INNODB_FT_DELETED' 2015-09-21 14:50:12 102498 [Note] Shutting down plugin 'INNODB_FT_DEFAULT_STOPWORD' 2015-09-21 14:50:12 102498 [Note] Shutting down plugin 'INNODB_METRICS' 2015-09-21 14:50:12 102498 [Note] Shutting down plugin 'INNODB_BUFFER_POOL_STATS' 2015-09-21 14:50:12 102498 [Note] Shutting down plugin 'INNODB_BUFFER_PAGE_LRU' 2015-09-21 14:50:12 102498 [Note] Shutting down plugin 'INNODB_BUFFER_PAGE' 2015-09-21 14:50:12 102498 [Note] Shutting down plugin 'INNODB_CMP_PER_INDEX_RESET' 2015-09-21 14:50:12 102498 [Note] Shutting down plugin 'INNODB_CMP_PER_INDEX' 2015-09-21 14:50:12 102498 [Note] Shutting down plugin 'INNODB_CMPMEM_RESET' 2015-09-21 14:50:12 102498 [Note] Shutting down plugin 'INNODB_CMPMEM' 2015-09-21 14:50:12 102498 [Note] Shutting down plugin 'INNODB_CMP_RESET' 2015-09-21 14:50:12 102498 [Note] Shutting down plugin 'INNODB_CMP' 2015-09-21 14:50:12 102498 [Note] Shutting down plugin 'INNODB_LOCK_WAITS' 2015-09-21 14:50:12 102498 [Note] Shutting down plugin 'INNODB_LOCKS' 2015-09-21 14:50:12 102498 [Note] Shutting down plugin 'INNODB_TRX' 2015-09-21 14:50:12 102498 [Note] Shutting down plugin 'XTRADB_RSEG' 2015-09-21 14:50:12 102498 [Note] Shutting down plugin 'XTRADB_INTERNAL_HASH_TABLES' 2015-09-21 14:50:12 102498 [Note] Shutting down plugin 'XTRADB_READ_VIEW' 2015-09-21 14:50:12 102498 [Note] Shutting down plugin 'InnoDB' 2015-09-21 14:50:12 102498 [Note] InnoDB: FTS optimize thread exiting. 2015-09-21 14:50:12 102498 [Note] InnoDB: Starting shutdown... 2015-09-21 14:50:14 102498 [Note] InnoDB: Shutdown completed; log sequence number 1672513 2015-09-21 14:50:14 102498 [Note] Shutting down plugin 'PERFORMANCE_SCHEMA' 2015-09-21 14:50:14 102498 [Note] Shutting down plugin 'MRG_MYISAM' 2015-09-21 14:50:14 102498 [Note] Shutting down plugin 'MyISAM' 2015-09-21 14:50:14 102498 [Note] Shutting down plugin 'MEMORY' 2015-09-21 14:50:14 102498 [Note] Shutting down plugin 'CSV' 2015-09-21 14:50:14 102498 [Note] Shutting down plugin 'sha256_password' 2015-09-21 14:50:14 102498 [Note] Shutting down plugin 'mysql_old_password' 2015-09-21 14:50:14 102498 [Note] Shutting down plugin 'mysql_native_password' 2015-09-21 14:50:14 102498 [Note] Shutting down plugin 'binlog' 2015-09-21 14:50:14 102498 [Note] /var/tmp/portage/dev-db/percona-server-5.6.26.74.0/work/mysql-abi_x86_64.amd64/sql/mysqld: Shutdown complete 2015-09-21 14:50:15 0 [Warning] TIMESTAMP with implicit DEFAULT value is deprecated. Please use --explicit_defaults_for_timestamp server option (see documentation for more details). 2015-09-21 14:50:15 0 [Note] /var/tmp/portage/dev-db/percona-server-5.6.26.74.0/work/mysql-abi_x86_64.amd64/sql/mysqld (mysqld 5.6.26-74.0-log) starting as process 102623 ... 2015-09-21 14:50:15 102623 [Warning] Buffered warning: Could not increase number of max_open_files to more than 3000 (request: 4162) 2015-09-21 14:50:15 102623 [Warning] Buffered warning: Changed limits: table_open_cache: 1419 (requested 2000) 2015-09-21 14:50:15 7f4f1e4ea780 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. 2015-09-21 14:50:15 102623 [Note] InnoDB: Using atomics to ref count buffer pool pages 2015-09-21 14:50:15 102623 [Note] InnoDB: The InnoDB memory heap is disabled 2015-09-21 14:50:15 102623 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins 2015-09-21 14:50:15 102623 [Note] InnoDB: Memory barrier is not used 2015-09-21 14:50:15 102623 [Note] InnoDB: Compressed tables use zlib 1.2.8 2015-09-21 14:50:15 102623 [Note] InnoDB: Using Linux native AIO 2015-09-21 14:50:15 102623 [Note] InnoDB: Using CPU crc32 instructions 2015-09-21 14:50:15 102623 [Note] InnoDB: Initializing buffer pool, size = 8.0M 2015-09-21 14:50:15 102623 [Note] InnoDB: Completed initialization of buffer pool 2015-09-21 14:50:15 102623 [Note] InnoDB: Highest supported file format is Barracuda. 2015-09-21 14:50:15 102623 [ERROR] InnoDB: Tried to read 4096 bytes at offset 4096. Was only able to read 0. 2015-09-21 14:50:15 7f4f1e4ea780 InnoDB: Operating system error number 22 in a file operation. InnoDB: Error number 22 means 'Invalid argument'. InnoDB: Some operating system error numbers are described at InnoDB: http://dev.mysql.com/doc/refman/5.6/en/operating-system-error-codes.html 2015-09-21 14:50:15 102623 [ERROR] InnoDB: File (unknown): 'read' returned OS error 122. Cannot continue operation ----------SERVER LOG END------------- mysqltest failed but provided no output The result from queries just before the failure was: < snip > call mtr.add_suppression("Failed to set O_DIRECT on file"); call mtr.add_suppression("O_DIRECT is known to result in"); DROP TABLE IF EXISTS t1; RESET CHANGED_PAGE_BITMAPS; CREATE TABLE t1 (a INT, b BLOB) ENGINE=InnoDB; INSERT INTO t1 VALUES (1, REPEAT("a", 20000)); ib_modified_log_1 INSERT INTO t1 VALUES (2, REPEAT("b", 20000)); ib_modified_log_1 ib_modified_log_2