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

11.4.2 breaks beyond repair the ib_logfile0 after restart

    XMLWordPrintable

Details

    • Bug
    • Status: Closed (View Workflow)
    • Major
    • Resolution: Duplicate
    • 11.4.2
    • 10.11.9
    • None
    • MacOS Sonoma 14.5 (23F79), Homebrew version of MariaDB 11.4.2

    Description

      Without making any other changes, I just updated MariaDB from 11.3.2 to 11.4.2 and after the restart my database got broken. Initially I thought the problem lies in the update process, but then I managed to reproduce the issue on a clean 11.4.2.

      Steps to reproduce :

      1. Install a fresh 11.4.2 or just delete the db files and do mariadb-install-db, doesn't matter (At this stage the DB works even after stopping and starting it back).
      2. Any kind of small operations like creating/removing users etc are fine (still works after stop and start)
      3. Import some big SQL file (a 2GB database dump in my case).

      After doing the above and without stopping the database - it continues to work properly, BUT once I stop it and start it back I get this (this is the full log, one successful start, then shutdown and then the failure) :

      240610 16:13:02 mysqld_safe Starting mariadbd daemon with databases from /opt/homebrew/var/mysql
      2024-06-10 16:13:02 0 [Warning] Setting lower_case_table_names=2 because file system for /opt/homebrew/var/mysql/ is case insensitive
      2024-06-10 16:13:02 0 [Note] Starting MariaDB 11.4.2-MariaDB source revision 3fca5ed772fb75e3e57c507edef2985f8eba5b12 as process 17229
      2024-06-10 16:13:02 0 [Note] InnoDB: Compressed tables use zlib 1.2.12
      2024-06-10 16:13:02 0 [Note] InnoDB: Number of transaction pools: 1
      2024-06-10 16:13:02 0 [Note] InnoDB: Using generic crc32 instructions
      2024-06-10 16:13:02 0 [Note] InnoDB: Initializing buffer pool, total size = 128.000MiB, chunk size = 2.000MiB
      2024-06-10 16:13:02 0 [Note] InnoDB: Completed initialization of buffer pool
      2024-06-10 16:13:02 0 [Note] InnoDB: End of log at LSN=47695
      2024-06-10 16:13:02 0 [Note] InnoDB: Opened 3 undo tablespaces
      2024-06-10 16:13:02 0 [Note] InnoDB: 128 rollback segments in 3 undo tablespaces are active.
      2024-06-10 16:13:02 0 [Note] InnoDB: Setting file './ibtmp1' size to 12.000MiB. Physically writing the file full; Please wait ...
      2024-06-10 16:13:02 0 [Note] InnoDB: File './ibtmp1' size is now 12.000MiB.
      2024-06-10 16:13:02 0 [Note] InnoDB: log sequence number 47695; transaction id 14
      2024-06-10 16:13:02 0 [Note] InnoDB: Loading buffer pool(s) from /opt/Homebrew/var/mysql/ib_buffer_pool
      2024-06-10 16:13:02 0 [Note] Plugin 'FEEDBACK' is disabled.
      2024-06-10 16:13:02 0 [Note] Plugin 'wsrep-provider' is disabled.
      2024-06-10 16:13:02 0 [Note] InnoDB: Buffer pool(s) load completed at 240610 16:13:02
      2024-06-10 16:13:03 0 [Note] Server socket created on IP: '127.0.0.1'.
      2024-06-10 16:13:03 0 [Warning] 'user' entry '@joro.home' ignored in --skip-name-resolve mode.
      2024-06-10 16:13:03 0 [Warning] 'proxies_priv' entry '@% joro@joro.home' ignored in --skip-name-resolve mode.
      2024-06-10 16:13:03 0 [Note] mariadbd: Event Scheduler: Loaded 0 events
      2024-06-10 16:13:03 0 [Note] /opt/homebrew/opt/mariadb/bin/mariadbd: ready for connections.
      Version: '11.4.2-MariaDB'  socket: '/tmp/mysql.sock'  port: 3306  Homebrew
      2024-06-10 16:57:35 0 [Note] /opt/homebrew/opt/mariadb/bin/mariadbd (initiated by: unknown): Normal shutdown
      2024-06-10 16:57:35 0 [Note] InnoDB: FTS optimize thread exiting.
      2024-06-10 16:57:35 0 [Note] InnoDB: Starting shutdown...
      2024-06-10 16:57:35 0 [Note] InnoDB: Dumping buffer pool(s) to /opt/Homebrew/var/mysql/ib_buffer_pool
      2024-06-10 16:57:35 0 [Note] InnoDB: Restricted to 2000 pages due to innodb_buf_pool_dump_pct=25
      2024-06-10 16:57:35 0 [Note] InnoDB: Buffer pool(s) dump completed at 240610 16:57:35
      2024-06-10 16:57:36 0 [Note] InnoDB: Removed temporary tablespace data file: "./ibtmp1"
      2024-06-10 16:57:36 0 [Note] InnoDB: Shutdown completed; log sequence number 10514036011; transaction id 105174
      2024-06-10 16:57:36 0 [Note] /opt/homebrew/opt/mariadb/bin/mariadbd: Shutdown complete
       
      240610 16:57:40 mysqld_safe Starting mariadbd daemon with databases from /opt/homebrew/var/mysql
      2024-06-10 16:57:40 0 [Warning] Setting lower_case_table_names=2 because file system for /opt/homebrew/var/mysql/ is case insensitive
      2024-06-10 16:57:40 0 [Note] Starting MariaDB 11.4.2-MariaDB source revision 3fca5ed772fb75e3e57c507edef2985f8eba5b12 as process 20792
      2024-06-10 16:57:40 0 [Note] InnoDB: Compressed tables use zlib 1.2.12
      2024-06-10 16:57:40 0 [Note] InnoDB: Number of transaction pools: 1
      2024-06-10 16:57:40 0 [Note] InnoDB: Using generic crc32 instructions
      2024-06-10 16:57:40 0 [Note] InnoDB: Initializing buffer pool, total size = 128.000MiB, chunk size = 2.000MiB
      2024-06-10 16:57:40 0 [Note] InnoDB: Completed initialization of buffer pool
      2024-06-10 16:57:40 0 [ERROR] InnoDB: Missing FILE_CHECKPOINT(10514035995) at 10514035995
      2024-06-10 16:57:40 0 [ERROR] InnoDB: Log scan aborted at LSN 10514035995
      2024-06-10 16:57:40 0 [ERROR] InnoDB: Plugin initialization aborted with error Generic error
      2024-06-10 16:57:40 0 [Note] InnoDB: Starting shutdown...
      2024-06-10 16:57:40 0 [ERROR] Plugin 'InnoDB' registration as a STORAGE ENGINE failed.
      2024-06-10 16:57:40 0 [Note] Plugin 'FEEDBACK' is disabled.
      2024-06-10 16:57:40 0 [Note] Plugin 'wsrep-provider' is disabled.
      2024-06-10 16:57:40 0 [ERROR] Unknown/unsupported storage engine: InnoDB
      2024-06-10 16:57:40 0 [ERROR] Aborting
      240610 16:57:40 mysqld_safe mysqld from pid file /opt/homebrew/var/mysql/joro.home.pid ended
      

      My config file is :

      [client]
      port=3306
       
      [mysqld]
      sql-mode="ERROR_FOR_DIVISION_BY_ZERO,NO_AUTO_CREATE_USER,NO_ENGINE_SUBSTITUTION"
      skip-name-resolve
      skip-host-cache
      character_set_server            = utf8mb4
      collation_server                = utf8mb4_unicode_ci
       
      bind-address=127.0.0.1
      port=3306
      

      I tried this many times with different configurations but same result. My feeling is the problem arises when :
      1. The ib_logfile0 get's filled with data
      2. The database gets shut down.

      Restarting before the ib_logfile0 gets filled in looks to do no damage. Once it gets broken, only innodb_force_recovery=6 allows it to start and I'm able to dump data from it, BUT in some cases only the indexes are damaged, in others - there is real data loss.

      Update : reverted to 11.3.2 - problem gone, everything works fine.

      Attachments

        Issue Links

          Activity

            People

              Gosselin Dave Gosselin
              joro_abv Georgi Georgiev
              Votes:
              0 Vote for this issue
              Watchers:
              9 Start watching this issue

              Dates

                Created:
                Updated:
                Resolved:

                Git Integration

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