Gentoo Websites Logo
Go to: Gentoo Home Documentation Forums Lists Bugs Planet Store Wiki Get Gentoo!
Bugzilla DB migration completed. Please report issues to Infra team via email via infra@gentoo.org or IRC
Bug 561020 - 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"
Summary: dev-db/percona-server-5.6.26.74.0 - Test innodb.percona_changed_page_bmp_flus...
Status: RESOLVED UPSTREAM
Alias: None
Product: Gentoo Linux
Classification: Unclassified
Component: [OLD] Server (show other bugs)
Hardware: All Linux
: Normal normal (vote)
Assignee: Gentoo Linux MySQL bugs team
URL:
Whiteboard:
Keywords:
Depends on:
Blocks:
 
Reported: 2015-09-21 13:20 UTC by Thomas Deutschmann
Modified: 2016-06-02 20:28 UTC (History)
0 users

See Also:
Package list:
Runtime testing required: ---


Attachments

Note You need to log in before you can comment on or make changes to this bug.
Description Thomas Deutschmann gentoo-dev Security 2015-09-21 13:20:59 UTC
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
Comment 1 Thomas Deutschmann gentoo-dev Security 2015-09-23 12:07:48 UTC
I posted this upstream because I was able to reproduce with vanilla percona-server.
Comment 2 Thomas Deutschmann gentoo-dev Security 2015-09-29 12:30:17 UTC
I am posting here because Launchpad seems to import comments (the Gentoo bug is linked to the Launchpad bug report) so we'll have it in both trackers:

Upstream (on behalf of Laurynas Biveinis) posted a patch (https://github.com/laurynas-biveinis/percona-server/commit/dbce5572d927ae679a03b591c1d94da706e8751d) which fixed the problem for me. Test suite passed.

Thanks!
Comment 3 Thomas Deutschmann gentoo-dev Security 2016-06-02 20:28:00 UTC
This appeared in v5.6.27-75.0.