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

InnoDB crashes on service restart, next restart all healthy again

Details

    Description

      The only change in mariadb.cnf is to remove a node from wsrep_cluster_address, restarted mariadb.service and InnoDB crashes, another service restart and all is healthy again. Not a lot of changes, running IST on both restarts.

      LOGS:
      {{
      2025-01-22 14:20:46 0 [Note] WSREP: Shifting PRIMARY -> JOINER (TO: 221932521)
      2025-01-22 14:20:46 1 [Note] WSREP: Requesting state transfer: success, donor: 1
      WSREP_SST: [INFO] 'xtrabackup_ist' received from donor: Running IST (20250122 14:20:47.318)
      (...)
      2025-01-22 14:20:47 3 [Note] WSREP: SST received
      2025-01-22 14:20:47 3 [Note] WSREP: Server status change joiner -> initializing
      2025-01-22 14:20:47 0 [Note] InnoDB: Compressed tables use zlib 1.2.11
      2025-01-22 14:20:47 0 [Note] InnoDB: Number of transaction pools: 1
      2025-01-22 14:20:47 0 [Note] InnoDB: Using crc32 + pclmulqdq instructions
      2025-01-22 14:20:47 0 [Note] InnoDB: Initializing buffer pool, total size = 2.864GiB, chunk size = 45.828MiB
      2025-01-22 14:20:47 0 [Note] InnoDB: Initialized memory pressure event listener
      2025-01-22 14:20:47 0 [Note] InnoDB: Completed initialization of buffer pool
      2025-01-22 14:20:47 0 [Note] InnoDB: File system buffers for log disabled (block size=512 bytes)
      2025-01-22 14:20:47 0 [Warning] InnoDB: Retry attempts for reading partial data failed.
      2025-01-22 14:20:47 0 [ERROR] InnoDB: Failed to read log at 40964608: I/O error
      2025-01-22 14:20:47 0 [ERROR] InnoDB: Plugin initialization aborted with error Generic error
      2025-01-22 14:20:47 0 [Note] InnoDB: Starting shutdown...
      2025-01-22 14:20:47 0 [ERROR] Plugin 'InnoDB' registration as a STORAGE ENGINE failed.
      2025-01-22 14:20:47 0 [Note] Plugin 'FEEDBACK' is disabled.
      2025-01-22 14:20:47 0 [ERROR] Unknown/unsupported storage engine: InnoDB
      2025-01-22 14:20:47 0 [ERROR] Aborting
      2025-01-22 14:20:47 3 [ERROR] WSREP: sst_received failed: State wait was interrupted
      2025-01-22 14:20:47 1 [ERROR] WSREP: Application received wrong state:
      Received: 00000000-0000-0000-0000-000000000000
      Required: 15a3cde4-8d25-11ef-9e70-87f74cf82f0b
      2025-01-22 14:20:47 1 [ERROR] WSREP: Application state transfer failed. This is unrecoverable condition, restart required.

      2025-01-22 14:21:23 0 [Note] Starting MariaDB 11.4.3-MariaDB-ubu2204-log source revision 5ab81ffe0097a22a774957df28c5223cf0201de3 server_uid 2kvendvuwn01ONhSSO3NiOJPVy
      M= as process 1343190
      2025-01-22 14:21:23 0 [Note] WSREP: Loading provider /usr/lib/libgalera_smm.so initial position: 15a3cde4-8d25-11ef-9e70-87f74cf82f0b:221931435
      2025-01-22 14:21:23 0 [Note] WSREP: wsrep_load(): loading provider library '/usr/lib/libgalera_smm.so'
      2025-01-22 14:21:23 0 [Note] WSREP: wsrep_load(): Galera 26.4.19(r5db72dad) by Codership Oy <info@codership.com> loaded successfully.
      2025-01-22 14:21:23 0 [Note] WSREP: Initializing allowlist service v1
      2025-01-22 14:21:23 0 [Note] WSREP: Initializing event service v1
      2025-01-22 14:21:23 0 [Note] WSREP: Resolved symbol 'wsrep_node_isolation_mode_set_v1'
      2025-01-22 14:21:23 0 [Note] WSREP: CRC-32C: using 64-bit x86 acceleration.
      2025-01-22 14:21:23 0 [Note] WSREP: Found saved state: 00000000-0000-0000-0000-000000000000:-1, safe_to_bootstrap: 0
      }}

      If you require more logs please let me know.
      I set minor priority because on subsequent restart all is healthy. However my automation workflow fails

      Thanks in advance.

      Attachments

        Activity

          Ascending order - Click to sort in descending order
          vmunoz Victor Munoz created issue -
          janlindstrom Jan Lindström made changes -
          Field Original Value New Value
          Assignee Jan Lindström [ JIRAUSER53125 ]
          janlindstrom Jan Lindström added a comment -

          vmunoz Please provide full error log and node configuration.

          janlindstrom Jan Lindström added a comment - vmunoz Please provide full error log and node configuration.
          janlindstrom Jan Lindström made changes -
          Status Open [ 1 ] Needs Feedback [ 10501 ]
          vmunoz Victor Munoz made changes -
          Attachment e2p1_mariadb.cnf [ 74530 ]
          Attachment e2p1_mysql_error.log [ 74531 ]
          vmunoz Victor Munoz made changes -
          Attachment e2p1_journal_mariadb.log [ 74532 ]
          vmunoz Victor Munoz added a comment -

          Thanks @janlindstrom ; logs attached.

          vmunoz Victor Munoz added a comment - Thanks @janlindstrom ; logs attached.
          janlindstrom Jan Lindström added a comment -

          vmunoz Based on error log it looks like reading InnoDB log failed causing SST failure.
          If you have backup and prepare logs from mariabackup they could help and naturally if you could provide actual InnoDB log file for analysis.

          2025-01-22 14:20:47 0 [Warning] InnoDB: Retry attempts for reading partial data failed.
          		 
          2025-01-22 14:20:47 0 [ERROR] InnoDB: Failed to read log at 40964608: I/O error
          		 
          2025-01-22 14:20:47 0 [ERROR] InnoDB: Plugin initialization aborted with error Generic error
          		 
          2025-01-22 14:20:47 0 [Note] InnoDB: Starting shutdown...
          		 
          2025-01-22 14:20:47 0 [ERROR] Plugin 'InnoDB' registration as a STORAGE ENGINE failed.
          		 
          2025-01-22 14:20:47 0 [Note] Plugin 'FEEDBACK' is disabled.
          		 
          2025-01-22 14:20:47 0 [ERROR] Unknown/unsupported storage engine: InnoDB
          		 
          2025-01-22 14:20:47 0 [ERROR] Aborting

          janlindstrom Jan Lindström added a comment - vmunoz Based on error log it looks like reading InnoDB log failed causing SST failure. If you have backup and prepare logs from mariabackup they could help and naturally if you could provide actual InnoDB log file for analysis. 2025-01-22 14:20:47 0 [Warning] InnoDB: Retry attempts for reading partial data failed. 2025-01-22 14:20:47 0 [ERROR] InnoDB: Failed to read log at 40964608: I/O error 2025-01-22 14:20:47 0 [ERROR] InnoDB: Plugin initialization aborted with error Generic error 2025-01-22 14:20:47 0 [Note] InnoDB: Starting shutdown... 2025-01-22 14:20:47 0 [ERROR] Plugin 'InnoDB' registration as a STORAGE ENGINE failed. 2025-01-22 14:20:47 0 [Note] Plugin 'FEEDBACK' is disabled. 2025-01-22 14:20:47 0 [ERROR] Unknown/unsupported storage engine: InnoDB 2025-01-22 14:20:47 0 [ERROR] Aborting
          janlindstrom Jan Lindström made changes -
          Status Needs Feedback [ 10501 ] Open [ 1 ]
          janlindstrom Jan Lindström made changes -
          Component/s Storage Engine - InnoDB [ 10129 ]
          janlindstrom Jan Lindström made changes -
          Status Open [ 1 ] Needs Feedback [ 10501 ]
          vmunoz Victor Munoz added a comment - - edited

          Hi Jan,

          I think you can close this ticket. I've detected our disk is not healthy as expected. I will rebuild the server and reopen the ticket if issue happens again:

          Jan 22 14:20:47 e2.p1.mariadb.mydomain.lan kernel: blk_update_request: I/O error, dev vda, sector 27326625 op 0x0:(READ) flags 0x4000 phys_seg 126 prio class 0
          		 
          Jan 22 14:20:47 e2.p1.mariadb.mydomain.lan kernel: blk_update_request: I/O error, dev vda, sector 27327641 op 0x0:(READ) flags 0x0 phys_seg 4 prio class 0
          		 
          Jan 22 14:20:47 e2.p1.mariadb.mydomain.lan kernel: blk_update_request: I/O error, dev vda, sector 27327673 op 0x0:(READ) flags 0x4000 phys_seg 126 prio class 0
          		 
          Jan 22 14:20:47 e2.p1.mariadb.mydomain.lan kernel: blk_update_request: I/O error, dev vda, sector 27329265 op 0x0:(READ) flags 0x4000 phys_seg 126 prio class 0
          		 
          Jan 22 14:20:47 e2.p1.mariadb.mydomain.lan kernel: blk_update_request: I/O error, dev vda, sector 27330273 op 0x0:(READ) flags 0x0 phys_seg 4 prio class 0
          		 
          Jan 22 14:20:47 e2.p1.mariadb.mydomain.lan kernel: blk_update_request: I/O error, dev vda, sector 27330305 op 0x0:(READ) flags 0x4000 phys_seg 126 prio class 0
          		 
          Jan 22 14:20:47 e2.p1.mariadb.mydomain.lan kernel: blk_update_request: I/O error, dev vda, sector 27331313 op 0x0:(READ) flags 0x4000 phys_seg 126 prio class 0
          		 
          Jan 22 14:20:47 e2.p1.mariadb.mydomain.lan kernel: blk_update_request: I/O error, dev vda, sector 27332353 op 0x0:(READ) flags 0x0 phys_seg 4 prio class 0
          		 
          Jan 22 14:20:47 e2.p1.mariadb.mydomain.lan kernel: blk_update_request: I/O error, dev vda, sector 27332385 op 0x0:(READ) flags 0x4000 phys_seg 126 prio class 0
          		 
          Jan 22 14:20:47 e2.p1.mariadb.mydomain.lan kernel: blk_update_request: I/O error, dev vda, sector 27333393 op 0x0:(READ) flags 0x4000 phys_seg 126 prio class 0

          Thanks anyway

          vmunoz Victor Munoz added a comment - - edited Hi Jan, I think you can close this ticket. I've detected our disk is not healthy as expected. I will rebuild the server and reopen the ticket if issue happens again: Jan 22 14:20:47 e2.p1.mariadb.mydomain.lan kernel: blk_update_request: I/O error, dev vda, sector 27326625 op 0x0:(READ) flags 0x4000 phys_seg 126 prio class 0 Jan 22 14:20:47 e2.p1.mariadb.mydomain.lan kernel: blk_update_request: I/O error, dev vda, sector 27327641 op 0x0:(READ) flags 0x0 phys_seg 4 prio class 0 Jan 22 14:20:47 e2.p1.mariadb.mydomain.lan kernel: blk_update_request: I/O error, dev vda, sector 27327673 op 0x0:(READ) flags 0x4000 phys_seg 126 prio class 0 Jan 22 14:20:47 e2.p1.mariadb.mydomain.lan kernel: blk_update_request: I/O error, dev vda, sector 27329265 op 0x0:(READ) flags 0x4000 phys_seg 126 prio class 0 Jan 22 14:20:47 e2.p1.mariadb.mydomain.lan kernel: blk_update_request: I/O error, dev vda, sector 27330273 op 0x0:(READ) flags 0x0 phys_seg 4 prio class 0 Jan 22 14:20:47 e2.p1.mariadb.mydomain.lan kernel: blk_update_request: I/O error, dev vda, sector 27330305 op 0x0:(READ) flags 0x4000 phys_seg 126 prio class 0 Jan 22 14:20:47 e2.p1.mariadb.mydomain.lan kernel: blk_update_request: I/O error, dev vda, sector 27331313 op 0x0:(READ) flags 0x4000 phys_seg 126 prio class 0 Jan 22 14:20:47 e2.p1.mariadb.mydomain.lan kernel: blk_update_request: I/O error, dev vda, sector 27332353 op 0x0:(READ) flags 0x0 phys_seg 4 prio class 0 Jan 22 14:20:47 e2.p1.mariadb.mydomain.lan kernel: blk_update_request: I/O error, dev vda, sector 27332385 op 0x0:(READ) flags 0x4000 phys_seg 126 prio class 0 Jan 22 14:20:47 e2.p1.mariadb.mydomain.lan kernel: blk_update_request: I/O error, dev vda, sector 27333393 op 0x0:(READ) flags 0x4000 phys_seg 126 prio class 0 Thanks anyway
          janlindstrom Jan Lindström made changes -
          Status Needs Feedback [ 10501 ] Open [ 1 ]
          janlindstrom Jan Lindström made changes -
          issue.field.resolutiondate 2025-01-28 07:39:38.0 2025-01-28 07:39:37.724
          janlindstrom Jan Lindström made changes -
          Fix Version/s N/A [ 14700 ]
          Resolution Not a Bug [ 6 ]
          Status Open [ 1 ] Closed [ 6 ]

          People

            janlindstrom Jan Lindström
            vmunoz Victor Munoz
            Votes:
            0 Vote for this issue
            Watchers:
            2 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.