[MDEV-25946] innodb.log_corruption failed in buildbot Created: 2021-06-17  Updated: 2021-06-17

Status: Open
Project: MariaDB Server
Component/s: Tests
Affects Version/s: 10.6
Fix Version/s: None

Type: Bug Priority: Major
Reporter: Thirunarayanan Balathandayuthapani Assignee: Unassigned
Resolution: Unresolved Votes: 0
Labels: None


 Description   

Failure present in the following link:

http://buildbot.askmonty.org/buildbot/builders/kvm-deb-bionic-ppc64le/builds/6173/steps/mtr/logs/stdio

Errors present in server log file:

 
 
2021-06-16 18:50:54 0 [Note] /usr/sbin/mariadbd (mysqld 10.6.2-MariaDB-1:10.6.2+maria~bionic-log) starting as process 19174 ...
 
2021-06-16 18:50:54 0 [Warning] Could not increase number of max_open_files to more than 1024 (request: 32186)
 
2021-06-16 18:50:54 0 [Warning] Changed limits: max_open_files: 1024  max_connections: 151 (was 151)  table_cache: 421 (was 2000)
 
2021-06-16 18:50:54 0 [Note] Plugin 'partition' is disabled.
 
2021-06-16 18:50:54 0 [Note] Plugin 'SEQUENCE' is disabled.
 
2021-06-16 18:50:54 0 [Note] InnoDB: Compressed tables use zlib 1.2.11
 
2021-06-16 18:50:54 0 [Note] InnoDB: Number of pools: 1
 
2021-06-16 18:50:54 0 [Note] InnoDB: Using POWER8 crc32 instructions
 
2021-06-16 18:50:54 0 [Note] mariadbd: O_TMPFILE is not supported on /dev/shm/var/tmp/3/mysqld.1 (disabling future attempts)
 
2021-06-16 18:50:54 0 [Note] InnoDB: Using Linux native AIO
 
2021-06-16 18:50:54 0 [Note] InnoDB: Initializing buffer pool, total size = 8388608, chunk size = 8388608
 
2021-06-16 18:50:54 0 [Note] InnoDB: Completed initialization of buffer pool
 
2021-06-16 18:50:54 0 [Note] InnoDB: Setting O_DIRECT on file /dev/shm/var/3/tmp/log_corruption/ibdata1 failed
 
2021-06-16 18:50:54 0 [ERROR] InnoDB: Upgrade after a crash is not supported. The redo log was created with MariaDB 10.3.1.
 
2021-06-16 18:50:54 0 [ERROR] InnoDB: Plugin initialization aborted with error Generic error
 
2021-06-16 18:50:54 0 [Note] InnoDB: Starting shutdown...
 
2021-06-16 18:50:54 0 [ERROR] Plugin 'InnoDB' init function returned error.
 
2021-06-16 18:50:54 0 [ERROR] Plugin 'InnoDB' registration as a STORAGE ENGINE failed.
 
2021-06-16 18:50:54 0 [Note] Plugin 'INNODB_FT_CONFIG' is disabled.
 
2021-06-16 18:50:54 0 [Note] Plugin 'INNODB_SYS_TABLESTATS' is disabled.
 
2021-06-16 18:50:54 0 [Note] Plugin 'INNODB_FT_DELETED' is disabled.
 
2021-06-16 18:50:54 0 [Note] Plugin 'INNODB_CMP' is disabled.
 
2021-06-16 18:50:54 0 [Note] Plugin 'THREAD_POOL_WAITS' is disabled.
 
2021-06-16 18:50:54 0 [Note] Plugin 'INNODB_CMP_RESET' is disabled.
 
2021-06-16 18:50:54 0 [Note] Plugin 'THREAD_POOL_QUEUES' is disabled.
 
2021-06-16 18:50:54 0 [Note] Plugin 'FEEDBACK' is disabled.
 
2021-06-16 18:50:54 0 [Note] Plugin 'INNODB_FT_INDEX_TABLE' is disabled.
 
2021-06-16 18:50:54 0 [Note] Plugin 'THREAD_POOL_GROUPS' is disabled.
 
2021-06-16 18:50:54 0 [Note] Plugin 'INNODB_CMP_PER_INDEX_RESET' is disabled.
 
2021-06-16 18:50:54 0 [Note] Plugin 'INNODB_FT_INDEX_CACHE' is disabled.
 
2021-06-16 18:50:54 0 [Note] Plugin 'INNODB_FT_BEING_DELETED' is disabled.
 
2021-06-16 18:50:54 0 [Note] Plugin 'INNODB_CMPMEM_RESET' is disabled.
 
2021-06-16 18:50:54 0 [Note] Plugin 'INNODB_FT_DEFAULT_STOPWORD' is disabled.
 
2021-06-16 18:50:54 0 [Note] Plugin 'INNODB_SYS_TABLESPACES' is disabled.
 
2021-06-16 18:50:54 0 [Note] Plugin 'user_variables' is disabled.
 
2021-06-16 18:50:54 0 [Note] Plugin 'INNODB_TABLESPACES_ENCRYPTION' is disabled.
 
2021-06-16 18:50:54 0 [Note] Plugin 'THREAD_POOL_STATS' is disabled.
 
2021-06-16 18:50:54 0 [Note] Plugin 'unix_socket' is disabled.
 
2021-06-16 18:50:54 0 [Warning] /usr/sbin/mariadbd: unknown variable 'loose-feedback-debug-startup-interval=20'
 
2021-06-16 18:50:54 0 [Warning] /usr/sbin/mariadbd: unknown variable 'loose-feedback-debug-first-interval=60'
 
2021-06-16 18:50:54 0 [Warning] /usr/sbin/mariadbd: unknown variable 'loose-feedback-debug-interval=60'
 
2021-06-16 18:50:54 0 [Warning] /usr/sbin/mariadbd: unknown option '--loose-pam-debug'
 
2021-06-16 18:50:54 0 [Warning] /usr/sbin/mariadbd: unknown option '--loose-aria'
 
2021-06-16 18:50:54 0 [Warning] /usr/sbin/mariadbd: unknown variable 'loose-debug-sync-timeout=300'
 
2021-06-16 18:50:54 0 [Note] Server socket created on IP: '127.0.0.1'.
 
2021-06-16 18:50:54 0 [Note] /usr/sbin/mariadbd: ready for connections.
 
Version: '10.6.2-MariaDB-1:10.6.2+maria~bionic-log'  socket: '/dev/shm/var/tmp/3/mysqld.1.sock'  port: 16020  mariadb.org binary distribution
 
2021-06-16 18:50:54 0 [Note] /usr/sbin/mariadbd (initiated by: root[root] @ localhost []): Normal shutdown
 
2021-06-16 18:50:54 0 [Note] /usr/sbin/mariadbd: Shutdown complete
 
 
 
----------SERVER LOG END-------------
 
 
 
 
 
worker[3] mysql-test-run: *** ERROR: Failed to start mysqld mysqld.1 with command /usr/sbin/mariadbd
 
Error happened at lib/mtr_report.pm line 695.
 
	mtr_report::mtr_error("Failed to start mysqld mysqld.1 with command /usr/sbin/mariadbd") called at mysql-test-run.pl line 5098
 
	main::mysqld_start(My::Config::Group=HASH(0x5b458542718), ARRAY(0x5b458509898)) called at mysql-test-run.pl line 4704
 
	main::check_expected_crash_and_restart("[mysqld.1 - pid: 19071, winpid: 19071, exit: 0]") called at mysql-test-run.pl line 4083
 
	main::run_testcase(My::Test=HASH(0x5b458542e50), IO::Socket::INET=GLOB(0x5b456db3258)) called at mysql-test-run.pl line 962
 
	main::run_worker(57865, 3) called at mysql-test-run.pl line 475
 
	main::main() called at mysql-test-run.pl line 347

log_corruption expects many InnoDB start up failure to happen. Above error log fails with 

2021-06-16 18:50:54 0 [ERROR] InnoDB: Upgrade after a crash is not supported. The redo log was created with MariaDB 10.3.1.
 
2021-06-16 18:50:54 0 [ERROR] InnoDB: Plugin initialization aborted with error Generic error
 
2021-06-16 18:50:54 0 [Note] InnoDB: Starting shutdown...

log_corruption expects this failure to happen:

--let $restart_parameters= $dirs
 
--source include/start_mysqld.inc
 
eval $check_no_innodb;
 
--source include/shutdown_mysqld.inc
 
let SEARCH_PATTERN=\\[ERROR\\] InnoDB: Upgrade after a crash is not supported\. The redo log was created with MariaDB 10\.3\.1\.;
 
--source include/search_pattern_in_file.inc

So it looks like mysql-test-run issue.

 Comments   
Comment by Thirunarayanan Balathandayuthapani [ 2021-06-17 ]

Same kind of error happens for encryption.innodb_encrypt_log_corruption in 10.6
http://buildbot.askmonty.org/buildbot/builders/kvm-fulltest/builds/30706/steps/mtr_ps/logs/stdio

 
 
2021-06-15 13:36:36 0 [Note] /mnt/buildbot/build/mariadb-10.6.2/sql/mariadbd (mysqld 10.6.2-MariaDB-log) starting as process 9647 ...
 
2021-06-15 13:36:36 0 [Warning] Could not increase number of max_open_files to more than 1024 (request: 32186)
 
2021-06-15 13:36:36 0 [Warning] Changed limits: max_open_files: 1024  max_connections: 151 (was 151)  table_cache: 421 (was 2000)
 
2021-06-15 13:36:36 0 [Note] Plugin 'SEQUENCE' is disabled.
 
2021-06-15 13:36:36 0 [Note] Plugin 'partition' is disabled.
 
2021-06-15 13:36:36 0 [Note] InnoDB: Compressed tables use zlib 1.2.11
 
2021-06-15 13:36:36 0 [Note] InnoDB: Number of pools: 1
 
2021-06-15 13:36:36 0 [Note] InnoDB: Using generic crc32 instructions
 
2021-06-15 13:36:36 0 [Note] mariadbd: O_TMPFILE is not supported on /mnt/buildbot/build/mariadb-10.6.2/mysql-test/var/tmp/1/mysqld.1 (disabling future attempts)
 
2021-06-15 13:36:36 0 [Note] InnoDB: Using Linux native AIO
 
2021-06-15 13:36:36 0 [Note] InnoDB: Initializing buffer pool, total size = 8388608, chunk size = 8388608
 
2021-06-15 13:36:36 0 [Note] InnoDB: Completed initialization of buffer pool
 
2021-06-15 13:36:36 0 [Note] InnoDB: Setting O_DIRECT on file /mnt/buildbot/build/mariadb-10.6.2/mysql-test/var/1/tmp/log_corruption/ibdata1 failed
 
2021-06-15 13:36:36 0 [ERROR] InnoDB: Log file /mnt/buildbot/build/mariadb-10.6.2/mysql-test/var/1/tmp/log_corruption/ib_logfile1 is of different size 1048576 bytes than other log files 2097152 bytes!
 
2021-06-15 13:36:36 0 [ERROR] InnoDB: Upgrade after a crash is not supported. The redo log was created with BogoDB 1.2.3.4, and it appears corrupted.
 
2021-06-15 13:36:36 0 [ERROR] InnoDB: Plugin initialization aborted with error Data structure corruption
 
2021-06-15 13:36:36 0 [Note] InnoDB: Starting shutdown...
 
2021-06-15 13:36:36 0 [ERROR] Plugin 'InnoDB' init function returned error.
 
2021-06-15 13:36:36 0 [ERROR] Plugin 'InnoDB' registration as a STORAGE ENGINE failed.
 
2021-06-15 13:36:36 0 [Note] Plugin 'INNODB_FT_CONFIG' is disabled.
 
2021-06-15 13:36:36 0 [Note] Plugin 'INNODB_SYS_TABLESTATS' is disabled.
 
2021-06-15 13:36:36 0 [Note] Plugin 'INNODB_FT_DELETED' is disabled.
 
2021-06-15 13:36:36 0 [Note] Plugin 'INNODB_CMP' is disabled.
 
2021-06-15 13:36:36 0 [Note] Plugin 'THREAD_POOL_WAITS' is disabled.
 
2021-06-15 13:36:36 0 [Note] Plugin 'INNODB_CMP_RESET' is disabled.
 
2021-06-15 13:36:36 0 [Note] Plugin 'THREAD_POOL_QUEUES' is disabled.
 
2021-06-15 13:36:36 0 [Note] Plugin 'FEEDBACK' is disabled.
 
2021-06-15 13:36:36 0 [Note] Plugin 'INNODB_FT_INDEX_TABLE' is disabled.
 
2021-06-15 13:36:36 0 [Note] Plugin 'THREAD_POOL_GROUPS' is disabled.
 
2021-06-15 13:36:36 0 [Note] Plugin 'INNODB_CMP_PER_INDEX_RESET' is disabled.
 
2021-06-15 13:36:36 0 [Note] Plugin 'INNODB_FT_INDEX_CACHE' is disabled.
 
2021-06-15 13:36:36 0 [Note] Plugin 'INNODB_FT_BEING_DELETED' is disabled.
 
2021-06-15 13:36:36 0 [Note] Plugin 'INNODB_CMPMEM_RESET' is disabled.
 
2021-06-15 13:36:36 0 [Note] Plugin 'INNODB_FT_DEFAULT_STOPWORD' is disabled.
 
2021-06-15 13:36:36 0 [Note] Plugin 'INNODB_SYS_TABLESPACES' is disabled.
 
2021-06-15 13:36:36 0 [Note] Plugin 'user_variables' is disabled.
 
2021-06-15 13:36:36 0 [Note] Plugin 'INNODB_TABLESPACES_ENCRYPTION' is disabled.
 
2021-06-15 13:36:36 0 [Note] Plugin 'THREAD_POOL_STATS' is disabled.
 
2021-06-15 13:36:36 0 [Note] Plugin 'unix_socket' is disabled.
 
2021-06-15 13:36:36 0 [Warning] /mnt/buildbot/build/mariadb-10.6.2/sql/mariadbd: unknown variable 'loose-feedback-debug-startup-interval=20'
 
2021-06-15 13:36:36 0 [Warning] /mnt/buildbot/build/mariadb-10.6.2/sql/mariadbd: unknown variable 'loose-feedback-debug-first-interval=60'
 
2021-06-15 13:36:36 0 [Warning] /mnt/buildbot/build/mariadb-10.6.2/sql/mariadbd: unknown variable 'loose-feedback-debug-interval=60'
 
2021-06-15 13:36:36 0 [Warning] /mnt/buildbot/build/mariadb-10.6.2/sql/mariadbd: unknown option '--loose-pam-debug'
 
2021-06-15 13:36:36 0 [Warning] /mnt/buildbot/build/mariadb-10.6.2/sql/mariadbd: unknown option '--loose-aria'
 
2021-06-15 13:36:36 0 [Warning] /mnt/buildbot/build/mariadb-10.6.2/sql/mariadbd: unknown variable 'loose-debug-sync-timeout=300'
 
2021-06-15 13:36:36 0 [Note] Server socket created on IP: '127.0.0.1'.
 
2021-06-15 13:36:36 0 [Note] /mnt/buildbot/build/mariadb-10.6.2/sql/mariadbd: ready for connections.
 
Version: '10.6.2-MariaDB-log'  socket: '/mnt/buildbot/build/mariadb-10.6.2/mysql-test/var/tmp/1/mysqld.1.sock'  port: 16020  MariaDB Server
 
2021-06-15 13:36:36 0 [Note] /mnt/buildbot/build/mariadb-10.6.2/sql/mariadbd (initiated by: root[root] @ localhost []): Normal shutdown
 
2021-06-15 13:36:36 0 [Note] /mnt/buildbot/build/mariadb-10.6.2/sql/mariadbd: Shutdown complete
 
 
 
----------SERVER LOG END-------------
 
 
 
 
 
worker[1] mysql-test-run: *** ERROR: Failed to start mysqld mysqld.1 with command /mnt/buildbot/build/mariadb-10.6.2/sql/mariadbd
 
Error happened at lib/mtr_report.pm line 695.
 
	mtr_report::mtr_error("Failed to start mysqld mysqld.1 with command /mnt/buildbot/bu"...) called at mysql-test-run.pl line 5098
 
	main::mysqld_start(My::Config::Group=HASH(0x202d7f0), ARRAY(0x228ce88)) called at mysql-test-run.pl line 4704
 
	main::check_expected_crash_and_restart("[mysqld.1 - pid: 9575, winpid: 9575, exit: 0]") called at mysql-test-run.pl line 4083
 
	main::run_testcase(My::Test=HASH(0x1fa2bc8), IO::Socket::INET=GLOB(0x2b999e8)) called at mysql-test-run.pl line 962
 
	main::run_worker(56549, 1) called at mysql-test-run.pl line 475
 
	main::main() called at mysql-test-run.pl line 347

Generated at Thu Feb 08 09:41:36 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.