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

mariabackup --backup fails with FATAL ERROR: ... failed to copy datafile.

Details

    Description

      origin/bb-10.11-new-innodb-defaults be6a3d9a01c4357fbb52b4eefcb91bf84a8d0d4c 2022-12-09T13:51:55+02:00
      		 
      Marko assumes that the trouble is linked to MDEV-29986.
      		 
       
      		 
      Scenario:
      		 
      1. The server is under concurrent DDL/DML load.
      		 
      2. During 1. is ongoing runs a mariabackup --backup to some other directory.
      		 
       
      		 
      Snip of the error log:
      		 
      ```# 2022-12-09T03:58:05 [234171] | [rr 332149 3776][00] 2022-12-09 03:58:04 >> log scanned up to (315140211)
      		 
      # 2022-12-09T03:58:05 [234171] | [rr 332149 3801][00] 2022-12-09 03:58:05 >> log scanned up to (315141264)
      		 
      # 2022-12-09T03:58:05 [234171] | [rr 332149 3808]2022-12-09  3:58:05 0 [Warning] InnoDB: 6291456 bytes should have been read at 10485760 from (unknown file), but got only 0. Retrying.
      		 
      # 2022-12-09T03:58:05 [234171] | [rr 332149 3814]2022-12-09  3:58:05 0 [Warning] InnoDB: 6291456 bytes should have been read at 10485760 from (unknown file), but got only 0. Retrying.
      		 
      # 2022-12-09T03:58:05 [234171] | [rr 332149 3820]2022-12-09  3:58:05 0 [Warning] InnoDB: 6291456 bytes should have been read at 10485760 from (unknown file), but got only 0. Retrying.
      		 
      # 2022-12-09T03:58:05 [234171] | [rr 332149 3826]2022-12-09  3:58:05 0 [Warning] InnoDB: 6291456 bytes should have been read at 10485760 from (unknown file), but got only 0. Retrying.
      		 
      # 2022-12-09T03:58:05 [234171] | [rr 332149 3832]2022-12-09  3:58:05 0 [Warning] InnoDB: 6291456 bytes should have been read at 10485760 from (unknown file), but got only 0. Retrying.
      		 
      # 2022-12-09T03:58:05 [234171] | [rr 332149 3838]2022-12-09  3:58:05 0 [Warning] InnoDB: 6291456 bytes should have been read at 10485760 from (unknown file), but got only 0. Retrying.
      		 
      # 2022-12-09T03:58:05 [234171] | [rr 332149 3846]2022-12-09  3:58:05 0 [Warning] InnoDB: 6291456 bytes should have been read at 10485760 from (unknown file), but got only 0. Retrying.
      		 
      # 2022-12-09T03:58:05 [234171] | [rr 332149 3856]2022-12-09  3:58:05 0 [Warning] InnoDB: 6291456 bytes should have been read at 10485760 from (unknown file), but got only 0. Retrying.
      		 
      # 2022-12-09T03:58:05 [234171] | [rr 332149 3864][00] 2022-12-09 03:58:05 >> log scanned up to (315165453)
      		 
      # 2022-12-09T03:58:05 [234171] | [rr 332149 3871]2022-12-09  3:58:05 0 [Warning] InnoDB: 6291456 bytes should have been read at 10485760 from (unknown file), but got only 0. Retrying.
      		 
      # 2022-12-09T03:58:05 [234171] | [rr 332149 3877]2022-12-09  3:58:05 0 [Warning] InnoDB: 6291456 bytes should have been read at 10485760 from (unknown file), but got only 0. Retrying.
      		 
      # 2022-12-09T03:58:05 [234171] | [rr 332149 3881]2022-12-09  3:58:05 0 [Warning] InnoDB: Retry attempts for reading partial data failed.
      		 
      # 2022-12-09T03:58:05 [234171] | [rr 332149 3890][01] 2022-12-09 03:58:05 mariabackup: xtrabackup_copy_datafile() failed.
      		 
      # 2022-12-09T03:58:05 [234171] | [rr 332149 3898][00] FATAL ERROR: 2022-12-09 03:58:05 failed to copy datafile.```

      Hitting this bug is very rare.

      RQG:
      ===

      1. git clone https://github.com/mleich1/rqg --branch <pick the right branch> RQG
        #
      2. GIT_SHOW: HEAD -> master, origin/master, origin/HEAD 1abbb033ff1d798d9d0a9bacdf072fe8fd4f5deb 2022-12-09T12:56:59+01:00
      3. rqg.pl : Version 4.2.1 (2022-12)
        #
      4. $RQG_HOME/rqg.pl \
      5. --grammar=conf/engines/many_indexes.yy \
      6. --gendata=conf/engines/many_indexes.zz \
      7. --reporters=Mariabackup_linux \
      8. --redefine=conf/mariadb/redefine_file_buffering_write_through.yy \
      9. -mysqld=-loose-innodb_lock_schedule_algorithm=fcfs \
      10. -mysqld=-loose-idle_write_transaction_timeout=0 \
      11. -mysqld=-loose-idle_transaction_timeout=0 \
      12. -mysqld=-loose-idle_readonly_transaction_timeout=0 \
      13. -mysqld=-connect_timeout=60 \
      14. -mysqld=-interactive_timeout=28800 \
      15. -mysqld=-slave_net_timeout=60 \
      16. -mysqld=-net_read_timeout=30 \
      17. -mysqld=-net_write_timeout=60 \
      18. -mysqld=-loose-table_lock_wait_timeout=50 \
      19. -mysqld=-wait_timeout=28800 \
      20. -mysqld=-lock-wait-timeout=86400 \
      21. -mysqld=-innodb-lock-wait-timeout=50 \
      22. --no-mask \
      23. --queries=10000000 \
      24. --seed=random \
      25. --reporters=Backtrace \
      26. --reporters=ErrorLog \
      27. --reporters=Deadlock \
      28. --validators=None \
      29. -mysqld=-log_output=none \
      30. -mysqld=-log_bin_trust_function_creators=1 \
      31. -mysqld=-loose-debug_assert_on_not_freed_memory=0 \
      32. --engine=InnoDB \
      33. --restart_timeout=240 \
      34. -mysqld=-plugin-load-add=file_key_management.so \
      35. -mysqld=-loose-file-key-management-filename=$RQG_HOME/conf/mariadb/encryption_keys.txt \
      36. -mysqld=-plugin-load-add=provider_lzo.so \
      37. -mysqld=-plugin-load-add=provider_bzip2.so \
      38. -mysqld=-plugin-load-add=provider_lzma.so \
      39. -mysqld=-plugin-load-add=provider_snappy.so \
      40. -mysqld=-plugin-load-add=provider_lz4.so \
      41. --duration=300 \
      42. -mysqld=-loose-innodb_fatal_semaphore_wait_threshold=300 \
      43. -mysqld=-innodb_file_per_table=0 \
      44. -mysqld=-loose-innodb_read_only_compressed=OFF \
      45. -mysqld=-innodb_stats_persistent=on \
      46. -mysqld=-innodb_adaptive_hash_index=off \
      47. -mysqld=-log-bin \
      48. -mysqld=-sync-binlog=1 \
      49. -mysqld=-loose-innodb_evict_tables_on_commit_debug=on \
      50. -mysqld=-loose-max-statement-time=30 \
      51. --threads=33 \
      52. -mysqld=-innodb_use_native_aio=1 \
      53. -mysqld=-loose_innodb_change_buffering=changes \
      54. -mysqld=-innodb_rollback_on_timeout=OFF \
      55. -mysqld=-innodb_page_size=16K \
      56. -mysqld=-innodb-buffer-pool-size=8M \
      57. --vardir_type=slow \
      58. <local settings>

      sdp:/data/results/1670586562/Backup$ _RR_TRACE_DIR=./1_clone/rr rr replay --mark-stdio

      Attachments

        Issue Links

          relates to

          Task - A task that needs to be done. MDEV-29986 Set innodb_undo_tablespaces=3 by default

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

          Activity

            People

              thiru Thirunarayanan Balathandayuthapani
              mleich Matthias Leich
              Votes:
              0 Vote for this issue
              Watchers:
              4 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.