[MDEV-16953] innodb.innodb-32k-crash failed in buildbot with CORRUPT LOG RECORD FOUND Created: 2018-08-11  Updated: 2019-09-30  Resolved: 2019-09-30

Status: Closed
Project: MariaDB Server
Component/s: Storage Engine - InnoDB, Tests
Affects Version/s: 10.2
Fix Version/s: 10.2.18, 10.3.10

Type: Bug Priority: Major
Reporter: Elena Stepanova Assignee: Marko Mäkelä
Resolution: Fixed Votes: 0
Labels: None


 Description   

http://buildbot.askmonty.org/buildbot/builders/kvm-bintar-trusty-x86/builds/7095

innodb.innodb-32k-crash 'innodb'         w3 [ fail ]
 
        Test ended at 2018-08-10 12:02:49
 
 
 
CURRENT_TEST: innodb.innodb-32k-crash
 
 
 
 
 
Server [mysqld.1 - pid: 3163, winpid: 3163, exit: 256] failed during test run
 
Server log from this test:
 
----------SERVER LOG START-----------
 
2018-08-10 12:02:47 3056940800 [Note] /usr/local/mariadb-10.2.17-linux-i686/bin/mysqld (mysqld 10.2.17-MariaDB-log) starting as process 3109 ...
 
2018-08-10 12:02:47 3056940800 [Warning] Could not increase number of max_open_files to more than 1024 (request: 4182)
 
2018-08-10 12:02:47 3056940800 [Warning] Changed limits: max_open_files: 1024  max_connections: 151 (was 151)  table_cache: 421 (was 2000)
 
2018-08-10 12:02:47 3056940800 [Note] Plugin 'SEQUENCE' is disabled.
 
2018-08-10 12:02:47 3056940800 [Note] Plugin 'partition' is disabled.
 
2018-08-10 12:02:47 3056940800 [Note] InnoDB: innodb_page_size=32768
 
2018-08-10 12:02:47 3056940800 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
 
2018-08-10 12:02:47 3056940800 [Note] InnoDB: Uses event mutexes
 
2018-08-10 12:02:47 3056940800 [Note] InnoDB: Compressed tables use zlib 1.2.3
 
2018-08-10 12:02:47 3056940800 [Note] InnoDB: Using Linux native AIO
 
2018-08-10 12:02:47 3056940800 [Note] InnoDB: Number of pools: 1
 
2018-08-10 12:02:47 3056940800 [Note] InnoDB: Using generic crc32 instructions
 
2018-08-10 12:02:47 3056940800 [Note] InnoDB: Initializing buffer pool, total size = 32M, instances = 1, chunk size = 32M
 
2018-08-10 12:02:47 3056940800 [Note] InnoDB: Completed initialization of buffer pool
 
2018-08-10 12:02:47 2864409408 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().
 
2018-08-10 12:02:47 3056940800 [Note] InnoDB: Highest supported file format is Barracuda.
 
2018-08-10 12:02:47 3056940800 [Note] InnoDB: 128 out of 128 rollback segments are active.
 
2018-08-10 12:02:47 3056940800 [Note] InnoDB: Creating shared tablespace for temporary tables
 
2018-08-10 12:02:47 3056940800 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
 
2018-08-10 12:02:47 3056940800 [Note] InnoDB: File './ibtmp1' size is now 12 MB.
 
2018-08-10 12:02:48 3056940800 [Note] InnoDB: 5.7.23 started; log sequence number 3116674
 
2018-08-10 12:02:48 3056940800 [Note] Plugin 'INNODB_SYS_DATAFILES' is disabled.
 
2018-08-10 12:02:48 3056940800 [Note] Plugin 'INNODB_SYS_TABLESTATS' is disabled.
 
2018-08-10 12:02:48 3056940800 [Note] Plugin 'INNODB_MUTEXES' is disabled.
 
2018-08-10 12:02:48 3056940800 [Note] Plugin 'INNODB_CMP' is disabled.
 
2018-08-10 12:02:48 3056940800 [Note] Plugin 'INNODB_FT_DELETED' is disabled.
 
2018-08-10 12:02:48 3056940800 [Note] Plugin 'INNODB_CMP_RESET' is disabled.
 
2018-08-10 12:02:48 3056940800 [Note] Plugin 'INNODB_LOCK_WAITS' is disabled.
 
2018-08-10 12:02:48 3056940800 [Note] Plugin 'INNODB_TABLESPACES_ENCRYPTION' is disabled.
 
2018-08-10 12:02:48 3056940800 [Note] Plugin 'INNODB_CMPMEM_RESET' is disabled.
 
2018-08-10 12:02:48 3056940800 [Note] Plugin 'FEEDBACK' is disabled.
 
2018-08-10 12:02:48 3056940800 [Note] Plugin 'INNODB_FT_INDEX_TABLE' is disabled.
 
2018-08-10 12:02:48 3056940800 [Note] Plugin 'INNODB_CMP_PER_INDEX_RESET' is disabled.
 
2018-08-10 12:02:48 3056940800 [Note] Plugin 'user_variables' is disabled.
 
2018-08-10 12:02:48 3056940800 [Note] Plugin 'INNODB_FT_INDEX_CACHE' is disabled.
 
2018-08-10 12:02:48 3056940800 [Note] Plugin 'INNODB_FT_BEING_DELETED' is disabled.
 
2018-08-10 12:02:48 3056940800 [Note] Plugin 'INNODB_FT_DEFAULT_STOPWORD' is disabled.
 
2018-08-10 12:02:48 3056940800 [Note] Plugin 'INNODB_FT_CONFIG' is disabled.
 
2018-08-10 12:02:48 3056940800 [Note] Plugin 'INNODB_SYS_TABLESPACES' is disabled.
 
2018-08-10 12:02:48 3056940800 [Note] Plugin 'INNODB_TABLESPACES_SCRUBBING' is disabled.
 
2018-08-10 12:02:48 3056940800 [Note] Plugin 'INNODB_SYS_SEMAPHORE_WAITS' is disabled.
 
2018-08-10 12:02:48 3056940800 [Warning] /usr/local/mariadb-10.2.17-linux-i686/bin/mysqld: unknown variable 'loose-feedback-debug-startup-interval=20'
 
2018-08-10 12:02:48 3056940800 [Warning] /usr/local/mariadb-10.2.17-linux-i686/bin/mysqld: unknown variable 'loose-feedback-debug-first-interval=60'
 
2018-08-10 12:02:48 3056940800 [Warning] /usr/local/mariadb-10.2.17-linux-i686/bin/mysqld: unknown variable 'loose-feedback-debug-interval=60'
 
2018-08-10 12:02:48 3056940800 [Warning] /usr/local/mariadb-10.2.17-linux-i686/bin/mysqld: unknown option '--loose-pam-debug'
 
2018-08-10 12:02:48 3056940800 [Warning] /usr/local/mariadb-10.2.17-linux-i686/bin/mysqld: unknown variable 'loose-debug-sync-timeout=300'
 
2018-08-10 12:02:48 2759842624 [Note] InnoDB: Loading buffer pool(s) from /run/shm/var_auto_0FDL/3/mysqld.1/data/ib_buffer_pool
 
2018-08-10 12:02:48 3056940800 [Note] Server socket created on IP: '127.0.0.1'.
 
2018-08-10 12:02:48 2759842624 [Note] InnoDB: Buffer pool(s) load completed at 180810 12:02:48
 
2018-08-10 12:02:48 3056940800 [Note] Reading of all Master_info entries succeded
 
2018-08-10 12:02:48 3056940800 [Note] Added new Master_info '' to hash table
 
2018-08-10 12:02:48 3056940800 [Note] /usr/local/mariadb-10.2.17-linux-i686/bin/mysqld: ready for connections.
 
Version: '10.2.17-MariaDB-log'  socket: '/usr/local/mariadb-10.2.17-linux-i686/mysql-test/var/tmp/3/mysqld.1.sock'  port: 16040  MariaDB Server
 
2018-08-10 12:02:49 3057477376 [Note] /usr/local/mariadb-10.2.17-linux-i686/bin/mysqld (mysqld 10.2.17-MariaDB-log) starting as process 3164 ...
 
2018-08-10 12:02:49 3057477376 [Warning] Could not increase number of max_open_files to more than 1024 (request: 4182)
 
2018-08-10 12:02:49 3057477376 [Warning] Changed limits: max_open_files: 1024  max_connections: 151 (was 151)  table_cache: 421 (was 2000)
 
2018-08-10 12:02:49 3057477376 [Note] Plugin 'SEQUENCE' is disabled.
 
2018-08-10 12:02:49 3057477376 [Note] Plugin 'partition' is disabled.
 
2018-08-10 12:02:49 3057477376 [Note] InnoDB: innodb_page_size=32768
 
2018-08-10 12:02:49 3057477376 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
 
2018-08-10 12:02:49 3057477376 [Note] InnoDB: Uses event mutexes
 
2018-08-10 12:02:49 3057477376 [Note] InnoDB: Compressed tables use zlib 1.2.3
 
2018-08-10 12:02:49 3057477376 [Note] InnoDB: Using Linux native AIO
 
2018-08-10 12:02:49 3057477376 [Note] InnoDB: Number of pools: 1
 
2018-08-10 12:02:49 3057477376 [Note] InnoDB: Using generic crc32 instructions
 
2018-08-10 12:02:49 3057477376 [Note] InnoDB: Initializing buffer pool, total size = 32M, instances = 1, chunk size = 32M
 
2018-08-10 12:02:49 3057477376 [Note] InnoDB: Completed initialization of buffer pool
 
2018-08-10 12:02:49 2865457984 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().
 
2018-08-10 12:02:49 3057477376 [Note] InnoDB: Highest supported file format is Barracuda.
 
2018-08-10 12:02:49 3057477376 [Note] InnoDB: Starting crash recovery from checkpoint LSN=3116674
 
2018-08-10 12:02:49 3057477376 [ERROR] InnoDB: ############### CORRUPT LOG RECORD FOUND ##################
 
2018-08-10 12:02:49 3057477376 [Note] InnoDB: Log record type 1, page 4:97. Log parsing proceeded successfully up to 5721161. Previous log record type 1, is multi 1 Recv offset 636496, prev 636490
 
2018-08-10 12:02:49 3057477376 [Note] InnoDB: Hex dump starting 100 bytes before and ending 0 bytes after the corrupted record:
 
 len 106; hex 636363636363636363636363636363636363636363636363636363636363636363630104613ffe00010461401200010461402600010461403a00010461404e00010461406200010461407600010461408a00010461409e0001046140b20001046140c60001046140da00; asc cccccccccccccccccccccccccccccccccc  a?    a@    a@&   a@:   a@N   a@b   a@v   a@    a@    a@    a@    a@  ;
 
2018-08-10 12:02:49 3057477376 [Note] InnoDB: Set innodb_force_recovery to ignore this error.
 
2018-08-10 12:02:49 3057477376 [ERROR] InnoDB: Plugin initialization aborted with error Generic error
 
2018-08-10 12:02:49 3057477376 [Note] InnoDB: Starting shutdown...
 
2018-08-10 12:02:49 3057477376 [ERROR] Plugin 'InnoDB' init function returned error.
 
2018-08-10 12:02:49 3057477376 [ERROR] Plugin 'InnoDB' registration as a STORAGE ENGINE failed.
 
2018-08-10 12:02:49 3057477376 [Note] Plugin 'INNODB_SYS_DATAFILES' is disabled.
 
2018-08-10 12:02:49 3057477376 [Note] Plugin 'INNODB_SYS_TABLESTATS' is disabled.
 
2018-08-10 12:02:49 3057477376 [Note] Plugin 'INNODB_MUTEXES' is disabled.
 
2018-08-10 12:02:49 3057477376 [Note] Plugin 'INNODB_CMP' is disabled.
 
2018-08-10 12:02:49 3057477376 [Note] Plugin 'INNODB_FT_DELETED' is disabled.
 
2018-08-10 12:02:49 3057477376 [Note] Plugin 'INNODB_CMP_RESET' is disabled.
 
2018-08-10 12:02:49 3057477376 [Note] Plugin 'INNODB_LOCK_WAITS' is disabled.
 
2018-08-10 12:02:49 3057477376 [Note] Plugin 'INNODB_TABLESPACES_ENCRYPTION' is disabled.
 
2018-08-10 12:02:49 3057477376 [Note] Plugin 'INNODB_CMPMEM_RESET' is disabled.
 
2018-08-10 12:02:49 3057477376 [Note] Plugin 'FEEDBACK' is disabled.
 
2018-08-10 12:02:49 3057477376 [Note] Plugin 'INNODB_FT_INDEX_TABLE' is disabled.
 
2018-08-10 12:02:49 3057477376 [Note] Plugin 'INNODB_CMP_PER_INDEX_RESET' is disabled.
 
2018-08-10 12:02:49 3057477376 [Note] Plugin 'user_variables' is disabled.
 
2018-08-10 12:02:49 3057477376 [Note] Plugin 'INNODB_FT_INDEX_CACHE' is disabled.
 
2018-08-10 12:02:49 3057477376 [Note] Plugin 'INNODB_FT_BEING_DELETED' is disabled.
 
2018-08-10 12:02:49 3057477376 [Note] Plugin 'INNODB_FT_DEFAULT_STOPWORD' is disabled.
 
2018-08-10 12:02:49 3057477376 [Note] Plugin 'INNODB_FT_CONFIG' is disabled.
 
2018-08-10 12:02:49 3057477376 [Note] Plugin 'INNODB_SYS_TABLESPACES' is disabled.
 
2018-08-10 12:02:49 3057477376 [Note] Plugin 'INNODB_TABLESPACES_SCRUBBING' is disabled.
 
2018-08-10 12:02:49 3057477376 [Note] Plugin 'INNODB_SYS_SEMAPHORE_WAITS' is disabled.
 
2018-08-10 12:02:49 3057477376 [Warning] /usr/local/mariadb-10.2.17-linux-i686/bin/mysqld: unknown variable 'loose-feedback-debug-startup-interval=20'
 
2018-08-10 12:02:49 3057477376 [Warning] /usr/local/mariadb-10.2.17-linux-i686/bin/mysqld: unknown variable 'loose-feedback-debug-first-interval=60'
 
2018-08-10 12:02:49 3057477376 [Warning] /usr/local/mariadb-10.2.17-linux-i686/bin/mysqld: unknown variable 'loose-feedback-debug-interval=60'
 
2018-08-10 12:02:49 3057477376 [Warning] /usr/local/mariadb-10.2.17-linux-i686/bin/mysqld: unknown option '--loose-pam-debug'
 
2018-08-10 12:02:49 3057477376 [Warning] /usr/local/mariadb-10.2.17-linux-i686/bin/mysqld: unknown variable 'loose-debug-sync-timeout=300'
 
2018-08-10 12:02:49 3057477376 [ERROR] Unknown/unsupported storage engine: InnoDB
 
2018-08-10 12:02:49 3057477376 [ERROR] Aborting
 
 
 
----------SERVER LOG END-------------
 
mysqltest failed but provided no output
 
The result from queries just before the failure was:
 
< snip >
 
UPDATE t1 SET ka=@d,la=@d,ma=@d,na=@d,oa=@d,pa=@d;
 
UPDATE t1 SET qa=@d,ra=@d,sa=@d,ta=@d,ua=@d;
 
UPDATE t1 SET va=@d,wa=@d,xa=@d,ya=@d,za=@d;
 
COMMIT;
 
BEGIN;
 
UPDATE t2 SET a=@l,b=@l,c=@l,d=@l,e=@l;
 
UPDATE t2 SET f=@l,g=@l,h=@l,i=@l,j=@l;
 
UPDATE t2 SET k=@l,l=@l,m=@l,n=@l,o=@l;
 
UPDATE t2 SET p=@l,q=@l,r=@l,s=@l,t=@l,u=@l;
 
UPDATE t2 SET v=@l,w=@l,x=@l,y=@l,z=@l;
 
UPDATE t2 SET aa=@l,ba=@l,ca=@l,da=@l;
 
UPDATE t2 SET ea=@l,fa=@l,ga=@l,ha=@l,ia=@l,ja=@l;
 
UPDATE t2 SET ka=@l,la=@l,ma=@l,na=@l,oa=@l,pa=@l;
 
UPDATE t2 SET qa=@l,ra=@l,sa=@l,ta=@l,ua=@l;
 
UPDATE t2 SET va=@l,wa=@l,xa=@l,ya=@l,za=@l;
 
COMMIT;
 
BEGIN;
 
INSERT INTO t1 SELECT * from t2;
 
BEGIN;
 
UPDATE t1 SET a=@e,b=@e,c=@e,d=@e,e=@e;



 Comments   
Comment by Elena Stepanova [ 2018-08-12 ]

tokudb_bugs.xa-3 failed due to seemingly the same problem:
http://buildbot.askmonty.org/buildbot/builders/kvm-bintar-centos6-amd64-debug/builds/691

tokudb_bugs.xa-3 'innodb'                w2 [ fail ]
 
        Test ended at 2018-08-10 17:21:11
 
 
 
CURRENT_TEST: tokudb_bugs.xa-3
 
 
 
 
 
Server [mysqld.1 - pid: 20312, winpid: 20312, exit: 256] failed during test run
 
Server log from this test:
 
----------SERVER LOG START-----------
 
SIGKILL myself
 
2018-08-10 17:21:10 140418077017888 [Note] /usr/local/mariadb-10.2.17-linux-x86_64/bin/mysqld (mysqld 10.2.17-MariaDB-debug-log) starting as process 20313 ...
 
2018-08-10 17:21:10 140418077017888 [Warning] Could not increase number of max_open_files to more than 1024 (request: 4182)
 
2018-08-10 17:21:10 140418077017888 [Warning] Changed limits: max_open_files: 1024  max_connections: 151 (was 151)  table_cache: 421 (was 2000)
 
2018-08-10 17:21:10 140418077017888 [Note] Plugin 'SEQUENCE' is disabled.
 
Fri Aug 10 17:21:10 2018 PerconaFT recovery starting in env /usr/local/mariadb-10.2.17-linux-x86_64/mysql-test/var/2/mysqld.1/data/
 
Fri Aug 10 17:21:10 2018 PerconaFT recovery scanning backward from 545
 
Fri Aug 10 17:21:10 2018 PerconaFT recovery bw_end_checkpoint at 12 timestamp 1533910863927033 xid 8 (bw_newer)
 
Fri Aug 10 17:21:10 2018 PerconaFT recovery bw_begin_checkpoint at 8 timestamp 1533910863926239 (bw_between)
 
Fri Aug 10 17:21:10 2018 PerconaFT recovery turning around at begin checkpoint 8 time 794
 
Fri Aug 10 17:21:10 2018 PerconaFT recovery starts scanning forward to 545 from 8 left 537 (fw_between)
 
Fri Aug 10 17:21:10 2018 PerconaFT recovery closing 2 dictionaries
 
Fri Aug 10 17:21:10 2018 PerconaFT recovery making a checkpoint
 
Fri Aug 10 17:21:10 2018 PerconaFT recovery done
 
2018-08-10 17:21:10 140418077017888 [Note] InnoDB: !!!!!!!! UNIV_DEBUG switched on !!!!!!!!!
 
2018-08-10 17:21:10 140418077017888 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
 
2018-08-10 17:21:10 140418077017888 [Note] InnoDB: Uses event mutexes
 
2018-08-10 17:21:10 140418077017888 [Note] InnoDB: Compressed tables use zlib 1.2.3
 
2018-08-10 17:21:10 140418077017888 [Note] InnoDB: Using Linux native AIO
 
2018-08-10 17:21:10 140418077017888 [Note] InnoDB: Number of pools: 1
 
2018-08-10 17:21:10 140418077017888 [Note] InnoDB: Using generic crc32 instructions
 
2018-08-10 17:21:10 140418077017888 [Note] InnoDB: Initializing buffer pool, total size = 8M, instances = 1, chunk size = 8M
 
2018-08-10 17:21:10 140418077017888 [Note] InnoDB: Completed initialization of buffer pool
 
2018-08-10 17:21:10 140416856860416 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().
 
2018-08-10 17:21:10 140418077017888 [Note] InnoDB: Highest supported file format is Barracuda.
 
2018-08-10 17:21:10 140418077017888 [Note] InnoDB: Starting crash recovery from checkpoint LSN=2787252
 
2018-08-10 17:21:10 140418077017888 [Note] InnoDB: Ignoring data file './test/t1.ibd' with space ID 14, since the redo log references ./test/t1.ibd with space ID 7.
 
2018-08-10 17:21:10 140418077017888 [Note] InnoDB: Ignoring data file './test/t1.ibd' with space ID 14, since the redo log references ./test/t1.ibd with space ID 13.
 
2018-08-10 17:21:10 140418077017888 [ERROR] InnoDB: ############### CORRUPT LOG RECORD FOUND ##################
 
2018-08-10 17:21:10 140418077017888 [Note] InnoDB: Log record type 2, page 0:434. Log parsing proceeded successfully up to 1736578. Previous log record type 2, is multi 1 Recv offset 63165, prev 63158
 
2018-08-10 17:21:10 140418077017888 [Note] InnoDB: Hex dump starting 100 bytes before and ending 0 bytes after the corrupted record:
 
 len 107; hex 9813aef0ffffffff01000001aa80ea040000003a333b0081b204008198133281b2020081b2001806020081b2004492f2040081b200408198040081b2003c00160081b201020081b2002a56020081b2003a00040081b2004600040081b2004af0ffffffff020081b2004e00; asc                    :3;        2              D       @       <           *V     :      F      J          N ;
 
2018-08-10 17:21:10 140418077017888 [Note] InnoDB: Set innodb_force_recovery to ignore this error.
 
2018-08-10 17:21:10 140418077017888 [ERROR] InnoDB: Plugin initialization aborted at srv0start.cc[2239] with error Generic error
 
2018-08-10 17:21:10 140418077017888 [Note] InnoDB: Starting shutdown...
 
2018-08-10 17:21:10 140418077017888 [ERROR] Plugin 'InnoDB' init function returned error.
 
2018-08-10 17:21:10 140418077017888 [ERROR] Plugin 'InnoDB' registration as a STORAGE ENGINE failed.
 
2018-08-10 17:21:10 140418077017888 [Note] Plugin 'partition' is disabled.
 
2018-08-10 17:21:10 140418077017888 [Note] Plugin 'INNODB_SYS_DATAFILES' is disabled.
 
2018-08-10 17:21:10 140418077017888 [Note] Plugin 'INNODB_SYS_TABLESTATS' is disabled.
 
2018-08-10 17:21:10 140418077017888 [Note] Plugin 'INNODB_CMP' is disabled.
 
2018-08-10 17:21:10 140418077017888 [Note] Plugin 'FEEDBACK' is disabled.
 
2018-08-10 17:21:10 140418077017888 [Note] Plugin 'INNODB_CMP_RESET' is disabled.
 
2018-08-10 17:21:10 140418077017888 [Note] Plugin 'INNODB_TABLESPACES_ENCRYPTION' is disabled.
 
2018-08-10 17:21:10 140418077017888 [Note] Plugin 'INNODB_CMPMEM_RESET' is disabled.
 
2018-08-10 17:21:10 140418077017888 [Note] Plugin 'INNODB_FT_INDEX_TABLE' is disabled.
 
2018-08-10 17:21:10 140418077017888 [Note] Plugin 'INNODB_CMP_PER_INDEX_RESET' is disabled.
 
2018-08-10 17:21:10 140418077017888 [Note] Plugin 'user_variables' is disabled.
 
2018-08-10 17:21:10 140418077017888 [Note] Plugin 'INNODB_FT_INDEX_CACHE' is disabled.
 
2018-08-10 17:21:10 140418077017888 [Note] Plugin 'INNODB_FT_BEING_DELETED' is disabled.
 
2018-08-10 17:21:10 140418077017888 [Note] Plugin 'INNODB_FT_DEFAULT_STOPWORD' is disabled.
 
2018-08-10 17:21:10 140418077017888 [Note] Plugin 'INNODB_FT_CONFIG' is disabled.
 
2018-08-10 17:21:10 140418077017888 [Note] Plugin 'INNODB_SYS_TABLESPACES' is disabled.
 
2018-08-10 17:21:10 140418077017888 [Note] Plugin 'INNODB_MUTEXES' is disabled.
 
2018-08-10 17:21:10 140418077017888 [Note] Plugin 'INNODB_SYS_SEMAPHORE_WAITS' is disabled.
 
2018-08-10 17:21:10 140418077017888 [Note] Plugin 'INNODB_LOCK_WAITS' is disabled.
 
2018-08-10 17:21:10 140418077017888 [Note] Plugin 'INNODB_FT_DELETED' is disabled.
 
2018-08-10 17:21:10 140418077017888 [Note] Plugin 'INNODB_TABLESPACES_SCRUBBING' is disabled.
 
2018-08-10 17:21:10 140418077017888 [Warning] /usr/local/mariadb-10.2.17-linux-x86_64/bin/mysqld: unknown option '--loose-pam-debug'
 
2018-08-10 17:21:10 140418077017888 [Note] Recovering after a crash using tc.log
 
2018-08-10 17:21:10 140418077017888 [ERROR] Recovery failed! You must enable all engines that were enabled at the moment of the crash
 
2018-08-10 17:21:10 140418077017888 [ERROR] Crash recovery failed. Either correct the problem (if it's, for example, out of memory error) and restart, or delete tc log and start mysqld with --tc-heuristic-recover={commit|rollback}
 
2018-08-10 17:21:10 140418077017888 [ERROR] Can't init tc log
 
2018-08-10 17:21:10 140418077017888 [ERROR] Aborting
 
 
 
----------SERVER LOG END-------------
 
mysqltest failed but provided no output
 
The result from queries just before the failure was:
 
< snip >
 
drop table if exists t1, t2;
 
CREATE TABLE t1 (a INT PRIMARY KEY) ENGINE=innodb;
 
CREATE TABLE t2 (b INT PRIMARY KEY) ENGINE=tokudb;
 
BEGIN;
 
SELECT @@log_bin;
 
@@log_bin
 
0
 
INSERT INTO t1 VALUES (1);
 
INSERT INTO t2 VALUES (2);
 
SET SESSION debug_dbug="d,crash_commit_before";
 
COMMIT;
 
ERROR HY000: Lost connection to MySQL server during query

Comment by Elena Stepanova [ 2018-08-12 ]

Possibly fixed by the next commit

commit 29150e23912ef6e1fe386f53b778c9a5551c4790 b853b4fd88b441f36eeb7eabdce79918ef10538a
 
Author: Marko Mäkelä <marko.makela@mariadb.com>
 
Date:   Fri Aug 10 17:01:53 2018 +0300
 
 
 
    Revert part of b853b4fd88b441f36eeb7eabdce79918ef10538a
 
    
    recv_parse_log_recs(): Do not check for corruption before
 
    checking for end-of-log-buffer. For some reason, adding the
 
    check to the logical-looking place would cause intermittent
 
    recovery failures in the tests innodb.innodb-index and
 
    innodb_gis.rtree_compress2.

Comment by Marko Mäkelä [ 2019-09-30 ]

The mentioned commit was first released in 10.2.18 and 10.3.10.

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