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

mariabackup 10.11 failed

Details

    • Bug
    • Status: Closed (View Workflow)
    • Major
    • Resolution: Incomplete
    • 10.11.9
    • N/A
    • mariabackup
    • Centos 9 Stream

    Description

      Hi,

      The mariabackup failed and this message appeared.

      FATAL ERROR: 2024-11-19 09:24:51 Was only able to copy log from 1986198832189 to 1986466251940, not 1986466252474; try increasing innodb_log_file_size

      My innodb_log_file_size=4G

      After this message, the node desynced itself from the group

      2024-11-19 9:24:45 27129026 [Note] WSREP: Desyncing and pausing the provider
      2024-11-19 9:24:45 0 [Note] WSREP: Member 5.0 (Node-1) desyncs itself from group
      2024-11-19 9:24:45 0 [Note] WSREP: Shifting SYNCED -> DONOR/DESYNCED (TO: 17682829)
      2024-11-19 9:24:45 27129026 [Note] WSREP: pause
      2024-11-19 9:24:45 27129026 [Note] WSREP: Provider paused at e424d1d9-a4ef-11ef-b5e1-76a93350b8e5:17682829 (18515772)
      2024-11-19 9:24:45 27129026 [Note] WSREP: Provider paused at: 17682829
      2024-11-19 9:24:45 27129026 [Note] WSREP: Server desynched from group during BACKUP STAGE BLOCK_DDL.
      2024-11-19 9:24:51 27129026 [Note] WSREP: Resuming and resyncing the provider
      2024-11-19 9:24:51 27129026 [Note] WSREP: resume
      2024-11-19 9:24:51 27129026 [Note] WSREP: resuming provider at 18515772
      2024-11-19 9:24:51 27129026 [Note] WSREP: Provider resumed.
      2024-11-19 9:24:51 0 [Note] WSREP: Member 5.0 (Node-1) resyncs itself to the group.
      2024-11-19 9:24:51 0 [Note] WSREP: Shifting DONOR/DESYNCED -> JOINED (TO: 17682829)
      2024-11-19 9:24:51 0 [Note] WSREP: Processing event queue:... -nan% (0/0 events) complete.
      2024-11-19 9:24:51 0 [Note] WSREP: Member 5.0 (Node-1) synced with group.
      2024-11-19 9:24:51 0 [Note] WSREP: Processing event queue:... 100.0% (1/1 events) complete.
      2024-11-19 9:24:51 0 [Note] WSREP: Shifting JOINED -> SYNCED (TO: 17682829)
      2024-11-19 9:24:51 58 [Note] WSREP: Server Node-1synced with group

      After restart it worked, but the db was desynced from the cluster every time.
      2024-11-19 10:22:55 27137310 [Note] WSREP: Desyncing and pausing the provider
      2024-11-19 10:22:55 0 [Note] WSREP: Member 5.0 (Node-1) desyncs itself from group
      2024-11-19 10:22:55 0 [Note] WSREP: Shifting SYNCED -> DONOR/DESYNCED (TO: 17684672)
      2024-11-19 10:22:55 27137310 [Note] WSREP: pause
      2024-11-19 10:22:55 27137310 [Note] WSREP: Provider paused at e424d1d9-a4ef-11ef-b5e1-76a93350b8e5:17684672 (18517647)
      2024-11-19 10:22:55 27137310 [Note] WSREP: Provider paused at: 17684672
      2024-11-19 10:22:55 27137310 [Note] WSREP: Server desynched from group during BACKUP STAGE BLOCK_DDL.
      2024-11-19 10:22:56 27137310 [Note] WSREP: Resuming and resyncing the provider
      2024-11-19 10:22:56 27137310 [Note] WSREP: resume
      2024-11-19 10:22:56 27137310 [Note] WSREP: resuming provider at 18517647
      2024-11-19 10:22:56 27137310 [Note] WSREP: Provider resumed.
      2024-11-19 10:22:56 0 [Note] WSREP: Member 5.0 (Node-1) resyncs itself to group.
      2024-11-19 10:22:56 0 [Note] WSREP: Shifting DONOR/DESYNCED -> JOINED (TO: 17684672)
      2024-11-19 10:22:56 0 [Note] WSREP: Processing event queue:... -nan% (0/0 events) complete.
      2024-11-19 10:22:56 0 [Note] WSREP: Member 5.0 (Node-1) synced with group.
      2024-11-19 10:22:56 0 [Note] WSREP: Processing event queue:... 100.0% (1/1 events) complete.
      2024-11-19 10:22:56 0 [Note] WSREP: Shifting JOINED -> SYNCED (TO: 17684672)
      2024-11-19 10:22:56 89 [Note] WSREP: Server Node-1 synced with group

      Attachments

        Issue Links

          relates to

          Bug - A problem which impairs or prevents the functions of the product. MDEV-36237 mariabackup fails with 'try increasing innodb_log_file_size'

          • Major - Major loss of function.
          • Open

          Activity

            Ascending order - Click to sort in descending order
            marko Marko Mäkelä added a comment -

            Hi! Is this reproducible with MariaDB Server 10.11.10, which includes the fixes of MDEV-34062 and MDEV-34850?

            marko Marko Mäkelä added a comment - Hi! Is this reproducible with MariaDB Server 10.11.10, which includes the fixes of MDEV-34062 and MDEV-34850 ?
            shexphobos Xesh added a comment -

            It is a production system already, I can't just switch it easily.

            Tried with 10.11.9,

            mysql -e 'SET GLOBAL innodb_log_file_buffering=ON;'
            /bin/mariabackup --backup --target-dir=
            mysql -e 'SET GLOBAL innodb_log_file_buffering=OFF;'

            But failed with an error

            [00] FATAL ERROR: 2024-11-25 12:20:42 Was only able to copy log from 3672774772394 to 3676210020642, not 3676210219652; try increasing innodb_log_file_size

            shexphobos Xesh added a comment - It is a production system already, I can't just switch it easily. Tried with 10.11.9, mysql -e 'SET GLOBAL innodb_log_file_buffering=ON;' /bin/mariabackup --backup --target-dir= mysql -e 'SET GLOBAL innodb_log_file_buffering=OFF;' But failed with an error [00] FATAL ERROR: 2024-11-25 12:20:42 Was only able to copy log from 3672774772394 to 3676210020642, not 3676210219652; try increasing innodb_log_file_size
            shexphobos Xesh added a comment - - edited

            I tried with 10.11.10, but it does not work. On two different servers, mariabackup fails.
            It cannot turn off or change innodb_log_file_buffering to OFF. Only restarting the server helps to be at the OFF state.

            The backup script look like this:
            mysql -e 'SET GLOBAL innodb_log_file_buffering=ON;'
            /bin/mariabackup --backup --target-dir=/mnt/backup/db/"$BACKUP_DATE"/ --user=root --password=xxx
            mysql -e 'SET GLOBAL innodb_log_file_buffering=OFF;'

            ------------------

            VERSION()

            ------------------

            10.11.10-MariaDB

            ------------------
            1 row in set (0.001 sec)

            MariaDB [(none)]> show variables like '%innodb_log_file_buffering%';
            ERROR 2006 (HY000): Server has gone away
            No connection. Trying to reconnect...
            Connection id: 152750
            Current database: *** NONE ***

            --------------------------------+

            Variable_name Value

            --------------------------------+

            innodb_log_file_buffering ON

            --------------------------------+
            1 row in set (0.001 sec)

            MariaDB [(none)]> set global innodb_log_file_buffering=OFF;
            ERROR 2006 (HY000): Server has gone away
            No connection. Trying to reconnect...
            Connection id: 152752
            Current database: *** NONE ***

            Query OK, 0 rows affected (0.000 sec)

            MariaDB [(none)]> show variables like '%innodb_log_file_buffering%';
            --------------------------------+

            Variable_name Value

            --------------------------------+

            innodb_log_file_buffering ON

            --------------------------------+
            1 row in set (0.001 sec)

            shexphobos Xesh added a comment - - edited I tried with 10.11.10, but it does not work. On two different servers, mariabackup fails. It cannot turn off or change innodb_log_file_buffering to OFF. Only restarting the server helps to be at the OFF state. The backup script look like this: mysql -e 'SET GLOBAL innodb_log_file_buffering=ON;' /bin/mariabackup --backup --target-dir=/mnt/backup/db/"$BACKUP_DATE"/ --user=root --password=xxx mysql -e 'SET GLOBAL innodb_log_file_buffering=OFF;' ------------------ VERSION() ------------------ 10.11.10-MariaDB ------------------ 1 row in set (0.001 sec) MariaDB [(none)] > show variables like '%innodb_log_file_buffering%'; ERROR 2006 (HY000): Server has gone away No connection. Trying to reconnect... Connection id: 152750 Current database: *** NONE *** -------------------------- ------+ Variable_name Value -------------------------- ------+ innodb_log_file_buffering ON -------------------------- ------+ 1 row in set (0.001 sec) MariaDB [(none)] > set global innodb_log_file_buffering=OFF; ERROR 2006 (HY000): Server has gone away No connection. Trying to reconnect... Connection id: 152752 Current database: *** NONE *** Query OK, 0 rows affected (0.000 sec) MariaDB [(none)] > show variables like '%innodb_log_file_buffering%'; -------------------------- ------+ Variable_name Value -------------------------- ------+ innodb_log_file_buffering ON -------------------------- ------+ 1 row in set (0.001 sec)
            shexphobos Xesh added a comment -

            Two different logs from two different servers failed.

            [00] 2024-12-11 09:14:10 Was only able to copy log from 7737783752828 to 7738227384313, not 7738227394986; try increasing innodb_log_file_size
            mariabackup: Stopping log copying thread.[00] 2024-12-11 09:14:10 Retrying read of log at LSN=7738227384313

            [00] 2024-12-11 12:52:12 Was only able to copy log from 15720103904989 to 15720203877895, not 15720203929469; try increasing innodb_log_file_size
            mariabackup: Stopping log copying thread.[00] 2024-12-11 12:52:12 Retrying read of log at LSN=15720203877895

            shexphobos Xesh added a comment - Two different logs from two different servers failed. [00] 2024-12-11 09:14:10 Was only able to copy log from 7737783752828 to 7738227384313, not 7738227394986; try increasing innodb_log_file_size mariabackup: Stopping log copying thread. [00] 2024-12-11 09:14:10 Retrying read of log at LSN=7738227384313 [00] 2024-12-11 12:52:12 Was only able to copy log from 15720103904989 to 15720203877895, not 15720203929469; try increasing innodb_log_file_size mariabackup: Stopping log copying thread. [00] 2024-12-11 12:52:12 Retrying read of log at LSN=15720203877895
            shexphobos Xesh added a comment -

            Sometimes even restarting the database does not help, sometimes it does.

            shexphobos Xesh added a comment - Sometimes even restarting the database does not help, sometimes it does.
            shexphobos Xesh added a comment - - edited

            I tried updating it from 10.11.9 to 10.11.10,but it did not help.
            I tried 10.11.10 with SET GLOBAL innodb_log_file_buffering=ON, it did not help.
            I tried 10.11.10 with --use-memory=12G and innodb_log_file_buffering=ON, but nothing.
            I tried 10.11.10 with only --innodb-log-file-mmap=ON, nothing
            I tried 10.11.10 with SET GLOBAL innodb_log_file_buffering=ON and --innodb-log-file-mmap=ON again nothing.

            Restart sometimes helps, sometimes not. Overall it does not work.

            I tried everything from Marko's references MDEV-34062 and MDEV-34850, but nothing

            shexphobos Xesh added a comment - - edited I tried updating it from 10.11.9 to 10.11.10,but it did not help. I tried 10.11.10 with SET GLOBAL innodb_log_file_buffering=ON, it did not help. I tried 10.11.10 with --use-memory=12G and innodb_log_file_buffering=ON, but nothing. I tried 10.11.10 with only --innodb-log-file-mmap=ON, nothing I tried 10.11.10 with SET GLOBAL innodb_log_file_buffering=ON and --innodb-log-file-mmap=ON again nothing. Restart sometimes helps, sometimes not. Overall it does not work. I tried everything from Marko's references MDEV-34062 and MDEV-34850 , but nothing

            People

              marko Marko Mäkelä
              shexphobos Xesh
              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.