Uploaded image for project: 'MariaDB Server'
  1. MariaDB Server
  2. MDEV-34566

InnoDB: Crash recovery is broken due to insufficient innodb_log_file_size (but wasn't in crash recovery)

    XMLWordPrintable

Details

    Description

      In attempting the MDEV-34480 test case on x86_64 got the following rather different error:

      10.11.9-579450c2c10b867347612efaf67bdce3c88504cd

      $ docker-compose  -f sysbench.yml up
      Creating network "examples_default" with the default driver
      Creating examples_mariadb_1 ... done
      Creating examples_sysbench_1 ... done
      Attaching to examples_mariadb_1, examples_sysbench_1
      mariadb_1   | 2024-07-11 03:44:46+00:00 [Note] [Entrypoint]: Entrypoint script for MariaDB Server 1:10.11.9+maria~ubu2204 started.
      mariadb_1   | 2024-07-11 03:44:46+00:00 [Warn] [Entrypoint]: /sys/fs/cgroup///memory.pressure not writable, functionality unavailable to MariaDB
      mariadb_1   | 2024-07-11 03:44:46+00:00 [Note] [Entrypoint]: Switching to dedicated user 'mysql'
      mariadb_1   | 2024-07-11 03:44:46+00:00 [Note] [Entrypoint]: Entrypoint script for MariaDB Server 1:10.11.9+maria~ubu2204 started.
      sysbench_1  | sysbench 1.0.20 (using bundled LuaJIT 2.1.0-beta2)
      sysbench_1  | 
      mariadb_1   | 2024-07-11 03:44:47+00:00 [Note] [Entrypoint]: Initializing database files
      mariadb_1   | 2024-07-11  3:44:47 0 [Warning] mariadbd: io_uring_queue_init() failed with ENOSYS: check seccomp filters, and the kernel version (newer than 5.1 required)
      mariadb_1   | 2024-07-11  3:44:47 0 [Warning] InnoDB: liburing disabled: falling back to innodb_use_native_aio=OFF
      mariadb_1   | 
      mariadb_1   | 
      mariadb_1   | PLEASE REMEMBER TO SET A PASSWORD FOR THE MariaDB root USER !
      mariadb_1   | To do so, start the server, then issue the following command:
      mariadb_1   | 
      mariadb_1   | '/usr/bin/mariadb-secure-installation'
      mariadb_1   | 
      mariadb_1   | which will also give you the option of removing the test
      mariadb_1   | databases and anonymous user created by default.  This is
      mariadb_1   | strongly recommended for production servers.
      mariadb_1   | 
      mariadb_1   | See the MariaDB Knowledgebase at https://mariadb.com/kb
      mariadb_1   | 
      mariadb_1   | Please report any problems at https://mariadb.org/jira
      mariadb_1   | 
      mariadb_1   | The latest information about MariaDB is available at https://mariadb.org/.
      mariadb_1   | 
      mariadb_1   | Consider joining MariaDB's strong and vibrant community:
      mariadb_1   | https://mariadb.org/get-involved/
      mariadb_1   | 
      mariadb_1   | 2024-07-11 03:44:48+00:00 [Note] [Entrypoint]: Database files initialized
      mariadb_1   | 2024-07-11 03:44:48+00:00 [Note] [Entrypoint]: Starting temporary server
      mariadb_1   | 2024-07-11 03:44:48+00:00 [Note] [Entrypoint]: Waiting for server startup
      mariadb_1   | 2024-07-11  3:44:48 0 [Note] Starting MariaDB 10.11.9-MariaDB-ubu2204 source revision 579450c2c10b867347612efaf67bdce3c88504cd server_uid AtcIAvqttVxNAphjlIHva3JYv+M= as process 95
      mariadb_1   | 2024-07-11  3:44:48 0 [Note] InnoDB: Compressed tables use zlib 1.2.11
      mariadb_1   | 2024-07-11  3:44:48 0 [Note] InnoDB: Number of transaction pools: 1
      mariadb_1   | 2024-07-11  3:44:48 0 [Note] InnoDB: Using AVX512 instructions
      mariadb_1   | 2024-07-11  3:44:48 0 [Note] mariadbd: O_TMPFILE is not supported on /tmp (disabling future attempts)
      mariadb_1   | 2024-07-11  3:44:48 0 [Warning] mariadbd: io_uring_queue_init() failed with ENOSYS: check seccomp filters, and the kernel version (newer than 5.1 required)
      mariadb_1   | 2024-07-11  3:44:48 0 [Warning] InnoDB: liburing disabled: falling back to innodb_use_native_aio=OFF
      sysbench_1  | Initializing worker threads...
      sysbench_1  | 
      mariadb_1   | 2024-07-11  3:44:48 0 [Note] InnoDB: Initializing buffer pool, total size = 5.000GiB, chunk size = 80.000MiB
      mariadb_1   | 2024-07-11  3:44:48 0 [Note] InnoDB: Completed initialization of buffer pool
      mariadb_1   | 2024-07-11  3:44:48 0 [Note] InnoDB: Buffered log writes (block size=512 bytes)
      mariadb_1   | 2024-07-11  3:44:48 0 [Note] InnoDB: End of log at LSN=45518
      mariadb_1   | 2024-07-11  3:44:48 0 [Note] InnoDB: 128 rollback segments are active.
      mariadb_1   | 2024-07-11  3:44:48 0 [Note] InnoDB: Setting file './ibtmp1' size to 12.000MiB. Physically writing the file full; Please wait ...
      mariadb_1   | 2024-07-11  3:44:48 0 [Note] InnoDB: File './ibtmp1' size is now 12.000MiB.
      mariadb_1   | 2024-07-11  3:44:48 0 [Note] InnoDB: log sequence number 45518; transaction id 14
      mariadb_1   | 2024-07-11  3:44:48 0 [Note] Plugin 'FEEDBACK' is disabled.
      mariadb_1   | 2024-07-11  3:44:48 0 [Warning] 'user' entry 'root@63dcb57155de' ignored in --skip-name-resolve mode.
      mariadb_1   | 2024-07-11  3:44:48 0 [Warning] 'proxies_priv' entry '@% root@63dcb57155de' ignored in --skip-name-resolve mode.
      mariadb_1   | 2024-07-11  3:44:48 0 [Note] mariadbd: ready for connections.
      mariadb_1   | Version: '10.11.9-MariaDB-ubu2204'  socket: '/run/mysqld/mysqld.sock'  port: 0  mariadb.org binary distribution
      mariadb_1   | 2024-07-11 03:44:49+00:00 [Note] [Entrypoint]: Temporary server started.
      mariadb_1   | 2024-07-11 03:44:49+00:00 [Note] [Entrypoint]: GENERATED ROOT PASSWORD: Q_Tax=k!Vk#1KAD42./ZhAHGu|P$>1Ig
      mariadb_1   | 2024-07-11 03:44:49+00:00 [Note] [Entrypoint]: Creating database testdb
      mariadb_1   | 2024-07-11 03:44:49+00:00 [Note] [Entrypoint]: Creating user testuser
      mariadb_1   | 2024-07-11 03:44:49+00:00 [Note] [Entrypoint]: Giving user testuser access to schema testdb
      mariadb_1   | 2024-07-11 03:44:49+00:00 [Note] [Entrypoint]: Securing system users (equivalent to running mysql_secure_installation)
      mariadb_1   | 
      mariadb_1   | 2024-07-11 03:44:49+00:00 [Note] [Entrypoint]: Stopping temporary server
      mariadb_1   | 2024-07-11  3:44:49 0 [Note] mariadbd (initiated by: unknown): Normal shutdown
      mariadb_1   | 2024-07-11  3:44:49 0 [Note] InnoDB: FTS optimize thread exiting.
      mariadb_1   | 2024-07-11  3:44:49 0 [Note] InnoDB: Starting shutdown...
      mariadb_1   | 2024-07-11  3:44:49 0 [Note] InnoDB: Dumping buffer pool(s) to /var/lib/mysql/ib_buffer_pool
      mariadb_1   | 2024-07-11  3:44:49 0 [Note] InnoDB: Buffer pool(s) dump completed at 240711  3:44:49
      mariadb_1   | 2024-07-11  3:44:50 0 [Note] InnoDB: Removed temporary tablespace data file: "./ibtmp1"
      mariadb_1   | 2024-07-11  3:44:50 0 [Note] InnoDB: Shutdown completed; log sequence number 47108; transaction id 15
      mariadb_1   | 2024-07-11  3:44:50 0 [Note] mariadbd: Shutdown complete
      mariadb_1   | 
      mariadb_1   | 2024-07-11 03:44:50+00:00 [Note] [Entrypoint]: Temporary server stopped
      mariadb_1   | 
      mariadb_1   | 2024-07-11 03:44:50+00:00 [Note] [Entrypoint]: MariaDB init process done. Ready for start up.
      mariadb_1   | 
      mariadb_1   | 2024-07-11  3:44:50 0 [Note] Starting MariaDB 10.11.9-MariaDB-ubu2204 source revision 579450c2c10b867347612efaf67bdce3c88504cd server_uid AtcIAvqttVxNAphjlIHva3JYv+M= as process 1
      mariadb_1   | 2024-07-11  3:44:50 0 [Note] InnoDB: Compressed tables use zlib 1.2.11
      mariadb_1   | 2024-07-11  3:44:50 0 [Note] InnoDB: Number of transaction pools: 1
      mariadb_1   | 2024-07-11  3:44:50 0 [Note] InnoDB: Using AVX512 instructions
      mariadb_1   | 2024-07-11  3:44:50 0 [Note] mariadbd: O_TMPFILE is not supported on /tmp (disabling future attempts)
      mariadb_1   | 2024-07-11  3:44:50 0 [Warning] mariadbd: io_uring_queue_init() failed with ENOSYS: check seccomp filters, and the kernel version (newer than 5.1 required)
      mariadb_1   | 2024-07-11  3:44:50 0 [Warning] InnoDB: liburing disabled: falling back to innodb_use_native_aio=OFF
      mariadb_1   | 2024-07-11  3:44:50 0 [Note] InnoDB: Initializing buffer pool, total size = 5.000GiB, chunk size = 80.000MiB
      mariadb_1   | 2024-07-11  3:44:50 0 [Note] InnoDB: Completed initialization of buffer pool
      mariadb_1   | 2024-07-11  3:44:50 0 [Note] InnoDB: Buffered log writes (block size=512 bytes)
      mariadb_1   | 2024-07-11  3:44:50 0 [Note] InnoDB: End of log at LSN=47108
      mariadb_1   | 2024-07-11  3:44:50 0 [Note] InnoDB: 128 rollback segments are active.
      mariadb_1   | 2024-07-11  3:44:50 0 [Note] InnoDB: Setting file './ibtmp1' size to 12.000MiB. Physically writing the file full; Please wait ...
      mariadb_1   | 2024-07-11  3:44:50 0 [Note] InnoDB: File './ibtmp1' size is now 12.000MiB.
      mariadb_1   | 2024-07-11  3:44:50 0 [Note] InnoDB: log sequence number 47108; transaction id 16
      mariadb_1   | 2024-07-11  3:44:50 0 [Note] InnoDB: Loading buffer pool(s) from /var/lib/mysql/ib_buffer_pool
      mariadb_1   | 2024-07-11  3:44:50 0 [Note] Plugin 'FEEDBACK' is disabled.
      mariadb_1   | 2024-07-11  3:44:50 0 [Warning] You need to use --log-bin to make --expire-logs-days or --binlog-expire-logs-seconds work.
      mariadb_1   | 2024-07-11  3:44:50 0 [Note] InnoDB: Buffer pool(s) load completed at 240711  3:44:50
      mariadb_1   | 2024-07-11  3:44:50 0 [Note] Server socket created on IP: '0.0.0.0'.
      mariadb_1   | 2024-07-11  3:44:50 0 [Note] Server socket created on IP: '::'.
      mariadb_1   | 2024-07-11  3:44:50 0 [Note] mariadbd: ready for connections.
      mariadb_1   | Version: '10.11.9-MariaDB-ubu2204'  socket: '/run/mysqld/mysqld.sock'  port: 3306  mariadb.org binary distribution
      sysbench_1  | Creating table 'sbtest5'...
      sysbench_1  | Creating table 'sbtest18'...
      sysbench_1  | Creating table 'sbtest2'...
      sysbench_1  | Creating table 'sbtest26'...
      sysbench_1  | Creating table 'sbtest7'...
      sysbench_1  | Creating table 'sbtest15'...
      sysbench_1  | Creating table 'sbtest22'...
      sysbench_1  | Creating table 'sbtest17'...
      sysbench_1  | Creating table 'sbtest20'...
      sysbench_1  | Creating table 'sbtest29'...
      sysbench_1  | Creating table 'sbtest1'...
      sysbench_1  | Creating table 'sbtest6'...
      sysbench_1  | Creating table 'sbtest21'...
      sysbench_1  | Creating table 'sbtest23'...
      sysbench_1  | Creating table 'sbtest10'...
      sysbench_1  | Creating table 'sbtest9'...
      sysbench_1  | Creating table 'sbtest13'...
      sysbench_1  | Creating table 'sbtest3'...
      sysbench_1  | Creating table 'sbtest28'...
      sysbench_1  | Creating table 'sbtest19'...
      sysbench_1  | Creating table 'sbtest11'...
      sysbench_1  | Creating table 'sbtest12'...
      sysbench_1  | Creating table 'sbtest14'...
      sysbench_1  | Creating table 'sbtest4'...
      sysbench_1  | Creating table 'sbtest25'...
      sysbench_1  | Creating table 'sbtest16'...
      sysbench_1  | Creating table 'sbtest8'...
      sysbench_1  | Creating table 'sbtest27'...
      sysbench_1  | Creating table 'sbtest24'...
      sysbench_1  | Creating table 'sbtest30'...
      sysbench_1  | Inserting 10000000 records into 'sbtest7'
      sysbench_1  | Inserting 10000000 records into 'sbtest5'
      sysbench_1  | Inserting 10000000 records into 'sbtest1'
      sysbench_1  | Inserting 10000000 records into 'sbtest26'
      sysbench_1  | Inserting 10000000 records into 'sbtest18'
      sysbench_1  | Inserting 10000000 records into 'sbtest17'
      sysbench_1  | Inserting 10000000 records into 'sbtest20'
      sysbench_1  | Inserting 10000000 records into 'sbtest22'
      sysbench_1  | Inserting 10000000 records into 'sbtest29'
      sysbench_1  | Inserting 10000000 records into 'sbtest21'
      sysbench_1  | Inserting 10000000 records into 'sbtest6'
      sysbench_1  | Inserting 10000000 records into 'sbtest9'
      sysbench_1  | Inserting 10000000 records into 'sbtest23'
      sysbench_1  | Inserting 10000000 records into 'sbtest3'
      sysbench_1  | Inserting 10000000 records into 'sbtest10'
      sysbench_1  | Inserting 10000000 records into 'sbtest28'
      sysbench_1  | Inserting 10000000 records into 'sbtest14'
      sysbench_1  | Inserting 10000000 records into 'sbtest19'
      sysbench_1  | Inserting 10000000 records into 'sbtest11'
      sysbench_1  | Inserting 10000000 records into 'sbtest12'
      sysbench_1  | Inserting 10000000 records into 'sbtest25'
      sysbench_1  | Inserting 10000000 records into 'sbtest4'
      sysbench_1  | Inserting 10000000 records into 'sbtest8'
      sysbench_1  | Inserting 10000000 records into 'sbtest27'
      sysbench_1  | Inserting 10000000 records into 'sbtest16'
      sysbench_1  | Inserting 10000000 records into 'sbtest24'
      sysbench_1  | Inserting 10000000 records into 'sbtest13'
      sysbench_1  | Inserting 10000000 records into 'sbtest15'
      sysbench_1  | Inserting 10000000 records into 'sbtest30'
      sysbench_1  | Inserting 10000000 records into 'sbtest2'
       sysbench_1  | Creating a secondary index on 'sbtest19'...
      sysbench_1  | Creating a secondary index on 'sbtest23'...
      sysbench_1  | Creating a secondary index on 'sbtest15'...
      sysbench_1  | Creating a secondary index on 'sbtest10'...
      sysbench_1  | Creating a secondary index on 'sbtest14'...
      sysbench_1  | Creating a secondary index on 'sbtest22'...
      sysbench_1  | Creating a secondary index on 'sbtest8'...
      sysbench_1  | Creating a secondary index on 'sbtest11'...
      sysbench_1  | Creating a secondary index on 'sbtest12'...
      sysbench_1  | Creating a secondary index on 'sbtest3'...
      sysbench_1  | Creating a secondary index on 'sbtest30'...
      sysbench_1  | Creating a secondary index on 'sbtest28'...
      sysbench_1  | Creating a secondary index on 'sbtest25'...
      sysbench_1  | Creating a secondary index on 'sbtest1'...
      sysbench_1  | Creating a secondary index on 'sbtest29'...
      sysbench_1  | Creating a secondary index on 'sbtest18'...
      sysbench_1  | Creating a secondary index on 'sbtest2'...
      sysbench_1  | Creating a secondary index on 'sbtest9'...
      sysbench_1  | Creating a secondary index on 'sbtest24'...
      sysbench_1  | Creating a secondary index on 'sbtest27'...
      sysbench_1  | Creating a secondary index on 'sbtest17'...
      sysbench_1  | Creating a secondary index on 'sbtest16'...
      sysbench_1  | Creating a secondary index on 'sbtest13'...
      sysbench_1  | Creating a secondary index on 'sbtest6'...
      sysbench_1  | Creating a secondary index on 'sbtest7'...
      sysbench_1  | Creating a secondary index on 'sbtest21'...
      sysbench_1  | Creating a secondary index on 'sbtest5'...
      sysbench_1  | Creating a secondary index on 'sbtest20'...
      sysbench_1  | Creating a secondary index on 'sbtest4'...
      sysbench_1  | Creating a secondary index on 'sbtest26'...
      mariadb_1   | 2024-07-11  3:56:24 0 [ERROR] InnoDB: Crash recovery is broken due to insufficient innodb_log_file_size; last checkpoint LSN=79013366993, current LSN=79103952908.
      mariadb_1   | 2024-07-11  3:56:29 18 [Note] InnoDB: Crash recovery was broken between LSN=79103952908 and checkpoint LSN=79014152603.
      examples_sysbench_1 exited with code 0
       
      $ podman exec  examples_mariadb_1 ls -la /var/lib/mysql
      total 336492
      drwxr-xr-x. 6 mysql mysql      4096 Jul 11 03:44 .
      drwxr-xr-x. 1 root  root       4096 Jul 10 01:48 ..
      -rw-------. 1 mysql mysql       118 Jul 11 03:44 .my-healthcheck.cnf
      -rw-rw----. 1 mysql mysql  16932864 Jul 11 03:44 aria_log.00000001
      -rw-rw----. 1 mysql mysql        52 Jul 11 03:44 aria_log_control
      -rw-rw----. 1 mysql mysql    372736 Jul 11 03:57 ddl_recovery.log
      -rw-rw----. 1 mysql mysql       838 Jul 11 03:44 ib_buffer_pool
      -rw-rw----. 1 mysql mysql 100663296 Jul 11 03:57 ib_logfile0
      -rw-rw----. 1 mysql mysql 213909504 Jul 11 03:57 ibdata1
      -rw-rw----. 1 mysql mysql  12582912 Jul 11 03:45 ibtmp1
      -rw-rw----. 1 mysql mysql         0 Jul 11 03:44 multi-master.info
      drwx------. 2 mysql mysql      4096 Jul 11 03:44 mysql
      -rw-r--r--. 1 mysql mysql        15 Jul 11 03:44 mysql_upgrade_info
      drwx------. 2 mysql mysql      4096 Jul 11 03:44 performance_schema
      drwx------. 2 mysql mysql     12288 Jul 11 03:44 sys
      drwx------. 2 mysql mysql      4096 Jul 11 03:57 testdb
      

      There's no missing MariaDB logs from output.

      Attachments

        Issue Links

          Activity

            People

              danblack Daniel Black
              danblack Daniel Black
              Votes:
              0 Vote for this issue
              Watchers:
              3 Start watching this issue

              Dates

                Created:
                Updated:

                Git Integration

                  Error rendering 'com.xiplink.jira.git.jira_git_plugin:git-issue-webpanel'. Please contact your Jira administrators.