[MDEV-13646] rpl.rpl_binlog_errors, gcol.gcol_update, innodb.autoinc_persist failed in buildbot Created: 2017-08-25  Updated: 2018-05-17  Resolved: 2018-05-17

Status: Closed
Project: MariaDB Server
Component/s: Tests
Affects Version/s: 10.3
Fix Version/s: N/A

Type: Bug Priority: Major
Reporter: Alice Sherepa Assignee: Sergei Golubchik
Resolution: Cannot Reproduce Votes: 0
Labels: None


 Description   

http://buildbot.askmonty.org/buildbot/builders/kvm-fulltest2/builds/9336/steps/test_2/logs/stdio
crash on shutdown

stack_bottom = 0x0 thread_stack 0x49000
/mnt/buildbot/build/mariadb-10.3.1/sql/mysqld(my_print_stacktrace+0x3b)[0x8d90d57]
/mnt/buildbot/build/mariadb-10.3.1/sql/mysqld(handle_fatal_signal+0x3cf)[0x8627bd3]
[0xb779d400]
[0xb779d424]
/lib/i386-linux-gnu/libpthread.so.0(pthread_cond_wait+0xdb)[0xb752996b]
/mnt/buildbot/build/mariadb-10.3.1/sql/mysqld(safe_cond_wait+0x208)[0x8d95da7]
/mnt/buildbot/build/mariadb-10.3.1/sql/mysqld[0x8294dcb]
/mnt/buildbot/build/mariadb-10.3.1/sql/mysqld(_Z11mysqld_mainiPPc+0xc7f)[0x82a045d]
/mnt/buildbot/build/mariadb-10.3.1/sql/mysqld(main+0x27)[0x82946bb]
/lib/i386-linux-gnu/libc.so.6(__libc_start_main+0xf3)[0xb72644d3]
/mnt/buildbot/build/mariadb-10.3.1/sql/mysqld[0x8294601]

http://buildbot.askmonty.org/buildbot/builders/kvm-fulltest2/builds/9336/steps/test_2/logs/mysqld.1.err.2

2017-08-24 13:32:09 13 [Note] Start binlog_dump to slave_server(2), pos(master-bin.000001, 4)
2017-08-24 13:32:09 14 [ERROR] Can't generate a unique log-filename master-bin.(1-999)
 
2017-08-24 13:32:09 13 [Warning] Aborted connection 13 to db: 'unconnected' user: 'root' host: 'localhost' (could not find next log; the first event 'master-bin.000001' at )
2017-08-24 13:32:11 14 [ERROR] Can't generate a unique log-filename master-bin.(1-999)
 
2017-08-24 13:32:11 14 [ERROR] mysqld: Error writing file 'master-bin' (errno: 0 "Internal error/check (Not system error)")
2017-08-24 13:32:13 14 [ERROR] Can't generate a unique log-filename master-bin.(1-999)
 
2017-08-24 13:32:13 14 [ERROR] mysqld: Error writing file 'master-bin' (errno: 0 "Internal error/check (Not system error)")
2017-08-24 13:32:14 14 [ERROR] Can't generate a unique log-filename master-bin.(1-999)
 
2017-08-24 13:32:14 14 [ERROR] mysqld: Error writing file 'master-bin' (errno: 0 "Internal error/check (Not system error)")
2017-08-24 13:32:14 14 [ERROR] Can't generate a unique log-filename master-bin.(1-999)
 
2017-08-24 13:32:14 14 [ERROR] mysqld: Error writing file 'master-bin' (errno: 0 "Internal error/check (Not system error)")
2017-08-24 13:32:14 14 [ERROR] Can't generate a unique log-filename master-bin.(1-999)
 
2017-08-24 13:32:14 14 [ERROR] mysqld: Error writing file 'master-bin' (errno: 0 "Internal error/check (Not system error)")
2017-08-24 13:32:14 14 [ERROR] Can't generate a unique log-filename master-bin.(1-999)
 
2017-08-24 13:32:14 14 [ERROR] mysqld: Error writing file 'master-bin' (errno: 0 "Internal error/check (Not system error)")
2017-08-24 13:32:14 14 [ERROR] Can't generate a unique log-filename master-bin.(1-999)
 
2017-08-24 13:32:14 14 [ERROR] mysqld: Error writing file 'master-bin' (errno: 0 "Internal error/check (Not system error)")
2017-08-24 13:32:14 14 [ERROR] Can't generate a unique log-filename master-bin.(1-999)
 
2017-08-24 13:32:14 14 [ERROR] mysqld: Error writing file 'master-bin' (errno: 0 "Internal error/check (Not system error)")
2017-08-24 13:32:15 14 [ERROR] MYSQL_BIN_LOG::open failed to sync the index file.
2017-08-24 13:32:15 14 [ERROR] Could not open ./master-bin.000002 for logging (error 2). Turning logging off for the whole duration of the MySQL server process. To turn it on again: fix the cause, shutdown the MySQL server and restart it.
2017-08-24 13:32:15 0 [Note] /mnt/buildbot/build/mariadb-10.3.1/sql/mysqld (root[root] @ localhost [127.0.0.1]): Normal shutdown
 
2017-08-24 13:32:15 0 [Note] InnoDB: FTS optimize thread exiting.
2017-08-24 13:32:15 0 [Note] Event Scheduler: Purging the queue. 0 events
2017-08-24 13:32:15 0 [Note] InnoDB: Starting shutdown...
2017-08-24 13:32:15 0 [Note] InnoDB: Dumping buffer pool(s) to /run/shm/var_auto_gdU6/2/mysqld.1/data/ib_buffer_pool
2017-08-24 13:32:15 0 [Note] InnoDB: Instance 0, restricted to 127 pages due to innodb_buf_pool_dump_pct=25
2017-08-24 13:32:15 0 [Note] InnoDB: Buffer pool(s) dump completed at 170824 13:32:15
2017-08-24 13:32:17 0 [Note] InnoDB: Shutdown completed; log sequence number 1681175
2017-08-24 13:32:17 0 [Note] InnoDB: Removed temporary tablespace data file: "ibtmp1"
2017-08-24 13:32:17 0 [Note] Debug sync points hit:                   4518
2017-08-24 13:32:17 0 [Note] Debug sync points executed:              0
2017-08-24 13:32:17 0 [Note] Debug sync points max active per thread: 0
2017-08-24 13:32:17 0 [Note] /mnt/buildbot/build/mariadb-10.3.1/sql/mysqld: Shutdown complete
 
2017-08-24 13:32:18 0 [Note] /mnt/buildbot/build/mariadb-10.3.1/sql/mysqld (mysqld 10.3.1-MariaDB-debug-log) starting as process 3218 ...
2017-08-24 13:32:18 0 [Warning] Could not increase number of max_open_files to more than 1024 (request: 4162)
2017-08-24 13:32:18 0 [Note] Failed to execute mysql_file_stat on file './master-bin.000002'
2017-08-24 13:32:18 0 [Note] Plugin 'partition' is disabled.
2017-08-24 13:32:18 0 [Note] InnoDB: !!!!!!!! UNIV_DEBUG switched on !!!!!!!!!
2017-08-24 13:32:18 0 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
2017-08-24 13:32:18 0 [Note] InnoDB: Uses event mutexes
2017-08-24 13:32:18 0 [Note] InnoDB: Compressed tables use zlib 1.2.3.4
2017-08-24 13:32:18 0 [Note] InnoDB: Using Linux native AIO
2017-08-24 13:32:18 0 [Note] InnoDB: Number of pools: 1
2017-08-24 13:32:18 0 [Note] InnoDB: Using generic crc32 instructions
2017-08-24 13:32:18 0 [Note] InnoDB: Initializing buffer pool, total size = 8M, instances = 1, chunk size = 8M
2017-08-24 13:32:18 0 [Note] InnoDB: Completed initialization of buffer pool
2017-08-24 13:32:18 0 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().
2017-08-24 13:32:19 0 [Note] InnoDB: 128 out of 128 rollback segments are active.
2017-08-24 13:32:19 0 [Note] InnoDB: Creating shared tablespace for temporary tables
2017-08-24 13:32:19 0 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
2017-08-24 13:32:19 0 [Note] InnoDB: File './ibtmp1' size is now 12 MB.
2017-08-24 13:32:19 0 [Note] InnoDB: Waiting for purge to start
2017-08-24 13:32:20 0 [Note] InnoDB: 5.7.19 started; log sequence number 1681175
2017-08-24 13:32:20 0 [Note] InnoDB: Loading buffer pool(s) from /run/shm/var_auto_gdU6/2/mysqld.1/data/ib_buffer_pool
2017-08-24 13:32:20 0 [Note] InnoDB: Buffer pool(s) load completed at 170824 13:32:20
2017-08-24 13:32:20 0 [Note] Plugin 'SEQUENCE' is disabled.
2017-08-24 13:32:20 0 [Note] Plugin 'INNODB_SYS_DATAFILES' is disabled.
2017-08-24 13:32:20 0 [Note] Plugin 'INNODB_SYS_TABLESTATS' is disabled.
2017-08-24 13:32:20 0 [Note] Plugin 'INNODB_TABLESPACES_SCRUBBING' is disabled.
2017-08-24 13:32:20 0 [Note] Plugin 'INNODB_CMP' is disabled.
2017-08-24 13:32:20 0 [Note] Plugin 'INNODB_FT_DELETED' is disabled.
2017-08-24 13:32:20 0 [Note] Plugin 'INNODB_CMP_RESET' is disabled.
2017-08-24 13:32:20 0 [Note] Plugin 'INNODB_LOCK_WAITS' is disabled.
2017-08-24 13:32:20 0 [Note] Plugin 'INNODB_TABLESPACES_ENCRYPTION' is disabled.
2017-08-24 13:32:20 0 [Note] Plugin 'INNODB_CMPMEM_RESET' is disabled.
2017-08-24 13:32:20 0 [Note] Plugin 'FEEDBACK' is disabled.
2017-08-24 13:32:20 0 [Note] Plugin 'INNODB_FT_INDEX_TABLE' is disabled.
2017-08-24 13:32:20 0 [Note] Plugin 'INNODB_CMP_PER_INDEX_RESET' is disabled.
2017-08-24 13:32:20 0 [Note] Plugin 'user_variables' is disabled.
2017-08-24 13:32:20 0 [Note] Plugin 'INNODB_FT_INDEX_CACHE' is disabled.
2017-08-24 13:32:20 0 [Note] Plugin 'INNODB_FT_BEING_DELETED' is disabled.
2017-08-24 13:32:20 0 [Note] Plugin 'INNODB_FT_DEFAULT_STOPWORD' is disabled.
2017-08-24 13:32:20 0 [Note] Plugin 'INNODB_FT_CONFIG' is disabled.
2017-08-24 13:32:20 0 [Note] Plugin 'INNODB_SYS_TABLESPACES' is disabled.
2017-08-24 13:32:20 0 [Note] Plugin 'INNODB_MUTEXES' is disabled.
2017-08-24 13:32:20 0 [Note] Plugin 'INNODB_SYS_SEMAPHORE_WAITS' is disabled.
2017-08-24 13:32:20 0 [Warning] /mnt/buildbot/build/mariadb-10.3.1/sql/mysqld: unknown option '--loose-pam-debug'
2017-08-24 13:32:20 0 [Note] Server socket created on IP: '127.0.0.1'.
2017-08-24 13:32:20 0 [Note] Reading of all Master_info entries succeded
2017-08-24 13:32:20 0 [Note] Added new Master_info '' to hash table
2017-08-24 13:32:20 0 [Note] /mnt/buildbot/build/mariadb-10.3.1/sql/mysqld: ready for connections.
Version: '10.3.1-MariaDB-debug-log'  socket: '/mnt/buildbot/build/mariadb-10.3.1/mysql-test/var/tmp/2/mysqld.1.sock'  port: 16020  Source distribution
2017-08-24 13:32:21 10 [ERROR] Error writing file './master-bin.index' (errno: 9 "Bad file descriptor")
2017-08-24 13:32:21 10 [ERROR] Could not open ./master-bin.000003 for logging (error 9). Turning logging off for the whole duration of the MySQL server process. To turn it on again: fix the cause, shutdown the MySQL server and restart it.
2017-08-24 13:32:21 0 [Note] /mnt/buildbot/build/mariadb-10.3.1/sql/mysqld (root[root] @ localhost [127.0.0.1]): Normal shutdown
 
2017-08-24 13:32:21 0 [Note] InnoDB: FTS optimize thread exiting.
2017-08-24 13:32:21 0 [Note] Event Scheduler: Purging the queue. 0 events
2017-08-24 13:32:21 0 [Note] InnoDB: Starting shutdown...
2017-08-24 13:32:21 0 [Note] InnoDB: Dumping buffer pool(s) to /run/shm/var_auto_gdU6/2/mysqld.1/data/ib_buffer_pool
2017-08-24 13:32:21 0 [Note] InnoDB: Instance 0, restricted to 127 pages due to innodb_buf_pool_dump_pct=25
2017-08-24 13:32:21 0 [Note] InnoDB: Buffer pool(s) dump completed at 170824 13:32:21
2017-08-24 13:32:23 0 [Note] InnoDB: Shutdown completed; log sequence number 1681686
2017-08-24 13:32:23 0 [Note] InnoDB: Removed temporary tablespace data file: "ibtmp1"
2017-08-24 13:32:23 0 [Note] Debug sync points hit:                   925
2017-08-24 13:32:23 0 [Note] Debug sync points executed:              0
2017-08-24 13:32:23 0 [Note] Debug sync points max active per thread: 0
2017-08-24 13:32:23 0 [Note] /mnt/buildbot/build/mariadb-10.3.1/sql/mysqld: Shutdown complete
 
2017-08-24 13:32:24 0 [Note] /mnt/buildbot/build/mariadb-10.3.1/sql/mysqld (mysqld 10.3.1-MariaDB-debug-log) starting as process 3573 ...
2017-08-24 13:32:24 0 [Warning] Could not increase number of max_open_files to more than 1024 (request: 4162)
2017-08-24 13:32:24 0 [Note] Plugin 'partition' is disabled.
2017-08-24 13:32:24 0 [Note] InnoDB: !!!!!!!! UNIV_DEBUG switched on !!!!!!!!!
2017-08-24 13:32:24 0 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
2017-08-24 13:32:24 0 [Note] InnoDB: Uses event mutexes
2017-08-24 13:32:24 0 [Note] InnoDB: Compressed tables use zlib 1.2.3.4
2017-08-24 13:32:24 0 [Note] InnoDB: Using Linux native AIO
2017-08-24 13:32:24 0 [Note] InnoDB: Number of pools: 1
2017-08-24 13:32:24 0 [Note] InnoDB: Using generic crc32 instructions
2017-08-24 13:32:24 0 [Note] InnoDB: Initializing buffer pool, total size = 8M, instances = 1, chunk size = 8M
2017-08-24 13:32:24 0 [Note] InnoDB: Completed initialization of buffer pool
2017-08-24 13:32:24 0 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().
2017-08-24 13:32:25 0 [Note] InnoDB: 128 out of 128 rollback segments are active.
2017-08-24 13:32:25 0 [Note] InnoDB: Creating shared tablespace for temporary tables
2017-08-24 13:32:25 0 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
2017-08-24 13:32:25 0 [Note] InnoDB: File './ibtmp1' size is now 12 MB.
2017-08-24 13:32:25 0 [Note] InnoDB: Waiting for purge to start
2017-08-24 13:32:25 0 [Note] InnoDB: 5.7.19 started; log sequence number 1681686
2017-08-24 13:32:25 0 [Note] InnoDB: Loading buffer pool(s) from /run/shm/var_auto_gdU6/2/mysqld.1/data/ib_buffer_pool
2017-08-24 13:32:26 0 [Note] InnoDB: Buffer pool(s) load completed at 170824 13:32:26
2017-08-24 13:32:26 0 [Note] Plugin 'SEQUENCE' is disabled.
2017-08-24 13:32:26 0 [Note] Plugin 'INNODB_SYS_DATAFILES' is disabled.
2017-08-24 13:32:26 0 [Note] Plugin 'INNODB_SYS_TABLESTATS' is disabled.
2017-08-24 13:32:26 0 [Note] Plugin 'INNODB_TABLESPACES_SCRUBBING' is disabled.
2017-08-24 13:32:26 0 [Note] Plugin 'INNODB_CMP' is disabled.
2017-08-24 13:32:26 0 [Note] Plugin 'INNODB_FT_DELETED' is disabled.
2017-08-24 13:32:26 0 [Note] Plugin 'INNODB_CMP_RESET' is disabled.
2017-08-24 13:32:26 0 [Note] Plugin 'INNODB_LOCK_WAITS' is disabled.
2017-08-24 13:32:26 0 [Note] Plugin 'INNODB_TABLESPACES_ENCRYPTION' is disabled.
2017-08-24 13:32:26 0 [Note] Plugin 'INNODB_CMPMEM_RESET' is disabled.
2017-08-24 13:32:26 0 [Note] Plugin 'FEEDBACK' is disabled.
2017-08-24 13:32:26 0 [Note] Plugin 'INNODB_FT_INDEX_TABLE' is disabled.
2017-08-24 13:32:26 0 [Note] Plugin 'INNODB_CMP_PER_INDEX_RESET' is disabled.
2017-08-24 13:32:26 0 [Note] Plugin 'user_variables' is disabled.
2017-08-24 13:32:26 0 [Note] Plugin 'INNODB_FT_INDEX_CACHE' is disabled.
2017-08-24 13:32:26 0 [Note] Plugin 'INNODB_FT_BEING_DELETED' is disabled.
2017-08-24 13:32:26 0 [Note] Plugin 'INNODB_FT_DEFAULT_STOPWORD' is disabled.
2017-08-24 13:32:26 0 [Note] Plugin 'INNODB_FT_CONFIG' is disabled.
2017-08-24 13:32:26 0 [Note] Plugin 'INNODB_SYS_TABLESPACES' is disabled.
2017-08-24 13:32:26 0 [Note] Plugin 'INNODB_MUTEXES' is disabled.
2017-08-24 13:32:26 0 [Note] Plugin 'INNODB_SYS_SEMAPHORE_WAITS' is disabled.
2017-08-24 13:32:26 0 [Warning] /mnt/buildbot/build/mariadb-10.3.1/sql/mysqld: unknown option '--loose-pam-debug'
2017-08-24 13:32:26 0 [Note] Server socket created on IP: '127.0.0.1'.
2017-08-24 13:32:26 0 [Note] Reading of all Master_info entries succeded
2017-08-24 13:32:26 0 [Note] Added new Master_info '' to hash table
2017-08-24 13:32:26 0 [Note] /mnt/buildbot/build/mariadb-10.3.1/sql/mysqld: ready for connections.
Version: '10.3.1-MariaDB-debug-log'  socket: '/mnt/buildbot/build/mariadb-10.3.1/mysql-test/var/tmp/2/mysqld.1.sock'  port: 16020  Source distribution
2017-08-24 13:32:27 10 [ERROR] Could not open ./master-bin.000004 for logging (error 2). Turning logging off for the whole duration of the MySQL server process. To turn it on again: fix the cause, shutdown the MySQL server and restart it.
2017-08-24 13:32:27 0 [Note] /mnt/buildbot/build/mariadb-10.3.1/sql/mysqld (root[root] @ localhost [127.0.0.1]): Normal shutdown
 
2017-08-24 13:32:27 0 [Note] InnoDB: FTS optimize thread exiting.
2017-08-24 13:32:27 0 [Note] Event Scheduler: Purging the queue. 0 events
170824 13:33:27 [ERROR] mysqld got signal 6 ;
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.3.1-MariaDB-debug-log
key_buffer_size=1048576
read_buffer_size=131072
max_used_connections=5
max_threads=153
thread_count=1
It is possible that mysqld could use up to 
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 61889 K  bytes of memory
Hope that's ok; if not, decrease some variables in the equation.
 
Thread pointer: 0x0
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 0x49000
/mnt/buildbot/build/mariadb-10.3.1/sql/mysqld(my_print_stacktrace+0x3b)[0x8d90d57]
/mnt/buildbot/build/mariadb-10.3.1/sql/mysqld(handle_fatal_signal+0x3cf)[0x8627bd3]
[0xb7784400]
[0xb7784424]
/lib/i386-linux-gnu/libpthread.so.0(pthread_cond_wait+0xdb)[0xb751096b]
/mnt/buildbot/build/mariadb-10.3.1/sql/mysqld(safe_cond_wait+0x208)[0x8d95da7]
/mnt/buildbot/build/mariadb-10.3.1/sql/mysqld[0x8294dcb]
/mnt/buildbot/build/mariadb-10.3.1/sql/mysqld(_Z11mysqld_mainiPPc+0xc7f)[0x82a045d]
/mnt/buildbot/build/mariadb-10.3.1/sql/mysqld(main+0x27)[0x82946bb]
/lib/i386-linux-gnu/libc.so.6(__libc_start_main+0xf3)[0xb724b4d3]
/mnt/buildbot/build/mariadb-10.3.1/sql/mysqld[0x8294601]



 Comments   
Comment by Elena Stepanova [ 2017-08-25 ]

It started happening on bb-10.3-monty on 2017-08-10, then bb-10.3-serg, then 10.3.

I think it might be related to "Have mysqltest first send SIGABRT, then SIGKILL". When I tried to do it some time ago upon marko's request, I had similar problems in my tree, couldn't get rid of them in reasonable time, which is why I never pushed it to the main tree.

Comment by Sergei Golubchik [ 2018-05-17 ]

gcol.gcol_update and innodb.autoinc_persist didn't fail for many months.
rpl.rpl_binlog_errors still fails, but with a different stack trace.

So, I'm closing this one.

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