[MDEV-9355] parts.partition_debug_innodb fails in buildbot on p8-rhel6-bintar-debug Created: 2016-01-04  Updated: 2016-02-16  Resolved: 2016-02-16

Status: Closed
Project: MariaDB Server
Component/s: Storage Engine - InnoDB, Storage Engine - XtraDB, Tests
Affects Version/s: 10.0, 10.1
Fix Version/s: 10.0.24

Type: Bug Priority: Major
Reporter: Elena Stepanova Assignee: Jan Lindström (Inactive)
Resolution: Fixed Votes: 0
Labels: None

Issue Links:
Blocks
blocks MDEV-7069 Fix buildbot failures in main server ... Stalled
Sprint: 10.0.24

 Description   

The test fails sporadically.

http://buildbot.askmonty.org/buildbot/builders/p8-rhel6-bintar-debug/builds/1221/steps/test/logs/stdio

parts.partition_debug_innodb 'xtradb'    w1 [ fail ]
 
        Test ended at 2016-01-03 07:22:08
 
 
 
CURRENT_TEST: parts.partition_debug_innodb
 
mysqltest: In included file "./include/wait_until_connected_again.inc": 
included from ./suite/parts/inc/partition_crash.inc at line 22:
 
included from ./suite/parts/inc/partition_crash_t2.inc at line 9:
 
included from ./suite/parts/inc/partition_crash_exchange.inc at line 10:
 
included from /home/buildbot/maria-slave/power8-vlp01-bintar-debug/build/mysql-test/suite/parts/t/partition_debug_innodb.test at line 90:
 
At line 26: Server failed to restart
 
 
 
The result from queries just before the failure was:
 
< snip >
 
11	Original from partition p1
 
12	Original from partition p1
 
13	Original from partition p1
 
14	Original from partition p1
 
2	Original from partition p0
 
21	Original from partition p1
 
22	Original from partition p1
 
23	Original from partition p1
 
24	Original from partition p1
 
3	Original from partition p0
 
4	Original from partition p0
 
ALTER TABLE t1 EXCHANGE PARTITION p0 WITH TABLE t2;
 
ERROR HY000: Lost connection to MySQL server during query
 
# State after crash (before recovery)
 
t1#P#p0.ibd
 
t1#P#p1.ibd
 
t1.frm
 
t1.par
 
t2.frm
 
t2.ibd

Server log: http://buildbot.askmonty.org/buildbot/builders/p8-rhel6-bintar-debug/builds/1221/steps/test/logs/mysqld.1.err.1

From the log, it looks like at some point recovery just stopped:

...
 
160103  7:13:46 [Note] /home/buildbot/maria-slave/power8-vlp01-bintar-debug/build/sql/mysqld: ready for connections.
 
Version: '10.0.23-MariaDB-debug-log'  socket: '/home/buildbot/maria-slave/power8-vlp01-bintar-debug/build/mysql-test/var/tmp/1/mysqld.1.sock'  port: 16040  Source distribution
 
SIGKILL myself
 
160103  7:13:46 [Note] /home/buildbot/maria-slave/power8-vlp01-bintar-debug/build/sql/mysqld (mysqld 10.0.23-MariaDB-debug-log) starting as process 4219 ...
 
160103  7:13:46 [Note] InnoDB: Using mutexes to ref count buffer pool pages
 
2016-01-03 07:13:46 fff95416ff0 InnoDB: !!!!!!!! UNIV_DEBUG switched on !!!!!!!!!
 
2016-01-03 07:13:46 fff95416ff0 InnoDB: !!!!!!!! UNIV_SYNC_DEBUG switched on !!!!!!!!!
 
160103  7:13:46 [Note] InnoDB: The InnoDB memory heap is disabled
 
160103  7:13:46 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
 
160103  7:13:46 [Note] InnoDB: GCC builtin __atomic_thread_fence() is used for memory barrier
 
160103  7:13:46 [Note] InnoDB: Compressed tables use zlib 1.2.6
 
160103  7:13:46 [Note] InnoDB: Using Linux native AIO
 
160103  7:13:46 [Note] InnoDB: Not using CPU crc32 instructions
 
160103  7:13:46 [Note] InnoDB: Initializing buffer pool, size = 8.0M
 
160103  7:13:46 [Note] InnoDB: Completed initialization of buffer pool
 
160103  7:13:46 [Note] InnoDB: Highest supported file format is Barracuda.
 
160103  7:13:46 [Note] InnoDB: Log scan progressed past the checkpoint lsn 1629973
 
160103  7:13:46 [Note] InnoDB: Database was not shutdown normally!
 
160103  7:13:46 [Note] InnoDB: Starting crash recovery.
 
160103  7:13:46 [Note] InnoDB: Reading tablespace information from the .ibd files...
 
160103  7:13:46 [Note] InnoDB: Restoring possible half-written data pages 
160103  7:13:46 [Note] InnoDB: from the doublewrite buffer...
 
InnoDB: Doing recovery: scanned up to log sequence number 2993928
 
160103  7:13:47 [Note] InnoDB: Starting an apply batch of log records to the database...
 
InnoDB: Progress in percent: 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 57 58 59 60 61 62 63 64 65 66 67 68 69 70 71 72 73 74 75 76 77 78 79 80 81 82 83 84 85 86 87 88 89 90 91 92 93 94 95 96 97 98 99 
InnoDB: Apply batch completed
 
CURRENT_TEST: parts.partition_repair_myisam
 
160103  7:22:09 [Note] /home/buildbot/maria-slave/power8-vlp01-bintar-debug/build/sql/mysqld (mysqld 10.0.23-MariaDB-debug-log) starting as process 16838 ...
 
...



 Comments   
Comment by Jan Lindström (Inactive) [ 2016-02-16 ]

Repeated on Linux (my laptop) with ./mysql-test-run --vardir=/dev/shm parts.partition_debug_innodb,xtradb --repeat=20 , but reason could be too small buffer pool setting.

2016-02-16 09:08:42 7f04ff0a1740  InnoDB: Warning: difficult to find free blocks in
 
InnoDB: the buffer pool (5002 search iterations)!
 
InnoDB: 5002 failed attempts to flush a page! Consider
 
InnoDB: increasing the buffer pool size.
 
InnoDB: It is also possible that in your Unix version
 
InnoDB: fsync is very slow, or completely frozen inside
 
InnoDB: the OS kernel. Then upgrading to a newer version
 
InnoDB: of your operating system may help. Look at the
 
InnoDB: number of fsyncs in diagnostic info below.
 
InnoDB: Pending flushes (fsync) log: 0; buffer pool: 0
 
InnoDB: 666 OS file reads, 72 OS file writes, 72 OS fsyncs
 
InnoDB: Starting InnoDB Monitor to print further
 
InnoDB: diagnostics to the standard output.

Comment by Jan Lindström (Inactive) [ 2016-02-16 ]

commit ab9b6650c3034d3680693db7c064662fa9aec229
Author: Jan Lindström <jan.lindstrom@mariadb.com>
Date: Tue Feb 16 10:49:13 2016 +0200

MDEV-9355: parts.partition_debug_innodb fails in buildbot on p8-rhel6-bintar-debug

At least on Linux test fails because too small buffer pool.

Generated at Thu Feb 08 07:34:02 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.