Details
-
Bug
-
Status: Closed (View Workflow)
-
Critical
-
Resolution: Fixed
-
10.1(EOL), 10.2(EOL)
-
None
Description
encryption.innodb_encryption-page-compression 'xtradb' w2 [ fail ] Found warnings/errors in server log file!
|
Test ended at 2016-11-29 16:32:56
|
line
|
2016-11-29 16:32:56 2495609664 [Warning] InnoDB: Trying to access missing tablespace 6
|
^ Found warnings in /usr/local/mariadb-10.2.3-linux-i686/mysql-test/var/2/log/mysqld.1.err
|
ok
|
|
|
- saving '/usr/local/mariadb-10.2.3-linux-i686/mysql-test/var/2/log/encryption.innodb_encryption-page-compression-xtradb/' to '/usr/local/mariadb-10.2.3-linux-i686/mysql-test/var/log/encryption.innodb_encryption-page-compression-xtradb/'
|
|
|
Retrying test encryption.innodb_encryption-page-compression, attempt(2/3)...
|
Attachments
Issue Links
- is part of
-
-
- Closed
-
- relates to
-
-
- Closed
-
-
MDEV-7069 Fix buildbot failures in main server trees
-
- Closed
-
Activity
| Component/s | Storage Engine - InnoDB [ 10129 ] |
| Assignee | Marko Mäkelä [ marko ] | Jan Lindström [ jplindst ] |
One more thought: If the DROP TABLE statements somehow (I do not see how) end up in the InnoDB background DROP TABLE queue, it is possible that the DROP TABLE statements get executed on the next server startup while some code (which code? buf0rea.cc?) is trying to access the tablespaces.
I should study the encryption code to see if there are any background operations that could explain this.
The test still crashes on Power, I don't know if it's the same or a different problem:
http://buildbot.askmonty.org/buildbot/builders/p8-rhel7-bintar-debug/builds/1927/steps/test/logs/stdio
encryption.innodb_encryption-page-compression 'xtradb' w4 [ fail ]
|
Test ended at 2016-12-10 19:07:35
|
|
|
CURRENT_TEST: encryption.innodb_encryption-page-compression
|
|
|
|
|
Server [mysqld.1 - pid: 11628, winpid: 11628, exit: 256] failed during test run
|
Server log from this test:
|
----------SERVER LOG START-----------
|
2016-12-10 19:06:39 70367258122384 [Note] /home/buildbot/maria-slave/power8-vlp03-bintar-debug/build/sql/mysqld (mysqld 10.2.3-MariaDB-debug-log) starting as process 11240 ...
|
2016-12-10 19:06:39 70367258122384 [Warning] Could not increase number of max_open_files to more than 1024 (request: 4162)
|
2016-12-10 19:06:39 70367258122384 [Note] Plugin 'SEQUENCE' is disabled.
|
2016-12-10 19:06:39 70367258122384 [Note] Plugin 'partition' is disabled.
|
2016-12-10 19:06:39 70367258122384 [Note] InnoDB: PUNCH HOLE support available
|
2016-12-10 19:06:39 70367258122384 [Note] InnoDB: !!!!!!!! UNIV_DEBUG switched on !!!!!!!!!
|
2016-12-10 19:06:39 70367258122384 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
|
2016-12-10 19:06:39 70367258122384 [Note] InnoDB: Uses event mutexes
|
2016-12-10 19:06:39 70367258122384 [Note] InnoDB: Compressed tables use zlib 1.2.8
|
2016-12-10 19:06:39 70367258122384 [Note] InnoDB: Using Linux native AIO
|
2016-12-10 19:06:39 70367258122384 [Note] InnoDB: Number of pools: 1
|
2016-12-10 19:06:39 70367258122384 [Note] InnoDB: Using generic crc32 instructions
|
2016-12-10 19:06:39 70367258122384 [Note] InnoDB: Initializing buffer pool, total size = 8M, instances = 1, chunk size = 8M
|
2016-12-10 19:06:39 70367258122384 [Note] InnoDB: Completed initialization of buffer pool
|
2016-12-10 19:06:39 70366823182656 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().
|
2016-12-10 19:06:39 70367258122384 [Note] InnoDB: Tablespace ID 0 name innodb_system:Default tablespace encryption mode scheme unencrypted
|
2016-12-10 19:06:39 70367258122384 [Note] InnoDB: Highest supported file format is Barracuda.
|
2016-12-10 19:06:40 70367258122384 [Note] InnoDB: Creating shared tablespace for temporary tables
|
2016-12-10 19:06:40 70367258122384 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
|
2016-12-10 19:06:40 70367258122384 [Note] InnoDB: File './ibtmp1' size is now 12 MB.
|
2016-12-10 19:06:40 70367258122384 [Note] InnoDB: Tablespace ID 5 name innodb_temporary:Default tablespace encryption mode scheme encrypted
|
2016-12-10 19:06:40 70367258122384 [Note] InnoDB: 96 redo rollback segment(s) found. 96 redo rollback segment(s) are active.
|
2016-12-10 19:06:40 70367258122384 [Note] InnoDB: 32 non-redo rollback segment(s) are active.
|
2016-12-10 19:06:40 70367258122384 [Note] InnoDB: Waiting for purge to start
|
2016-12-10 19:06:40 70367258122384 [Note] InnoDB: 5.7.14 started; log sequence number 1238508
|
2016-12-10 19:06:40 70367258122384 [Note] InnoDB: Creating 1 encryption thread id 70366709936448 total threads 4.
|
2016-12-10 19:06:40 70367258122384 [Note] InnoDB: Creating 2 encryption thread id 70366701547840 total threads 4.
|
2016-12-10 19:06:40 70367258122384 [Note] InnoDB: Creating 3 encryption thread id 70366693159232 total threads 4.
|
2016-12-10 19:06:40 70367258122384 [Note] InnoDB: Creating 4 encryption thread id 70366684770624 total threads 4.
|
2016-12-10 19:06:41 70366667993408 [Note] InnoDB: Loading buffer pool(s) from /home/buildbot/maria-slave/power8-vlp03-bintar-debug/build/mysql-test/var/4/mysqld.1/data/ib_buffer_pool
|
2016-12-10 19:06:41 70366667993408 [Note] InnoDB: Buffer pool(s) load completed at 161210 19:06:41
|
2016-12-10 19:06:41 70367258122384 [Note] Plugin 'INNODB_SYS_DATAFILES' is disabled.
|
2016-12-10 19:06:41 70367258122384 [Note] Plugin 'INNODB_SYS_TABLESTATS' is disabled.
|
2016-12-10 19:06:41 70367258122384 [Note] Plugin 'INNODB_TABLESPACES_SCRUBBING' is disabled.
|
2016-12-10 19:06:41 70367258122384 [Note] Plugin 'INNODB_CMPMEM_RESET' is disabled.
|
2016-12-10 19:06:41 70367258122384 [Note] Plugin 'INNODB_CMP' is disabled.
|
2016-12-10 19:06:41 70367258122384 [Note] Plugin 'INNODB_FT_DELETED' is disabled.
|
2016-12-10 19:06:41 70367258122384 [Note] Plugin 'INNODB_CMP_RESET' is disabled.
|
2016-12-10 19:06:41 70367258122384 [Note] Plugin 'INNODB_LOCK_WAITS' is disabled.
|
2016-12-10 19:06:41 70367258122384 [Note] Plugin 'INNODB_SYS_FIELDS' is disabled.
|
2016-12-10 19:06:41 70367258122384 [Note] Plugin 'FEEDBACK' is disabled.
|
2016-12-10 19:06:41 70367258122384 [Note] Plugin 'INNODB_FT_BEING_DELETED' is disabled.
|
2016-12-10 19:06:41 70367258122384 [Note] Plugin 'INNODB_FT_INDEX_TABLE' is disabled.
|
2016-12-10 19:06:41 70367258122384 [Note] Plugin 'INNODB_TEMP_TABLE_INFO' is disabled.
|
2016-12-10 19:06:41 70367258122384 [Note] Plugin 'INNODB_MUTEXES' is disabled.
|
2016-12-10 19:06:41 70367258122384 [Note] Plugin 'INNODB_FT_INDEX_CACHE' is disabled.
|
2016-12-10 19:06:41 70367258122384 [Note] Plugin 'INNODB_FT_DEFAULT_STOPWORD' is disabled.
|
2016-12-10 19:06:41 70367258122384 [Note] Plugin 'INNODB_SYS_COLUMNS' is disabled.
|
2016-12-10 19:06:41 70367258122384 [Note] Plugin 'INNODB_FT_CONFIG' is disabled.
|
2016-12-10 19:06:41 70367258122384 [Note] Plugin 'INNODB_SYS_INDEXES' is disabled.
|
2016-12-10 19:06:41 70367258122384 [Note] Plugin 'INNODB_SYS_TABLESPACES' is disabled.
|
2016-12-10 19:06:41 70367258122384 [Note] Plugin 'INNODB_CMP_PER_INDEX_RESET' is disabled.
|
2016-12-10 19:06:41 70367258122384 [Note] Plugin 'INNODB_SYS_VIRTUAL' is disabled.
|
2016-12-10 19:06:41 70367258122384 [Note] Plugin 'INNODB_SYS_SEMAPHORE_WAITS' is disabled.
|
2016-12-10 19:06:41 70367258122384 [Warning] /home/buildbot/maria-slave/power8-vlp03-bintar-debug/build/sql/mysqld: unknown option '--loose-pam-debug'
|
2016-12-10 19:06:41 70367258122384 [Note] Server socket created on IP: '127.0.0.1'.
|
2016-12-10 19:06:41 70367258122384 [Note] /home/buildbot/maria-slave/power8-vlp03-bintar-debug/build/sql/mysqld: ready for connections.
|
Version: '10.2.3-MariaDB-debug-log' socket: '/home/buildbot/maria-slave/power8-vlp03-bintar-debug/build/mysql-test/var/tmp/4/mysqld.1.sock' port: 16000 Source distribution
|
2016-12-10 19:06:42 70366976965952 [Note] InnoDB: Tablespace ID 6 name test/innodb_normal:Default tablespace encryption mode scheme encrypted
|
2016-12-10 19:06:42 70366976965952 [Note] InnoDB: Tablespace ID 7 name test/innodb_page_compressed1:Default tablespace encryption mode scheme encrypted
|
2016-12-10 19:06:42 70366976965952 [Note] InnoDB: Tablespace ID 8 name test/innodb_page_compressed2:Default tablespace encryption mode scheme encrypted
|
2016-12-10 19:06:42 70366976965952 [Note] InnoDB: Tablespace ID 9 name test/innodb_page_compressed3:Default tablespace encryption mode scheme encrypted
|
2016-12-10 19:06:42 70366976965952 [Note] InnoDB: Tablespace ID 10 name test/innodb_page_compressed4:Default tablespace encryption mode scheme encrypted
|
2016-12-10 19:06:42 70366976965952 [Note] InnoDB: Tablespace ID 11 name test/innodb_page_compressed5:Default tablespace encryption mode scheme encrypted
|
2016-12-10 19:06:42 70366976965952 [Note] InnoDB: Tablespace ID 12 name test/innodb_page_compressed6:Default tablespace encryption mode scheme encrypted
|
2016-12-10 19:06:42 70366976965952 [Note] InnoDB: Tablespace ID 13 name test/innodb_page_compressed7:Default tablespace encryption mode scheme encrypted
|
2016-12-10 19:06:42 70366976965952 [Note] InnoDB: Tablespace ID 14 name test/innodb_page_compressed8:Default tablespace encryption mode scheme encrypted
|
2016-12-10 19:06:43 70366976965952 [Note] InnoDB: Tablespace ID 15 name test/innodb_page_compressed9:Default tablespace encryption mode scheme encrypted
|
2016-12-10 19:07:29 70366976572736 [Note] /home/buildbot/maria-slave/power8-vlp03-bintar-debug/build/sql/mysqld (root[root] @ localhost []): Normal shutdown
|
|
|
2016-12-10 19:07:29 70366976572736 [Note] Event Scheduler: Purging the queue. 0 events
|
2016-12-10 19:07:29 70366651216192 [Note] InnoDB: FTS optimize thread exiting.
|
2016-12-10 19:07:29 70366976572736 [Note] InnoDB: Starting shutdown...
|
2016-12-10 19:07:29 70366667993408 [Note] InnoDB: Dumping buffer pool(s) to /home/buildbot/maria-slave/power8-vlp03-bintar-debug/build/mysql-test/var/4/mysqld.1/data/ib_buffer_pool
|
2016-12-10 19:07:29 70366667993408 [Note] InnoDB: Buffer pool(s) dump completed at 161210 19:07:29
|
2016-12-10 19:07:30 70366976572736 [Note] InnoDB: Shutdown completed; log sequence number 5368640
|
2016-12-10 19:07:30 70366976572736 [Note] InnoDB: Removed temporary tablespace data file: "ibtmp1"
|
2016-12-10 19:07:30 70366976572736 [Note] Debug sync points hit: 757836
|
2016-12-10 19:07:30 70366976572736 [Note] Debug sync points executed: 0
|
2016-12-10 19:07:30 70366976572736 [Note] Debug sync points max active per thread: 0
|
2016-12-10 19:07:30 70366976572736 [Note] /home/buildbot/maria-slave/power8-vlp03-bintar-debug/build/sql/mysqld: Shutdown complete
|
|
|
2016-12-10 19:07:32 70366508587152 [Note] /home/buildbot/maria-slave/power8-vlp03-bintar-debug/build/sql/mysqld (mysqld 10.2.3-MariaDB-debug-log) starting as process 11630 ...
|
2016-12-10 19:07:32 70366508587152 [Warning] Could not increase number of max_open_files to more than 1024 (request: 4162)
|
2016-12-10 19:07:32 70366508587152 [Note] Plugin 'SEQUENCE' is disabled.
|
2016-12-10 19:07:32 70366508587152 [Note] Plugin 'partition' is disabled.
|
2016-12-10 19:07:32 70366508587152 [Note] InnoDB: PUNCH HOLE support available
|
2016-12-10 19:07:32 70366508587152 [Note] InnoDB: !!!!!!!! UNIV_DEBUG switched on !!!!!!!!!
|
2016-12-10 19:07:32 70366508587152 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
|
2016-12-10 19:07:32 70366508587152 [Note] InnoDB: Uses event mutexes
|
2016-12-10 19:07:32 70366508587152 [Note] InnoDB: Compressed tables use zlib 1.2.8
|
2016-12-10 19:07:32 70366508587152 [Note] InnoDB: Using Linux native AIO
|
2016-12-10 19:07:32 70366508587152 [Note] InnoDB: Number of pools: 1
|
2016-12-10 19:07:32 70366508587152 [Note] InnoDB: Using generic crc32 instructions
|
2016-12-10 19:07:32 70366508587152 [Note] InnoDB: Initializing buffer pool, total size = 8M, instances = 1, chunk size = 8M
|
2016-12-10 19:07:32 70366508587152 [Note] InnoDB: Completed initialization of buffer pool
|
2016-12-10 19:07:32 70366076596544 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().
|
2016-12-10 19:07:32 70366508587152 [Note] InnoDB: Tablespace ID 0 name innodb_system:Default tablespace encryption mode scheme encrypted
|
2016-12-10 19:07:32 70366508587152 [Note] InnoDB: Highest supported file format is Barracuda.
|
2016-12-10 19:07:33 70366508587152 [Note] InnoDB: Tablespace ID 3 name mysql/innodb_index_stats:Default tablespace encryption mode scheme encrypted
|
2016-12-10 19:07:33 70366508587152 [Note] InnoDB: Tablespace ID 2 name mysql/innodb_table_stats:Default tablespace encryption mode scheme encrypted
|
2016-12-10 19:07:33 70366508587152 [Note] InnoDB: Tablespace ID 6 name test/innodb_normal:Default tablespace encryption mode scheme encrypted
|
2016-12-10 19:07:33 70366508587152 [Note] InnoDB: Tablespace ID 7 name test/innodb_page_compressed1:Default tablespace encryption mode scheme encrypted
|
2016-12-10 19:07:33 70366508587152 [Note] InnoDB: Tablespace ID 8 name test/innodb_page_compressed2:Default tablespace encryption mode scheme encrypted
|
2016-12-10 19:07:33 70366508587152 [Note] InnoDB: Tablespace ID 9 name test/innodb_page_compressed3:Default tablespace encryption mode scheme encrypted
|
2016-12-10 19:07:33 70366508587152 [Note] InnoDB: Tablespace ID 10 name test/innodb_page_compressed4:Default tablespace encryption mode scheme encrypted
|
2016-12-10 19:07:33 70366508587152 [Note] InnoDB: Tablespace ID 11 name test/innodb_page_compressed5:Default tablespace encryption mode scheme encrypted
|
2016-12-10 19:07:33 70366508587152 [Note] InnoDB: Tablespace ID 12 name test/innodb_page_compressed6:Default tablespace encryption mode scheme encrypted
|
2016-12-10 19:07:33 70366508587152 [Note] InnoDB: Tablespace ID 13 name test/innodb_page_compressed7:Default tablespace encryption mode scheme encrypted
|
2016-12-10 19:07:33 70366508587152 [Note] InnoDB: Tablespace ID 14 name test/innodb_page_compressed8:Default tablespace encryption mode scheme encrypted
|
2016-12-10 19:07:33 70366508587152 [Note] InnoDB: Tablespace ID 15 name test/innodb_page_compressed9:Default tablespace encryption mode scheme encrypted
|
2016-12-10 19:07:33 70366508587152 [Note] InnoDB: Creating shared tablespace for temporary tables
|
2016-12-10 19:07:33 70366508587152 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
|
2016-12-10 19:07:33 70366508587152 [Note] InnoDB: File './ibtmp1' size is now 12 MB.
|
2016-12-10 19:07:33 70366508587152 [Note] InnoDB: Tablespace ID 16 name innodb_temporary:Default tablespace encryption mode scheme encrypted
|
2016-12-10 19:07:33 70366508587152 [Note] InnoDB: 96 redo rollback segment(s) found. 96 redo rollback segment(s) are active.
|
2016-12-10 19:07:33 70366508587152 [Note] InnoDB: 32 non-redo rollback segment(s) are active.
|
2016-12-10 19:07:33 70366508587152 [Note] InnoDB: Waiting for purge to start
|
161210 19:07:33 [ERROR] mysqld got signal 11 ;
|
This could be because you hit a bug. It is also possible that this binary
|
or one of the libraries it was linked against is corrupt, improperly built,
|
or misconfigured. This error can also be caused by malfunctioning hardware.
|
|
|
To report this bug, see https://mariadb.com/kb/en/reporting-bugs
|
|
|
We will try our best to scrape up some info that will hopefully help
|
diagnose the problem, but since we have already crashed,
|
something is definitely wrong and this may fail.
|
|
|
Server version: 10.2.3-MariaDB-debug-log
|
key_buffer_size=1048576
|
read_buffer_size=131072
|
max_used_connections=0
|
max_threads=153
|
thread_count=0
|
It is possible that mysqld could use up to
|
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 63061 K bytes of memory
|
Hope that's ok; if not, decrease some variables in the equation.
|
|
|
Thread pointer: 0x0x0
|
Attempting backtrace. You can use the following information to find out
|
where mysqld died. If you see no messages after this, something went
|
terribly wrong...
|
stack_bottom = 0x0 thread_stack 0x48c00
|
2016-12-10 19:07:33 70366508587152 [Note] InnoDB: 5.7.14 started; log sequence number 5368640
|
2016-12-10 19:07:33 70366508587152 [Note] InnoDB: Creating 1 encryption thread id 70365963350336 total threads 4.
|
2016-12-10 19:07:33 70366508587152 [Note] InnoDB: Creating 2 encryption thread id 70365954961728 total threads 4.
|
2016-12-10 19:07:33 70366508587152 [Note] InnoDB: Creating 3 encryption thread id 70365946573120 total threads 4.
|
2016-12-10 19:07:33 70366508587152 [Note] InnoDB: Creating 4 encryption thread id 70365938184512 total threads 4.
|
/home/buildbot/maria-slave/power8-vlp03-bintar-debug/build/sql/mysqld(my_print_stacktrace-0xab1b04)[0x35568f1c]
|
/home/buildbot/maria-slave/power8-vlp03-bintar-debug/build/sql/mysqld(handle_fatal_signal-0x14b3d98)[0x34aa9100]
|
linux-vdso64.so.1(__kernel_sigtramp_rt64+0x0)[0x3fff7ab80478]
|
/home/buildbot/maria-slave/power8-vlp03-bintar-debug/build/sql/mysqld(+0xee158c)[0x34e4158c]
|
[0x0]
|
/home/buildbot/maria-slave/power8-vlp03-bintar-debug/build/sql/mysqld(+0xf66130)[0x34ec6130]
|
/home/buildbot/maria-slave/power8-vlp03-bintar-debug/build/sql/mysqld(+0xf65dc8)[0x34ec5dc8]
|
/home/buildbot/maria-slave/power8-vlp03-bintar-debug/build/sql/mysqld(+0x12bed98)[0x3521ed98]
|
/home/buildbot/maria-slave/power8-vlp03-bintar-debug/build/sql/mysqld(+0x12c024c)[0x3522024c]
|
/home/buildbot/maria-slave/power8-vlp03-bintar-debug/build/sql/mysqld(+0x12c08b8)[0x352208b8]
|
/home/buildbot/maria-slave/power8-vlp03-bintar-debug/build/sql/mysqld(+0x11f07cc)[0x351507cc]
|
/home/buildbot/maria-slave/power8-vlp03-bintar-debug/build/sql/mysqld(+0x12057e0)[0x351657e0]
|
/home/buildbot/maria-slave/power8-vlp03-bintar-debug/build/sql/mysqld(+0x12061f0)[0x351661f0]
|
/home/buildbot/maria-slave/power8-vlp03-bintar-debug/build/sql/mysqld(+0x1206e90)[0x35166e90]
|
/home/buildbot/maria-slave/power8-vlp03-bintar-debug/build/sql/mysqld(+0x1207328)[0x35167328]
|
/home/buildbot/maria-slave/power8-vlp03-bintar-debug/build/sql/mysqld(+0x12080e4)[0x351680e4]
|
/home/buildbot/maria-slave/power8-vlp03-bintar-debug/build/sql/mysqld(+0x12086fc)[0x351686fc]
|
/home/buildbot/maria-slave/power8-vlp03-bintar-debug/build/sql/mysqld(+0x12090bc)[0x351690bc]
|
/home/buildbot/maria-slave/power8-vlp03-bintar-debug/build/sql/mysqld(+0x1209484)[0x35169484]
|
/home/buildbot/maria-slave/power8-vlp03-bintar-debug/build/sql/mysqld(+0x120deac)[0x3516deac]
|
/opt/at8.0/lib64/power8/libpthread.so.0(+0xb9e0)[0x3fff7ab4b9e0]
|
/opt/at8.0/lib64/power8/libc.so.6(clone-0xaa8e8)[0x3fff7a2e18d0]
|
The manual page at http://dev.mysql.com/doc/mysql/en/crashing.html contains
|
information that should help you find out what is causing the crash.
|
Writing a core file
|
----------SERVER LOG END-------------
|
mysqltest failed but provided no output
|
The result from queries just before the failure was:
|
< snip >
|
count(*)
|
5000
|
select count(*) from innodb_page_compressed8 where c1 < 500000;
|
count(*)
|
5000
|
select count(*) from innodb_page_compressed9 where c1 < 500000;
|
count(*)
|
5000
|
SELECT variable_value >= 0 FROM information_schema.global_status WHERE variable_name = 'innodb_num_pages_encrypted';
|
variable_value >= 0
|
1
|
SELECT variable_value >= 0 FROM information_schema.global_status WHERE variable_name = 'innodb_num_pages_decrypted';
|
variable_value >= 0
|
1
|
SELECT variable_value >= 0 FROM information_schema.global_status WHERE variable_name = 'innodb_num_pages_page_compressed';
|
variable_value >= 0
|
1
|
SELECT variable_value >= 0 FROM information_schema.global_status WHERE variable_name = 'innodb_num_pages_page_decompressed';
|
variable_value >= 0
|
1
|
|
|
|
|
|
|
- saving '/home/buildbot/maria-slave/power8-vlp03-bintar-debug/build/mysql-test/var/4/log/encryption.innodb_encryption-page-compression-xtradb/' to '/home/buildbot/maria-slave/power8-vlp03-bintar-debug/build/mysql-test/var/log/encryption.innodb_encryption-page-compression-xtradb/'
|
- found 'core.11630' (0/5)
|
|
|
Trying 'dbx' to get a backtrace
|
|
|
Trying 'gdb' to get a backtrace
|
Core generated by '/home/buildbot/maria-slave/power8-vlp03-bintar-debug/build/sql/mysqld'
|
Output from gdb follows. The first stack trace is from the failing thread.
|
The following stack traces are from all threads (so the failing one is
|
duplicated).
|
--------------------------
|
[New LWP 11648]
|
[New LWP 11667]
|
[New LWP 11670]
|
[New LWP 11674]
|
[New LWP 11630]
|
[New LWP 11640]
|
[New LWP 11645]
|
[New LWP 11668]
|
[New LWP 11671]
|
[New LWP 11672]
|
[New LWP 11680]
|
[New LWP 11643]
|
[New LWP 11647]
|
[New LWP 11669]
|
[New LWP 11673]
|
[New LWP 11678]
|
[New LWP 11646]
|
[New LWP 11642]
|
[New LWP 11644]
|
[New LWP 11679]
|
[New LWP 11681]
|
|
|
warning: Could not load shared library symbols for linux-vdso64.so.1.
|
Do you need "set solib-search-path" or "set sysroot"?
|
|
|
warning: File "/opt/at8.0/lib64/power8/libthread_db-1.0.so" auto-loading has been declined by your `auto-load safe-path' set to "$debugdir:$datadir/auto-load:/usr/bin/mono-gdb.py".
|
To enable execution of this file add
|
add-auto-load-safe-path /opt/at8.0/lib64/power8/libthread_db-1.0.so
|
line to your configuration file "/home/buildbot/.gdbinit".
|
To completely disable this security protection add
|
set auto-load safe-path /
|
line to your configuration file "/home/buildbot/.gdbinit".
|
For more information about this security protection see the
|
"Auto-loading safe path" section in the GDB manual. E.g., run from the shell:
|
info "(gdb)Auto-loading safe path"
|
|
|
warning: Unable to find libthread_db matching inferior's thread library, thread debugging will not be available.
|
|
|
warning: File "/opt/at8.0/lib64/power8/libthread_db-1.0.so" auto-loading has been declined by your `auto-load safe-path' set to "$debugdir:$datadir/auto-load:/usr/bin/mono-gdb.py".
|
Program terminated with signal 11, Segmentation fault.
|
#0 0x00003fff7ab54f00 in __pthread_kill (threadid=<optimized out>, signo=<optimized out>) at ../sysdeps/unix/sysv/linux/pthread_kill.c:60
|
60 ../sysdeps/unix/sysv/linux/pthread_kill.c: No such file or directory.
|
#0 0x00003fff7ab54f00 in __pthread_kill (threadid=<optimized out>, signo=<optimized out>) at ../sysdeps/unix/sysv/linux/pthread_kill.c:60
|
#1 0x00000000355690b4 in my_write_core (sig=11) at /home/buildbot/maria-slave/power8-vlp03-bintar-debug/build/mysys/stacktrace.c:477
|
#2 0x0000000034aa9670 in handle_fatal_signal (sig=11) at /home/buildbot/maria-slave/power8-vlp03-bintar-debug/build/sql/signal_handler.cc:294
|
#3 <signal handler called>
|
#4 0x0000000034e4158c in OSMutex::enter (this=0x10) at /home/buildbot/maria-slave/power8-vlp03-bintar-debug/build/storage/innobase/include/sync0types.h:475
|
#5 0x0000000034ec6130 in os_event::set (this=0x0) at /home/buildbot/maria-slave/power8-vlp03-bintar-debug/build/storage/innobase/os/os0event.cc:73
|
#6 0x0000000034ec5dc8 in os_event_set (event=0x0) at /home/buildbot/maria-slave/power8-vlp03-bintar-debug/build/storage/innobase/os/os0event.cc:484
|
#7 0x000000003521ed98 in fil_crypt_get_latest_key_version (crypt_data=0x3fff79a71d80) at /home/buildbot/maria-slave/power8-vlp03-bintar-debug/build/storage/innobase/fil/fil0crypt.cc:156
|
#8 0x000000003522024c in fil_encrypt_buf (crypt_data=0x3fff79a71d80, space=0, offset=7, lsn=5368659, src_frame=0x3fff647f4000 "\001A\224\314", page_size=..., dst_frame=0x3fff72920000 "z\206\344\365") at /home/buildbot/maria-slave/power8-vlp03-bintar-debug/build/storage/innobase/fil/fil0crypt.cc:543
|
#9 0x00000000352208b8 in fil_space_encrypt (space=0, offset=7, lsn=5368659, src_frame=0x3fff647f4000 "\001A\224\314", page_size=..., dst_frame=0x3fff72920000 "z\206\344\365") at /home/buildbot/maria-slave/power8-vlp03-bintar-debug/build/storage/innobase/fil/fil0crypt.cc:649
|
#10 0x00000000351507cc in buf_page_encrypt_before_write (bpage=0x3fff64780000, src_frame=0x3fff647f4000 "\001A\224\314", space_id=0) at /home/buildbot/maria-slave/power8-vlp03-bintar-debug/build/storage/innobase/buf/buf0buf.cc:7473
|
#11 0x00000000351657e0 in buf_flush_write_block_low (bpage=0x3fff64780000, flush_type=BUF_FLUSH_LIST, sync=false) at /home/buildbot/maria-slave/power8-vlp03-bintar-debug/build/storage/innobase/buf/buf0flu.cc:1082
|
#12 0x00000000351661f0 in buf_flush_page (buf_pool=0x3fff74791200, bpage=0x3fff64780000, flush_type=BUF_FLUSH_LIST, sync=false) at /home/buildbot/maria-slave/power8-vlp03-bintar-debug/build/storage/innobase/buf/buf0flu.cc:1241
|
#13 0x0000000035166e90 in buf_flush_try_neighbors (page_id=..., flush_type=BUF_FLUSH_LIST, n_flushed=1, n_to_flush=200) at /home/buildbot/maria-slave/power8-vlp03-bintar-debug/build/storage/innobase/buf/buf0flu.cc:1465
|
#14 0x0000000035167328 in buf_flush_page_and_try_neighbors (bpage=0x3fff64780000, flush_type=BUF_FLUSH_LIST, n_to_flush=200, count=0x3fff60ffe248) at /home/buildbot/maria-slave/power8-vlp03-bintar-debug/build/storage/innobase/buf/buf0flu.cc:1537
|
#15 0x00000000351680e4 in buf_do_flush_list_batch (buf_pool=0x3fff74791200, min_n=200, lsn_limit=18446744073709551615) at /home/buildbot/maria-slave/power8-vlp03-bintar-debug/build/storage/innobase/buf/buf0flu.cc:1797
|
#16 0x00000000351686fc in buf_flush_batch (buf_pool=0x3fff74791200, flush_type=BUF_FLUSH_LIST, min_n=200, lsn_limit=18446744073709551615, n=0x3fff60ffe458) at /home/buildbot/maria-slave/power8-vlp03-bintar-debug/build/storage/innobase/buf/buf0flu.cc:1875
|
#17 0x00000000351690bc in buf_flush_do_batch (buf_pool=0x3fff74791200, type=BUF_FLUSH_LIST, min_n=200, lsn_limit=18446744073709551615, n=0x3fff60ffe458) at /home/buildbot/maria-slave/power8-vlp03-bintar-debug/build/storage/innobase/buf/buf0flu.cc:2046
|
#18 0x0000000035169484 in buf_flush_lists (min_n=200, lsn_limit=18446744073709551615, n_processed=0x3fff60ffe510) at /home/buildbot/maria-slave/power8-vlp03-bintar-debug/build/storage/innobase/buf/buf0flu.cc:2156
|
#19 0x000000003516deac in buf_flush_page_cleaner_coordinator (arg=0x0) at /home/buildbot/maria-slave/power8-vlp03-bintar-debug/build/storage/innobase/buf/buf0flu.cc:3377
|
#20 0x00003fff7ab4b9e0 in start_thread (arg=0x3fff60fff140) at pthread_create.c:312
|
#21 0x00003fff7a2e18d0 in .__clone () at ../sysdeps/unix/sysv/linux/powerpc/powerpc64/clone.S:96
|
The test crashes a lot now, not only on Power, but on usual x86 platforms, also on 10.1. Sometimes with various symptoms from MDEV-9359, but not limited to it.
Revision 74a5638a1d5de35f5f377aaae6a5d5266e4d05a6 (mariadb/10.1) - same test on innodb plugin
x86_64, Ubuntu-16.04
cmake /source -DCMAKE_BUILD_TYPE=Debug -DBUILD_CONFIG=mysql_release -DWITH_PROTOBUF=system -DWITH_NDB_JAVA=NO -DCMAKE_C_COMPILER=gcc -DCMAKE_CXX_COMPILER=g++ '-DCMAKE_C_FLAGS_RELWITHDEBINFO=-m64 -O3 -g -mtune=native' '-DCMAKE_CXX_FLAGS_RELWITHDEBINFO=-m64 -O3 -g -mtune=native' '-DCMAKE_C_FLAGS=-m64 -O3 -g -mtune=native' '-DCMAKE_CXX_FLAGS=-m64 -O3 -g -mtune=native' -DWITH_SSL=system -DCMAKE_INSTALL_PREFIX=/mysql/mariadb-upstream-Debug-10.2 -DCMAKE_C_COMPILER_LAUNCHER=ccache -DCMAKE_CXX_COMPILER_LAUNCHER=ccache -DWITHOUT_FEDERATED_STORAGE_ENGINE=1 -DWITHOUT_FEDERATEDX_STORAGE_ENGINE=1 -DWITHOUT_TOKUDB_STORAGE_ENGINE=1
|
...
|
12:09:30 encryption.innodb_encryption-page-compression 'innodb_plugin' w20 [ fail ]
|
12:09:30 Test ended at 2017-02-16 01:09:30
|
12:09:30
|
12:09:30 CURRENT_TEST: encryption.innodb_encryption-page-compression
|
12:09:30 mysqltest: At line 155: query 'drop table innodb_page_compressed5' failed: 2013: Lost connection to MySQL server during query
|
12:09:30
|
12:09:30 The result from queries just before the failure was:
|
12:09:30 < snip >
|
12:09:30 update innodb_page_compressed9 set c1 = c1 + 1;
|
12:09:30 SELECT variable_value >= 0 FROM information_schema.global_status WHERE variable_name = 'innodb_num_pages_encrypted';
|
12:09:30 variable_value >= 0
|
12:09:30 1
|
12:09:30 SELECT variable_value >= 0 FROM information_schema.global_status WHERE variable_name = 'innodb_num_pages_decrypted';
|
12:09:30 variable_value >= 0
|
12:09:30 1
|
12:09:30 SELECT variable_value >= 0 FROM information_schema.global_status WHERE variable_name = 'innodb_num_pages_page_compressed';
|
12:09:30 variable_value >= 0
|
12:09:30 1
|
12:09:30 SELECT variable_value >= 0 FROM information_schema.global_status WHERE variable_name = 'innodb_num_pages_page_decompressed';
|
12:09:30 variable_value >= 0
|
12:09:30 1
|
12:09:30 drop procedure innodb_insert_proc;
|
12:09:30 drop table innodb_normal;
|
12:09:30 drop table innodb_page_compressed1;
|
12:09:30 drop table innodb_page_compressed2;
|
12:09:30 drop table innodb_page_compressed3;
|
12:09:30 drop table innodb_page_compressed4;
|
12:09:30 drop table innodb_page_compressed5;
|
12:09:30
|
12:09:30 More results from queries before failure can be found in /build/build/mysql-test/var/20/log/innodb_encryption-page-compression.log
|
12:09:30
|
12:09:30
|
12:09:30 Server [mysqld.1 - pid: 332, winpid: 332, exit: 256] failed during test run
|
12:09:30 Server log from this test:
|
12:09:30 ----------SERVER LOG START-----------
|
12:09:30 2017-02-16 1:09:21 140597154433280 [Note] /build/build/sql/mysqld (mysqld 10.1.22-MariaDB) starting as process 85997 ...
|
12:09:30 2017-02-16 1:09:21 140597154433280 [Warning] Could not increase number of max_open_files to more than 1024 (request: 4162)
|
12:09:30 2017-02-16 1:09:21 140597154433280 [Note] Plugin 'partition' is disabled.
|
12:09:30 2017-02-16 1:09:21 140597154433280 [Note] Plugin 'SEQUENCE' is disabled.
|
12:09:30 2017-02-16 1:09:22 140597154433280 [Note] InnoDB: Using mutexes to ref count buffer pool pages
|
12:09:30 2017-02-16 1:09:22 140597154433280 [Note] InnoDB: The InnoDB memory heap is disabled
|
12:09:30 2017-02-16 1:09:22 140597154433280 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
|
12:09:30 2017-02-16 1:09:22 140597154433280 [Note] InnoDB: GCC builtin __atomic_thread_fence() is used for memory barrier
|
12:09:30 2017-02-16 1:09:22 140597154433280 [Note] InnoDB: Compressed tables use zlib 1.2.3
|
12:09:30 2017-02-16 1:09:22 140597154433280 [Note] InnoDB: Using Linux native AIO
|
12:09:30 2017-02-16 1:09:22 140597154433280 [Note] InnoDB: Using SSE crc32 instructions
|
12:09:30 2017-02-16 01:09:22 7fdf53724900 InnoDB: Warning: io_setup() failed with EAGAIN. Will make 5 attempts before giving up.
|
12:09:30 InnoDB: Warning: io_setup() attempt 1 failed.
|
12:09:30 InnoDB: Warning: io_setup() attempt 2 failed.
|
12:09:30 InnoDB: Warning: io_setup() attempt 3 failed.
|
12:09:30 InnoDB: Warning: io_setup() attempt 4 failed.
|
12:09:30 InnoDB: Warning: io_setup() attempt 5 failed.
|
12:09:30 2017-02-16 01:09:24 7fdf53724900 InnoDB: Error: io_setup() failed with EAGAIN after 5 attempts.
|
12:09:30 InnoDB: You can disable Linux Native AIO by setting innodb_use_native_aio = 0 in my.cnf
|
12:09:30 2017-02-16 1:09:24 140597154433280 [Warning] InnoDB: Linux Native AIO disabled.
|
12:09:30 2017-02-16 1:09:24 140597154433280 [Note] InnoDB: Initializing buffer pool, size = 8.0M
|
12:09:30 2017-02-16 1:09:24 140597154433280 [Note] InnoDB: Completed initialization of buffer pool
|
12:09:30 2017-02-16 1:09:24 140597154433280 [Note] InnoDB: Highest supported file format is Barracuda.
|
12:09:30 2017-02-16 1:09:24 140597154433280 [Note] InnoDB: 128 rollback segment(s) are active.
|
12:09:30 2017-02-16 1:09:24 140597154433280 [Note] InnoDB: Waiting for purge to start
|
12:09:30 2017-02-16 1:09:24 140597154433280 [Note] InnoDB: 5.6.35 started; log sequence number 1629796
|
12:09:30 2017-02-16 1:09:24 140597154433280 [Note] InnoDB: Creating #1 thread id 140596794607360 total threads 4.
|
12:09:30 2017-02-16 1:09:24 140597154433280 [Note] InnoDB: Creating #2 thread id 140596786214656 total threads 4.
|
12:09:30 2017-02-16 1:09:24 140597154433280 [Note] InnoDB: Creating #3 thread id 140596769453824 total threads 4.
|
12:09:30 2017-02-16 1:09:24 140596819785472 [Note] InnoDB: Dumping buffer pool(s) not yet started
|
12:09:30 2017-02-16 1:09:24 140597154433280 [Note] InnoDB: Creating #4 thread id 140596752676608 total threads 4.
|
12:09:30 2017-02-16 1:09:24 140597154433280 [Note] Plugin 'INNODB_SYS_DATAFILES' is disabled.
|
12:09:30 2017-02-16 1:09:24 140597154433280 [Note] Plugin 'INNODB_SYS_TABLESTATS' is disabled.
|
12:09:30 2017-02-16 1:09:24 140597154433280 [Note] Plugin 'INNODB_CMP' is disabled.
|
12:09:30 2017-02-16 1:09:24 140597154433280 [Note] Plugin 'XTRADB_READ_VIEW' is disabled.
|
12:09:30 2017-02-16 1:09:24 140597154433280 [Note] Plugin 'XTRADB_RSEG' is disabled.
|
12:09:30 2017-02-16 1:09:24 140597154433280 [Note] Plugin 'INNODB_FT_DELETED' is disabled.
|
12:09:30 2017-02-16 1:09:24 140597154433280 [Note] Plugin 'INNODB_LOCK_WAITS' is disabled.
|
12:09:30 2017-02-16 1:09:24 140597154433280 [Note] Plugin 'CHANGED_PAGE_BITMAPS' is disabled.
|
12:09:30 2017-02-16 1:09:24 140597154433280 [Note] Plugin 'INNODB_SYS_FIELDS' is disabled.
|
12:09:30 2017-02-16 1:09:24 140597154433280 [Note] Plugin 'XTRADB_INTERNAL_HASH_TABLES' is disabled.
|
12:09:30 2017-02-16 1:09:24 140597154433280 [Note] Plugin 'INNODB_TABLESPACES_SCRUBBING' is disabled.
|
12:09:30 2017-02-16 1:09:24 140597154433280 [Note] Plugin 'INNODB_CMPMEM_RESET' is disabled.
|
12:09:30 2017-02-16 1:09:24 140597154433280 [Note] Plugin 'INNODB_FT_INDEX_TABLE' is disabled.
|
12:09:30 2017-02-16 1:09:24 140597154433280 [Note] Plugin 'INNODB_FT_BEING_DELETED' is disabled.
|
12:09:30 2017-02-16 1:09:24 140597154433280 [Note] Plugin 'INNODB_MUTEXES' is disabled.
|
12:09:30 2017-02-16 1:09:24 140597154433280 [Note] Plugin 'INNODB_FT_CONFIG' is disabled.
|
12:09:30 2017-02-16 1:09:24 140597154433280 [Note] Plugin 'FEEDBACK' is disabled.
|
12:09:30 2017-02-16 1:09:24 140597154433280 [Note] Plugin 'INNODB_FT_INDEX_CACHE' is disabled.
|
12:09:30 2017-02-16 1:09:24 140597154433280 [Note] Plugin 'INNODB_FT_DEFAULT_STOPWORD' is disabled.
|
12:09:30 2017-02-16 1:09:24 140597154433280 [Note] Plugin 'INNODB_CMP_RESET' is disabled.
|
12:09:30 2017-02-16 1:09:24 140597154433280 [Note] Plugin 'INNODB_SYS_COLUMNS' is disabled.
|
12:09:30 2017-02-16 1:09:24 140597154433280 [Note] Plugin 'INNODB_CMP_PER_INDEX_RESET' is disabled.
|
12:09:30 2017-02-16 1:09:24 140597154433280 [Note] Plugin 'INNODB_SYS_TABLESPACES' is disabled.
|
12:09:30 2017-02-16 1:09:24 140597154433280 [Note] Plugin 'INNODB_SYS_SEMAPHORE_WAITS' is disabled.
|
12:09:30 2017-02-16 1:09:24 140597154433280 [Note] Plugin 'INNODB_SYS_INDEXES' is disabled.
|
12:09:30 2017-02-16 1:09:24 140597154433280 [Warning] /build/build/sql/mysqld: unknown variable 'loose-feedback-debug-startup-interval=20'
|
12:09:30 2017-02-16 1:09:24 140597154433280 [Warning] /build/build/sql/mysqld: unknown variable 'loose-feedback-debug-first-interval=60'
|
12:09:30 2017-02-16 1:09:24 140597154433280 [Warning] /build/build/sql/mysqld: unknown variable 'loose-feedback-debug-interval=60'
|
12:09:30 2017-02-16 1:09:24 140597154433280 [Warning] /build/build/sql/mysqld: unknown option '--loose-pam-debug'
|
12:09:30 2017-02-16 1:09:24 140597154433280 [Warning] /build/build/sql/mysqld: unknown option '--loose-skip-plugin-innodb-changed-pages'
|
12:09:30 2017-02-16 1:09:24 140597154433280 [Warning] /build/build/sql/mysqld: unknown variable 'loose-debug-sync-timeout=300'
|
12:09:30 2017-02-16 1:09:24 140597154433280 [Note] Server socket created on IP: '127.0.0.1'.
|
12:09:30 2017-02-16 1:09:24 140597154433280 [Note] /build/build/sql/mysqld: ready for connections.
|
12:09:30 Version: '10.1.22-MariaDB' socket: '/build/build/mysql-test/var/tmp/20/mysqld.1.sock' port: 16360 MariaDB Server
|
12:09:30 2017-02-16 1:09:25 140597153512192 [Note] /build/build/sql/mysqld: Normal shutdown
|
12:09:30
|
12:09:30 2017-02-16 1:09:25 140597153512192 [Note] Event Scheduler: Purging the queue. 0 events
|
12:09:30 2017-02-16 1:09:25 140596803000064 [Note] InnoDB: FTS optimize thread exiting.
|
12:09:30 2017-02-16 1:09:25 140597153512192 [Note] InnoDB: Starting shutdown...
|
12:09:30 2017-02-16 1:09:28 140597153512192 [Note] InnoDB: Shutdown completed; log sequence number 5760292
|
12:09:30 2017-02-16 1:09:28 140597153512192 [Note] /build/build/sql/mysqld: Shutdown complete
|
12:09:30
|
12:09:30 2017-02-16 1:09:28 139909759301888 [Note] /build/build/sql/mysqld (mysqld 10.1.22-MariaDB) starting as process 333 ...
|
12:09:30 2017-02-16 1:09:28 139909759301888 [Warning] Could not increase number of max_open_files to more than 1024 (request: 4162)
|
12:09:30 2017-02-16 1:09:28 139909759301888 [Note] Plugin 'partition' is disabled.
|
12:09:30 2017-02-16 1:09:28 139909759301888 [Note] Plugin 'SEQUENCE' is disabled.
|
12:09:30 2017-02-16 1:09:28 139909759301888 [Note] InnoDB: Using mutexes to ref count buffer pool pages
|
12:09:30 2017-02-16 1:09:28 139909759301888 [Note] InnoDB: The InnoDB memory heap is disabled
|
12:09:30 2017-02-16 1:09:28 139909759301888 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
|
12:09:30 2017-02-16 1:09:28 139909759301888 [Note] InnoDB: GCC builtin __atomic_thread_fence() is used for memory barrier
|
12:09:30 2017-02-16 1:09:28 139909759301888 [Note] InnoDB: Compressed tables use zlib 1.2.3
|
12:09:30 2017-02-16 1:09:28 139909759301888 [Note] InnoDB: Using Linux native AIO
|
12:09:30 2017-02-16 1:09:28 139909759301888 [Note] InnoDB: Using SSE crc32 instructions
|
12:09:30 2017-02-16 1:09:28 139909759301888 [Note] InnoDB: Initializing buffer pool, size = 8.0M
|
12:09:30 2017-02-16 1:09:28 139909759301888 [Note] InnoDB: Completed initialization of buffer pool
|
12:09:30 2017-02-16 1:09:28 139909759301888 [Note] InnoDB: Highest supported file format is Barracuda.
|
12:09:30 2017-02-16 1:09:28 139909759301888 [Note] InnoDB: 128 rollback segment(s) are active.
|
12:09:30 2017-02-16 1:09:28 139909759301888 [Note] InnoDB: Waiting for purge to start
|
12:09:30 2017-02-16 1:09:28 139909759301888 [Note] InnoDB: 5.6.35 started; log sequence number 5760292
|
12:09:30 2017-02-16 1:09:28 139909427877632 [Note] InnoDB: Dumping buffer pool(s) not yet started
|
12:09:30 2017-02-16 1:09:28 139909759301888 [Note] InnoDB: Creating #1 thread id 139909394331392 total threads 4.
|
12:09:30 2017-02-16 1:09:28 139909759301888 [Note] InnoDB: Creating #2 thread id 139909377554176 total threads 4.
|
12:09:30 2017-02-16 1:09:28 139909759301888 [Note] InnoDB: Creating #3 thread id 139909369161472 total threads 4.
|
12:09:30 2017-02-16 1:09:28 139909759301888 [Note] InnoDB: Creating #4 thread id 139909360768768 total threads 4.
|
12:09:30 2017-02-16 1:09:28 139909759301888 [Note] Plugin 'INNODB_SYS_DATAFILES' is disabled.
|
12:09:30 2017-02-16 1:09:28 139909759301888 [Note] Plugin 'INNODB_SYS_TABLESTATS' is disabled.
|
12:09:30 2017-02-16 1:09:28 139909759301888 [Note] Plugin 'INNODB_CMP' is disabled.
|
12:09:30 2017-02-16 1:09:28 139909759301888 [Note] Plugin 'XTRADB_READ_VIEW' is disabled.
|
12:09:30 2017-02-16 1:09:28 139909759301888 [Note] Plugin 'XTRADB_RSEG' is disabled.
|
12:09:30 2017-02-16 1:09:28 139909759301888 [Note] Plugin 'INNODB_FT_DELETED' is disabled.
|
12:09:30 2017-02-16 1:09:28 139909759301888 [Note] Plugin 'INNODB_LOCK_WAITS' is disabled.
|
12:09:30 2017-02-16 1:09:28 139909759301888 [Note] Plugin 'CHANGED_PAGE_BITMAPS' is disabled.
|
12:09:30 2017-02-16 1:09:28 139909759301888 [Note] Plugin 'INNODB_SYS_FIELDS' is disabled.
|
12:09:30 2017-02-16 1:09:28 139909759301888 [Note] Plugin 'XTRADB_INTERNAL_HASH_TABLES' is disabled.
|
12:09:30 2017-02-16 1:09:28 139909759301888 [Note] Plugin 'INNODB_TABLESPACES_SCRUBBING' is disabled.
|
12:09:30 2017-02-16 1:09:28 139909759301888 [Note] Plugin 'INNODB_CMPMEM_RESET' is disabled.
|
12:09:30 2017-02-16 1:09:28 139909759301888 [Note] Plugin 'INNODB_FT_INDEX_TABLE' is disabled.
|
12:09:30 2017-02-16 1:09:28 139909759301888 [Note] Plugin 'INNODB_FT_BEING_DELETED' is disabled.
|
12:09:30 2017-02-16 1:09:28 139909759301888 [Note] Plugin 'INNODB_MUTEXES' is disabled.
|
12:09:30 2017-02-16 1:09:28 139909759301888 [Note] Plugin 'INNODB_FT_CONFIG' is disabled.
|
12:09:30 2017-02-16 1:09:28 139909759301888 [Note] Plugin 'FEEDBACK' is disabled.
|
12:09:30 2017-02-16 1:09:28 139909759301888 [Note] Plugin 'INNODB_FT_INDEX_CACHE' is disabled.
|
12:09:30 2017-02-16 1:09:28 139909759301888 [Note] Plugin 'INNODB_FT_DEFAULT_STOPWORD' is disabled.
|
12:09:30 2017-02-16 1:09:28 139909759301888 [Note] Plugin 'INNODB_CMP_RESET' is disabled.
|
12:09:30 2017-02-16 1:09:28 139909759301888 [Note] Plugin 'INNODB_SYS_COLUMNS' is disabled.
|
12:09:30 2017-02-16 1:09:28 139909759301888 [Note] Plugin 'INNODB_CMP_PER_INDEX_RESET' is disabled.
|
12:09:30 2017-02-16 1:09:28 139909759301888 [Note] Plugin 'INNODB_SYS_TABLESPACES' is disabled.
|
12:09:30 2017-02-16 1:09:28 139909759301888 [Note] Plugin 'INNODB_SYS_SEMAPHORE_WAITS' is disabled.
|
12:09:30 2017-02-16 1:09:28 139909759301888 [Note] Plugin 'INNODB_SYS_INDEXES' is disabled.
|
12:09:30 2017-02-16 1:09:28 139909759301888 [Warning] /build/build/sql/mysqld: unknown variable 'loose-feedback-debug-startup-interval=20'
|
12:09:30 2017-02-16 1:09:28 139909759301888 [Warning] /build/build/sql/mysqld: unknown variable 'loose-feedback-debug-first-interval=60'
|
12:09:30 2017-02-16 1:09:28 139909759301888 [Warning] /build/build/sql/mysqld: unknown variable 'loose-feedback-debug-interval=60'
|
12:09:30 2017-02-16 1:09:28 139909759301888 [Warning] /build/build/sql/mysqld: unknown option '--loose-pam-debug'
|
12:09:30 2017-02-16 1:09:28 139909759301888 [Warning] /build/build/sql/mysqld: unknown option '--loose-skip-plugin-innodb-changed-pages'
|
12:09:30 2017-02-16 1:09:28 139909759301888 [Warning] /build/build/sql/mysqld: unknown variable 'loose-debug-sync-timeout=300'
|
12:09:30 2017-02-16 1:09:28 139909759301888 [Note] Server socket created on IP: '127.0.0.1'.
|
12:09:30 2017-02-16 1:09:28 139909759301888 [Note] /build/build/sql/mysqld: ready for connections.
|
12:09:30 Version: '10.1.22-MariaDB' socket: '/build/build/mysql-test/var/tmp/20/mysqld.1.sock' port: 16360 MariaDB Server
|
12:09:30 170216 1:09:29 [ERROR] mysqld got signal 11 ;
|
12:09:30 This could be because you hit a bug. It is also possible that this binary
|
12:09:30 or one of the libraries it was linked against is corrupt, improperly built,
|
12:09:30 or misconfigured. This error can also be caused by malfunctioning hardware.
|
12:09:30
|
12:09:30 To report this bug, see https://mariadb.com/kb/en/reporting-bugs
|
12:09:30
|
12:09:30 We will try our best to scrape up some info that will hopefully help
|
12:09:30 diagnose the problem, but since we have already crashed,
|
12:09:30 something is definitely wrong and this may fail.
|
12:09:30
|
12:09:30 Server version: 10.1.22-MariaDB
|
12:09:30 key_buffer_size=1048576
|
12:09:30 read_buffer_size=131072
|
12:09:30 max_used_connections=1
|
12:09:30 max_threads=153
|
12:09:30 thread_count=1
|
12:09:30 It is possible that mysqld could use up to
|
12:09:30 key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 62897 K bytes of memory
|
12:09:30 Hope that's ok; if not, decrease some variables in the equation.
|
12:09:30
|
12:09:30 Thread pointer: 0x7f3f3ae97008
|
12:09:30 Attempting backtrace. You can use the following information to find out
|
12:09:30 where mysqld died. If you see no messages after this, something went
|
12:09:30 terribly wrong...
|
12:09:30 stack_bottom = 0x7f3f477480b8 thread_stack 0x48400
|
12:09:30 /build/build/sql/mysqld(my_print_stacktrace+0x29)[0x55b9e9048ed9]
|
12:09:30 /build/build/sql/mysqld(handle_fatal_signal+0x2f5)[0x55b9e8bc0a05]
|
12:09:30 /lib/x86_64-linux-gnu/libpthread.so.0(+0x113e0)[0x7f3f45f3b3e0]
|
12:09:30 /build/build/mysql-test/var/20/plugins/ha_innodb.so(+0x1e359a)[0x7f3f3dd1259a]
|
12:09:30 /build/build/mysql-test/var/20/plugins/ha_innodb.so(+0x1fb69e)[0x7f3f3dd2a69e]
|
12:09:30 mysys/stacktrace.c:268(my_print_stacktrace)[0x7f3f3dd223d9]
|
12:09:30 /build/build/mysql-test/var/20/plugins/ha_innodb.so(+0x1f4651)[0x7f3f3dd23651]
|
12:09:30 /build/build/mysql-test/var/20/plugins/ha_innodb.so(+0x1f4c49)[0x7f3f3dd23c49]
|
12:09:30 /build/build/mysql-test/var/20/plugins/ha_innodb.so(+0x1aa776)[0x7f3f3dcd9776]
|
12:09:30 /build/build/mysql-test/var/20/plugins/ha_innodb.so(+0x102cfe)[0x7f3f3dc31cfe]
|
12:09:30 sql/handler.cc:2352(ha_delete_table(THD*, handlerton*, char const*, char const*, char const*, bool))[0x55b9e8bc7b92]
|
12:09:30 sql/sql_table.cc:2471(mysql_rm_table_no_locks(THD*, TABLE_LIST*, bool, bool, bool, bool, bool))[0x55b9e8ac44c8]
|
12:09:30 sql/sql_table.cc:2085(mysql_rm_table(THD*, TABLE_LIST*, char, char))[0x55b9e8ac4e44]
|
12:09:30 sql/sql_parse.cc:4229(mysql_execute_command(THD*))[0x55b9e8a43897]
|
12:09:30 sql/sql_parse.cc:7327(mysql_parse(THD*, char*, unsigned int, Parser_state*))[0x55b9e8a4a6ba]
|
12:09:30 sql/sql_parse.cc:1490(dispatch_command(enum_server_command, THD*, char*, unsigned int))[0x55b9e8a4d618]
|
12:09:30 sql/sql_parse.cc:1111(do_command(THD*))[0x55b9e8a4dd3e]
|
12:09:30 sql/sql_connect.cc:1349(do_handle_one_connection(THD*))[0x55b9e8b0f01c]
|
12:09:30 sql/sql_connect.cc:1263(handle_one_connection)[0x55b9e8b0f1c7]
|
12:09:30 perfschema/pfs.cc:1863(pfs_spawn_thread)[0x55b9e8e045b8]
|
12:09:30 /lib/x86_64-linux-gnu/libpthread.so.0(+0x770a)[0x7f3f45f3170a]
|
12:09:30 /lib/x86_64-linux-gnu/libc.so.6(clone+0x6d)[0x7f3f455d682d]
|
12:09:30
|
12:09:30 Trying to get some variables.
|
12:09:30 Some pointers may be invalid and cause the dump to abort.
|
12:09:30 Query (0x7f3f2dc1f020): drop table innodb_page_compressed5
|
12:09:30 Connection ID (thread ID): 2
|
12:09:30 Status: NOT_KILLED
|
12:09:30
|
12:09:30 Optimizer switch: index_merge=on,index_merge_union=on,index_merge_sort_union=on,index_merge_intersection=on,index_merge_sort_intersection=off,engine_condition_pushdown=off,index_condition_pushdown=on,derived_merge=on,derived_with_keys=on,firstmatch=on,loosescan=on,materialization=on,in_to_exists=on,semijoin=on,partial_match_rowid_merge=on,partial_match_table_scan=on,subquery_cache=on,mrr=off,mrr_cost_based=off,mrr_sort_keys=off,outer_join_with_cache=on,semijoin_with_cache=on,join_cache_incremental=on,join_cache_hashed=on,join_cache_bka=on,optimize_join_buffer_size=off,table_elimination=on,extended_keys=on,exists_to_in=on,orderby_uses_equalities=off
|
12:09:30
|
12:09:30 The manual page at http://dev.mysql.com/doc/mysql/en/crashing.html contains
|
12:09:30 information that should help you find out what is causing the crash.
|
12:09:30 Writing a core file
|
12:09:30 ----------SERVER LOG END-------------
|
danblack, could you try to resolve the ha_innodb.so symbols?
I think I have seen similar failures when testing --suite=encryption in a WITH_ASAN build. The InnoDB tablespace encryption in 10.1 and 10.2 suffers from race conditions and design problems. jplindst is working on a fix in MDEV-11738.
| Link |
This issue relates to |
Sorry I couldn't get the debug symbols, I've changed my CI to have gdb so I'll have them next time. I noticed this output has an io_setup failure so it might be some transitory test environment failure, sorry - should of looked closer. I'll keep an eye on MDEV-11738 for changes.
| Priority | Major [ 3 ] | Critical [ 2 ] |
Currently it either hands to takes too long:
encryption.innodb_encryption-page-compression 'innodb' w2 [ fail ] timeout after 900 seconds
|
http://buildbot.askmonty.org/buildbot/builders/kvm-fulltest/builds/8229/steps/test_2/logs/stdio
| Labels | 10.2-ga |
| Status | Open [ 1 ] | In Progress [ 3 ] |
| Link |
This issue is part of |
It stopped failing in buildbot on March 30, and then started failing again on April 12, first on bb-10.1-marko ( http://askmonty.org/buildbot/builders/kvm-deb-xenial-x86/builds/1657 ) and further on various 10.1-based trees, the latest for now being April 22 on 10.1 main:
http://buildbot.askmonty.org/buildbot/builders/p8-rhel71-bintar/builds/1986
Thus, I'm adding 10.1 to the list of affected/fix versions and removing 10.2-ga label.
| Fix Version/s | 10.1 [ 16100 ] | |
| Affects Version/s | 10.1 [ 16100 ] | |
| Labels | 10.2-ga |
10.1:
commit 765a43605a42c069ede604826ede2d93d72c4fdd
Author: Jan Lindström <jan.lindstrom@mariadb.com>
Date: Wed Apr 26 15:19:16 2017 +0300
MDEV-12253: Buffer pool blocks are accessed after they have been freed
Problem was that bpage was referenced after it was already freed
from LRU. Fixed by adding a new variable encrypted that is
passed down to buf_page_check_corrupt() and used in
buf_page_get_gen() to stop processing page read.
This patch should also address following test failures and
bugs:
MDEV-12419: IMPORT should not look up tablespace in
PageConverter::validate(). This is now removed.
MDEV-10099: encryption.innodb_onlinealter_encryption fails
sporadically in buildbot
MDEV-11420: encryption.innodb_encryption-page-compression
failed in buildbot
MDEV-11222: encryption.encrypt_and_grep failed in buildbot on P8
Removed dict_table_t::is_encrypted and dict_table_t::ibd_file_missing
and replaced these with dict_table_t::file_unreadable. Table
ibd file is missing if fil_get_space(space_id) returns NULL
and encrypted if not. Removed dict_table_t::is_corrupted field.
Ported FilSpace class from 10.2 and using that on buf_page_check_corrupt(),
buf_page_decrypt_after_read(), buf_page_encrypt_before_write(),
buf_dblwr_process(), buf_read_page(), dict_stats_save_defrag_stats().
Added test cases when enrypted page could be read while doing
redo log crash recovery. Also added test case for row compressed
blobs.
btr_cur_open_at_index_side_func(),
btr_cur_open_at_rnd_pos_func(): Avoid referencing block that is
NULL.
buf_page_get_zip(): Issue error if page read fails.
buf_page_get_gen(): Use dberr_t for error detection and
do not reference bpage after we hare freed it.
buf_mark_space_corrupt(): remove bpage from LRU also when
it is encrypted.
buf_page_check_corrupt(): @return DB_SUCCESS if page has
been read and is not corrupted,
DB_PAGE_CORRUPTED if page based on checksum check is corrupted,
DB_DECRYPTION_FAILED if page post encryption checksum matches but
after decryption normal page checksum does not match. In read
case only DB_SUCCESS is possible.
buf_page_io_complete(): use dberr_t for error handling.
buf_flush_write_block_low(),
buf_read_ahead_random(),
buf_read_page_async(),
buf_read_ahead_linear(),
buf_read_ibuf_merge_pages(),
buf_read_recv_pages(),
fil_aio_wait():
Issue error if page read fails.
btr_pcur_move_to_next_page(): Do not reference page if it is
NULL.
Introduced dict_table_t::is_readable() and dict_index_t::is_readable()
that will return true if tablespace exists and pages read from
tablespace are not corrupted or page decryption failed.
Removed buf_page_t::key_version. After page decryption the
key version is not removed from page frame. For unencrypted
pages, old key_version is removed at buf_page_encrypt_before_write()
dict_stats_update_transient_for_index(),
dict_stats_update_transient()
Do not continue if table decryption failed or table
is corrupted.
dict0stats.cc: Introduced a dict_stats_report_error function
to avoid code duplication.
fil_parse_write_crypt_data():
Check that key read from redo log entry is found from
encryption plugin and if it is not, refuse to start.
PageConverter::validate(): Removed access to fil_space_t as
tablespace is not available during import.
Fixed error code on innodb.innodb test.
Merged test cased innodb-bad-key-change5 and innodb-bad-key-shutdown
to innodb-bad-key-change2. Removed innodb-bad-key-change5 test.
Decreased unnecessary complexity on some long lasting tests.
Removed fil_inc_pending_ops(), fil_decr_pending_ops(),
fil_get_first_space(), fil_get_next_space(),
fil_get_first_space_safe(), fil_get_next_space_safe()
functions.
fil_space_verify_crypt_checksum(): Fixed bug found using ASAN
where FIL_PAGE_END_LSN_OLD_CHECKSUM field was incorrectly
accessed from row compressed tables. Fixed out of page frame
bug for row compressed tables in
fil_space_verify_crypt_checksum() found using ASAN. Incorrect
function was called for compressed table.
Added new tests for discard, rename table and drop (we should allow them
even when page decryption fails). Alter table rename is not allowed.
Added test for restart with innodb-force-recovery=1 when page read on
redo-recovery cant be decrypted. Added test for corrupted table where
both page data and FIL_PAGE_FILE_FLUSH_LSN_OR_KEY_VERSION is corrupted.
Adjusted the test case innodb_bug14147491 so that it does not anymore
expect crash. Instead table is just mostly not usable.
fil0fil.h: fil_space_acquire_low is not visible function
and fil_space_acquire and fil_space_acquire_silent are
inline functions. FilSpace class uses fil_space_acquire_low
directly.
recv_apply_hashed_log_recs() does not return anything.
| Fix Version/s | 10.1.23 [ 22503 ] | |
| Fix Version/s | 10.2 [ 14601 ] | |
| Fix Version/s | 10.1 [ 16100 ] | |
| Resolution | Fixed [ 1 ] | |
| Status | In Progress [ 3 ] | Closed [ 6 ] |
10.2:
commit aad8cefd2d0e49acb9f8ae3ebaa0e3b90f27b89c
Author: Jan Lindström <jan.lindstrom@mariadb.com>
Date: Thu Jun 1 14:08:41 2017 +0300
Enable innodb_encryption-page-compression test.
| Workflow | MariaDB v3 [ 78531 ] | MariaDB v4 [ 151271 ] |
This seems to be related to the discovery of encrypted tablespaces. In the server error log file the nearby tests are restarting the server often, and the warning appears to be issued for something that was created in the preceding test. Here are some relevant lines from the server error log:
CURRENT_TEST: encryption.innodb_encryption-page-compression2016-11-29 16:32:47 3057669888 [Note] /usr/local/mariadb-10.2.3-linux-i686/bin/mysqld (mysqld 10.2.3-MariaDB-log) starting as process 19384 ...…2016-11-29 16:32:48 3057669888 [Note] Server socket created on IP: '127.0.0.1'.2016-11-29 16:32:48 3057669888 [Note] /usr/local/mariadb-10.2.3-linux-i686/bin/mysqld: ready for connections.Version: '10.2.3-MariaDB-log' socket: '/usr/local/mariadb-10.2.3-linux-i686/mysql-test/var/tmp/2/mysqld.1.sock' port: 16060 MariaDB Server2016-11-29 16:32:48 2964670272 [Note] InnoDB: Tablespace ID 6 name test/innodb_normal:Default tablespace encryption mode scheme encrypted2016-11-29 16:32:48 2964670272 [Note] InnoDB: Tablespace ID 7 name test/innodb_page_compressed1:Default tablespace encryption mode scheme encrypted…2016-11-29 16:32:52 2964367168 [Note] /usr/local/mariadb-10.2.3-linux-i686/bin/mysqld: Shutdown complete2016-11-29 16:32:54 3056998144 [Note] /usr/local/mariadb-10.2.3-linux-i686/bin/mysqld (mysqld 10.2.3-MariaDB-log) starting as process 19546 ...…2016-11-29 16:32:54 3056998144 [Note] InnoDB: Tablespace ID 6 name test/innodb_normal:Default tablespace encryption mode scheme encrypted…Version: '10.2.3-MariaDB-log' socket: '/usr/local/mariadb-10.2.3-linux-i686/mysql-test/var/tmp/2/mysqld.1.sock' port: 16060 MariaDB Server2016-11-29 16:32:56 2495609664 [Warning] InnoDB: Trying to access missing tablespace 6CURRENT_TEST: encryption.innodb_encryption-page-compressionIt appears to me that the server is being restarted between the two instances of the test, and that the preceding test (encryption.innodb_encryption-page-compression) is where the offending warning message is being issued. The table innodb-normal is being both created and dropped in the test.
Could there be some dangling reference to this table (tablespace 6) in some persistent data structure? Doublewrite buffer? It cannot be the change buffer, because there is no secondary index defined on innodb_normal (or for any other table created in the test, for that matter).
A possible fix could be to replace fil_space_acquire() with fil_space_acquire_silent() after careful review.
I had a quick check of the fil_space_acquire() calls and did not find anything suspicious.