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

mariabackup rsync fails to copy /var/lib/mysql/var/lib/mysql/ib_buffer_pool

Details

    Description

      Since I upgraded the mariadb stack from 10.5.15 to 10.5.16 I observe rsync errors during the daily mariabackup

      Command : 

      /usr/bin/mariabackup --backup --rsync --tmpdir=/tmp --slave-info --target-dir=/var/backups/percona

      Log output (end) :

      [00] 2022-06-09 08:42:14 Starting prep copy of non-InnoDB tables and files
      		 
      [00] 2022-06-09 08:42:14 Starting rsync as: rsync -t . --files-from=/tmp/xtrabackup_rsyncfiles_pass1 /var/backups/percona/
      		 
      2022-06-09  8:42:14 0 [Note] InnoDB: Read redo log up to LSN=5532145282560
      		 
      [00] 2022-06-09 08:42:14 >> log scanned up to (5532145282501)
      		 
      rsync: link_stat "/var/lib/mysql/var/lib/mysql/ib_buffer_pool" failed: No such file or directory (2)
      		 
      [00] 2022-06-09 08:42:15 >> log scanned up to (5532145282501)
      		 
      rsync error: some files/attrs were not transferred (see previous errors) (code 23) at main.c(1207) [sender=3.1.3]
      		 
      [00] 2022-06-09 08:42:15 rsync finished successfully.
      		 
      [00] 2022-06-09 08:42:15 Finished a prep copy of non-InnoDB tables and files
      		 
      [00] 2022-06-09 08:42:15 Acquiring BACKUP LOCKS...
      		 
      [00] 2022-06-09 08:42:15 Starting to backup non-InnoDB tables and files
      		 
      [00] 2022-06-09 08:42:15 Starting rsync as: rsync -t . --files-from=/tmp/xtrabackup_rsyncfiles_pass2 /var/backups/percona/
      		 
      rsync: link_stat "/var/lib/mysql/var/lib/mysql/ib_buffer_pool" failed: No such file or directory (2)
      		 
      rsync error: some files/attrs were not transferred (see previous errors) (code 23) at main.c(1207) [sender=3.1.3]
      		 
      [00] 2022-06-09 08:42:15 Error: rsync failed with error code 1
      		 
      mariabackup: Stopping log copying thread.[00] 2022-06-09 08:42:15 >> log scanned up to (5532145282501)

      The files /tmp/xtrabackup_rsyncfiles_pass1 and /tmp/xtrabackup_rsyncfiles_pass2 contains relative paths in the form of ./<dbname>/<tablename>.<ext> except for the last line containing the absolute path /var/lib/mysql/ib_buffer_pool.

      I upgraded from 10.3 to 10.5.15 mid-May, and it was working fine until the 10.5.16 upgrade last week.

      Below are the defaults for mysqld and mariabackup, ***** replace redacted names.

      mysqld --print-defaults

      mysqld would have been started with the following arguments:
      		 
      --socket=/run/mysqld/mysqld.sock --innodb_autoextend_increment=1 --innodb_buffer_pool_instances=1 --innodb_buffer_pool_size=2G --innodb_doublewrite=1 --innodb_file_format=Barracuda --innodb_file_per_table=1 --innodb_flush_log_at_trx_commit=1 --innodb_flush_log_at_trx_commit=2 --innodb_large_prefix=ON --innodb_lock_wait_timeout=60 --innodb_log_buffer_size=128M --innodb_log_file_size=48M --innodb_log_files_in_group=2 --innodb_log_group_home_dir=/var/lib/mysql/ --innodb_max_dirty_pages_pct=25 --innodb_thread_concurrency=16 --innodb_file_format=barracuda --sql_mode=ERROR_FOR_DIVISION_BY_ZERO,NO_AUTO_CREATE_USER,NO_ENGINE_SUBSTITUTION --innodb_adaptive_hash_index=OFF --user=mysql --pid-file=/var/run/mysqld/mysqld.pid --socket=/var/run/mysqld/mysqld.sock --port=3306 --basedir=/usr --datadir=/var/lib/mysql --tmpdir=/tmp --lc-messages-dir=/usr/share/mysql --skip-external-locking --bind-address=0.0.0.0 --key_buffer_size=16M --max_allowed_packet=16M --thread_stack=192K --thread_cache_size=8 --myisam_recover_options=BACKUP --query_cache_limit=1M --query_cache_size=16M --log_error=/var/log/mysql/error.log --expire_logs_days=10 --max_binlog_size=100M --character-set-server=utf8mb4 --collation-server=utf8mb4_general_ci --sql_mode=ERROR_FOR_DIVISION_BY_ZERO,NO_AUTO_CREATE_USER,NO_ENGINE_SUBSTITUTION --tmpdir=/var/mysqltmp --user=mysql --pid-file=/var/run/mysqld/mysqld.pid --socket=/var/run/mysqld/mysqld.sock --port=3306 --basedir=/usr --datadir=/var/lib/mysql --tmpdir=/tmp --language=/usr/share/mysql/english --long_query_time=2 --log_bin=/var/log/mysql/mysql-bin.log --server-id=1 --innodb_autoextend_increment=1 --innodb_buffer_pool_instances=1 --innodb_buffer_pool_size=2G --innodb_default_row_format=dynamic --innodb_doublewrite=1 --innodb_file_format=Barracuda --innodb_file_per_table=1 --innodb_flush_log_at_trx_commit=1 --innodb_flush_log_at_trx_commit=2 --innodb_large_prefix=ON --innodb_lock_wait_timeout=60 --innodb_log_buffer_size=128M --innodb_log_file_size=48M --innodb_log_files_in_group=2 --innodb_log_group_home_dir=/var/lib/mysql/ --innodb_max_dirty_pages_pct=25 --innodb_thread_concurrency=16 --long_query_time=0.1 --key_buffer=256M --max_allowed_packet=16M --max_connections=1000 --myisam-recover=BACKUP --query_cache_limit=1M --query_cache_size=128M --table_cache=256 --thread_cache_size=4 --expire_logs_days=11 --max_binlog_size=101M --binlog_do_db=***** --log-slave-updates --binlog_format=ROW --skip-slave-start=yes --log_bin_trust_function_creators=ON --ssl --ssl-ca=/etc/mysql/certs/ca-mysql-*****1-cert.pem --ssl-cert=/etc/mysql/certs/*****1-cert.pem --ssl-key=/etc/mysql/certs/*****1-key.pem --slow_query_log=ON --log_warnings=2 --general_log=OFF --log_error=/var/log/mysql/error.log --slow_query_log_file=/var/log/mysql/mysql-slow.log

      mariabackup --print-defaults

      mariabackup would have been started with the following arguments:
      		 
      --socket=/run/mysqld/mysqld.sock --innodb_autoextend_increment=1 --innodb_buffer_pool_instances=1 --innodb_buffer_pool_size=2G --innodb_doublewrite=1 --innodb_file_format=Barracuda --innodb_file_per_table=1 --innodb_flush_log_at_trx_commit=1 --innodb_flush_log_at_trx_commit=2 --innodb_large_prefix=ON --innodb_lock_wait_timeout=60 --innodb_log_buffer_size=128M --innodb_log_file_size=48M --innodb_log_files_in_group=2 --innodb_log_group_home_dir=/var/lib/mysql/ --innodb_max_dirty_pages_pct=25 --innodb_thread_concurrency=16 --innodb_file_format=barracuda --sql_mode=ERROR_FOR_DIVISION_BY_ZERO,NO_AUTO_CREATE_USER,NO_ENGINE_SUBSTITUTION --innodb_adaptive_hash_index=OFF --user=mysql --pid-file=/var/run/mysqld/mysqld.pid --socket=/var/run/mysqld/mysqld.sock --port=3306 --basedir=/usr --datadir=/var/lib/mysql --tmpdir=/tmp --lc-messages-dir=/usr/share/mysql --skip-external-locking --bind-address=0.0.0.0 --key_buffer_size=16M --max_allowed_packet=16M --thread_stack=192K --thread_cache_size=8 --myisam_recover_options=BACKUP --query_cache_limit=1M --query_cache_size=16M --log_error=/var/log/mysql/error.log --expire_logs_days=10 --max_binlog_size=100M --character-set-server=utf8mb4 --collation-server=utf8mb4_general_ci --sql_mode=ERROR_FOR_DIVISION_BY_ZERO,NO_AUTO_CREATE_USER,NO_ENGINE_SUBSTITUTION --tmpdir=/var/mysqltmp --user=mysql --pid-file=/var/run/mysqld/mysqld.pid --socket=/var/run/mysqld/mysqld.sock --port=3306 --basedir=/usr --datadir=/var/lib/mysql --tmpdir=/tmp --language=/usr/share/mysql/english --long_query_time=2 --log_bin=/var/log/mysql/mysql-bin.log --server-id=1 --innodb_autoextend_increment=1 --innodb_buffer_pool_instances=1 --innodb_buffer_pool_size=2G --innodb_default_row_format=dynamic --innodb_doublewrite=1 --innodb_file_format=Barracuda --innodb_file_per_table=1 --innodb_flush_log_at_trx_commit=1 --innodb_flush_log_at_trx_commit=2 --innodb_large_prefix=ON --innodb_lock_wait_timeout=60 --innodb_log_buffer_size=128M --innodb_log_file_size=48M --innodb_log_files_in_group=2 --innodb_log_group_home_dir=/var/lib/mysql/ --innodb_max_dirty_pages_pct=25 --innodb_thread_concurrency=16 --long_query_time=0.1 --key_buffer=256M --max_allowed_packet=16M --max_connections=1000 --myisam-recover=BACKUP --query_cache_limit=1M --query_cache_size=128M --table_cache=256 --thread_cache_size=4 --expire_logs_days=11 --max_binlog_size=101M --binlog_do_db=***** --log-slave-updates --binlog_format=ROW --skip-slave-start=yes --log_bin_trust_function_creators=ON --ssl --ssl-ca=/etc/mysql/certs/ca-mysql-*****1-cert.pem --ssl-cert=/etc/mysql/certs/*****1-cert.pem --ssl-key=/etc/mysql/certs/*****1-key.pem --slow_query_log=ON --log_warnings=2 --general_log=OFF --log_error=/var/log/mysql/error.log --slow_query_log_file=/var/log/mysql/mysql-slow.log

      Attachments

        Issue Links

          is caused by

          Bug - A problem which impairs or prevents the functions of the product. MDEV-27524 Incorrect binlogs after Galera SST using rsync and mariabackup

          • Critical - Crashes, loss of data, severe memory leak.
          • Closed
          is duplicated by

          Bug - A problem which impairs or prevents the functions of the product. MDEV-28814 MariaDB-10.6.8 mariabackup --rsync option is error

          • Major - Major loss of function.
          • Closed
          relates to

          Bug - A problem which impairs or prevents the functions of the product. MDEV-28758 Mariabackup copies binary logs to backup directory

          • Blocker - Blocks development and/or testing work, production could not run.
          • Closed

          Activity

            Ascending order - Click to sort in descending order
            octocyp Cyprien Nicolas added a comment -

            I just got a report from a collegue (same company) having the exact same issue after an upgrade from 10.3.27 to 10.3.35 yesterday.

            octocyp Cyprien Nicolas added a comment - I just got a report from a collegue (same company) having the exact same issue after an upgrade from 10.3.27 to 10.3.35 yesterday.
            tucha79 Denis added a comment -

            the same issue with MariaDB-backup-10.6.8-1.el7.centos.x86_64, downgrading to the MariaDB-backup-10.6.7-1.el7.centos.x86_64 is solve issue

            tucha79 Denis added a comment - the same issue with MariaDB-backup-10.6.8-1.el7.centos.x86_64, downgrading to the MariaDB-backup-10.6.7-1.el7.centos.x86_64 is solve issue
            nunop Nuno added a comment - - edited

            I'm getting the exact same issue now, with MariaDB 10.8.3-MariaDB-log on AlmaLinux.

            But same also happens on another database in a Docker container with 10.8.3-MariaDB-1:10.8.3+maria~jammy

            AlmaLinux:

            [00] 2022-06-26 07:01:10 Starting prep copy of non-InnoDB tables and files
            		 
            [00] 2022-06-26 07:01:10 Starting rsync as: rsync -t . --files-from=/var/lib/mysqltmp/xtrabackup_rsyncfiles_pass1 /opt/backup/mysql/
            		 
            rsync: link_stat "/var/lib/mysql/var/lib/mysql/ib_buffer_pool" failed: No such file or directory (2)
            		 
            rsync error: some files/attrs were not transferred (see previous errors) (code 23) at main.c(1189) [sender=3.1.3]
            		 
            [00] 2022-06-26 07:01:10 rsync finished successfully.
            		 
            [00] 2022-06-26 07:01:10 Finished a prep copy of non-InnoDB tables and files
            		 
            [00] 2022-06-26 07:01:10 Acquiring BACKUP LOCKS...
            		 
            [00] 2022-06-26 07:01:10 Starting to backup non-InnoDB tables and files
            		 
            [00] 2022-06-26 07:01:10 Starting rsync as: rsync -t . --files-from=/var/lib/mysqltmp/xtrabackup_rsyncfiles_pass2 /opt/backup/mysql/
            		 
            rsync: link_stat "/var/lib/mysql/var/lib/mysql/ib_buffer_pool" failed: No such file or directory (2)
            		 
            rsync error: some files/attrs were not transferred (see previous errors) (code 23) at main.c(1189) [sender=3.1.3]
            		 
            [00] 2022-06-26 07:01:10 Error: rsync failed with error code 1
            		 
            mariabackup: Stopping log copying thread.[00] 2022-06-26 07:01:10 >> log scanned up to (10109424124814)

            Docker container:

            [00] 2022-06-26 07:01:31 Starting prep copy of non-InnoDB tables and files
            		 
            [00] 2022-06-26 07:01:31 Starting rsync as: rsync -t . --files-from=/tmp/xtrabackup_rsyncfiles_pass1 /backup/
            		 
            rsync: [sender] link_stat "/var/lib/mysql/var/lib/mysql/ib_buffer_pool" failed: No such file or directory (2)
            		 
            [00] 2022-06-26 07:01:32 >> log scanned up to (94185383726)
            		 
            rsync error: some files/attrs were not transferred (see previous errors) (code 23) at main.c(1333) [sender=3.2.3]
            		 
            [00] 2022-06-26 07:01:32 rsync finished successfully.
            		 
            [00] 2022-06-26 07:01:32 Finished a prep copy of non-InnoDB tables and files
            		 
            [00] 2022-06-26 07:01:32 Acquiring BACKUP LOCKS...
            		 
            [00] 2022-06-26 07:01:32 Starting to backup non-InnoDB tables and files
            		 
            [00] 2022-06-26 07:01:32 Starting rsync as: rsync -t . --files-from=/tmp/xtrabackup_rsyncfiles_pass2 /backup/
            		 
            rsync: [sender] link_stat "/var/lib/mysql/var/lib/mysql/ib_buffer_pool" failed: No such file or directory (2)
            		 
            rsync error: some files/attrs were not transferred (see previous errors) (code 23) at main.c(1333) [sender=3.2.3]
            		 
            [00] 2022-06-26 07:01:32 Error: rsync failed with error code 1
            		 
            mariabackup: Stopping log copying thread.[00] 2022-06-26 07:01:32 >> log scanned up to (94185383726)

            igor, serg, marko, Any ideas? This might be critical as it is breaking our backups.

            Thank you!

            nunop Nuno added a comment - - edited I'm getting the exact same issue now, with MariaDB 10.8.3-MariaDB-log on AlmaLinux. But same also happens on another database in a Docker container with 10.8.3-MariaDB-1:10.8.3+maria~jammy AlmaLinux: [00] 2022-06-26 07:01:10 Starting prep copy of non-InnoDB tables and files [00] 2022-06-26 07:01:10 Starting rsync as: rsync -t . --files-from=/var/lib/mysqltmp/xtrabackup_rsyncfiles_pass1 /opt/backup/mysql/ rsync: link_stat "/var/lib/mysql/var/lib/mysql/ib_buffer_pool" failed: No such file or directory (2) rsync error: some files/attrs were not transferred (see previous errors) (code 23) at main.c(1189) [sender=3.1.3] [00] 2022-06-26 07:01:10 rsync finished successfully. [00] 2022-06-26 07:01:10 Finished a prep copy of non-InnoDB tables and files [00] 2022-06-26 07:01:10 Acquiring BACKUP LOCKS... [00] 2022-06-26 07:01:10 Starting to backup non-InnoDB tables and files [00] 2022-06-26 07:01:10 Starting rsync as: rsync -t . --files-from=/var/lib/mysqltmp/xtrabackup_rsyncfiles_pass2 /opt/backup/mysql/ rsync: link_stat "/var/lib/mysql/var/lib/mysql/ib_buffer_pool" failed: No such file or directory (2) rsync error: some files/attrs were not transferred (see previous errors) (code 23) at main.c(1189) [sender=3.1.3] [00] 2022-06-26 07:01:10 Error: rsync failed with error code 1 mariabackup: Stopping log copying thread.[00] 2022-06-26 07:01:10 >> log scanned up to (10109424124814) Docker container: [00] 2022-06-26 07:01:31 Starting prep copy of non-InnoDB tables and files [00] 2022-06-26 07:01:31 Starting rsync as: rsync -t . --files-from=/tmp/xtrabackup_rsyncfiles_pass1 /backup/ rsync: [sender] link_stat "/var/lib/mysql/var/lib/mysql/ib_buffer_pool" failed: No such file or directory (2) [00] 2022-06-26 07:01:32 >> log scanned up to (94185383726) rsync error: some files/attrs were not transferred (see previous errors) (code 23) at main.c(1333) [sender=3.2.3] [00] 2022-06-26 07:01:32 rsync finished successfully. [00] 2022-06-26 07:01:32 Finished a prep copy of non-InnoDB tables and files [00] 2022-06-26 07:01:32 Acquiring BACKUP LOCKS... [00] 2022-06-26 07:01:32 Starting to backup non-InnoDB tables and files [00] 2022-06-26 07:01:32 Starting rsync as: rsync -t . --files-from=/tmp/xtrabackup_rsyncfiles_pass2 /backup/ rsync: [sender] link_stat "/var/lib/mysql/var/lib/mysql/ib_buffer_pool" failed: No such file or directory (2) rsync error: some files/attrs were not transferred (see previous errors) (code 23) at main.c(1333) [sender=3.2.3] [00] 2022-06-26 07:01:32 Error: rsync failed with error code 1 mariabackup: Stopping log copying thread.[00] 2022-06-26 07:01:32 >> log scanned up to (94185383726) igor , serg , marko , Any ideas? This might be critical as it is breaking our backups. Thank you!
            serg Sergei Golubchik added a comment -

            will be fixed in the next release

            serg Sergei Golubchik added a comment - will be fixed in the next release
            sysprg Julius Goryavsky added a comment -

            Fixed by MDEV-28758
            (related commits: https://github.com/MariaDB/server/commit/5b4154373a93b323c3502692c46dcc51b1731785 and
            https://github.com/MariaDB/server/commit/5197519f4f7b31c61e3abccf75650e5356aecd4c)

            sysprg Julius Goryavsky added a comment - Fixed by MDEV-28758 (related commits: https://github.com/MariaDB/server/commit/5b4154373a93b323c3502692c46dcc51b1731785 and https://github.com/MariaDB/server/commit/5197519f4f7b31c61e3abccf75650e5356aecd4c )
            nunop Nuno added a comment -

            I confirm this is resolved.
            Thank you!

            nunop Nuno added a comment - I confirm this is resolved. Thank you!

            People

              sysprg Julius Goryavsky
              octocyp Cyprien Nicolas
              Votes:
              2 Vote for this issue
              Watchers:
              6 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.