borg
borg copied to clipboard
freebsd test failure in test_hard_link_deletion_and_replacement
Spotted this in PR #9146 (master branch):
=================================== FAILURES ===================================
2025-11-05T17:50:25.2963838Z ______________ test_hard_link_deletion_and_replacement[archiver] _______________
2025-11-05T17:50:25.2964927Z [gw1] freebsd14 -- Python 3.11.13 /home/runner/work/borg/borg/.venv/bin/python
2025-11-05T17:50:25.2965578Z
2025-11-05T17:50:25.2965758Z archivers = 'archiver'
2025-11-05T17:50:25.2966629Z request = <FixtureRequest for <Function test_hard_link_deletion_and_replacement[archiver]>>
2025-11-05T17:50:25.2967444Z
2025-11-05T17:50:25.2967986Z @pytest.mark.skipif(not are_hardlinks_supported(), reason="hardlinks not supported")
2025-11-05T17:50:25.2968969Z def test_hard_link_deletion_and_replacement(archivers, request):
2025-11-05T17:50:25.2969544Z archiver = request.getfixturevalue(archivers)
2025-11-05T17:50:25.2969962Z
2025-11-05T17:50:25.2970341Z # repo-create changes umask, so create the repo first to avoid any
2025-11-05T17:50:25.2970853Z # unexpected permission changes.
2025-11-05T17:50:25.2971782Z cmd(archiver, "repo-create", RK_ENCRYPTION)
2025-11-05T17:50:25.2972272Z path_a = os.path.join(archiver.input_path, "a")
2025-11-05T17:50:25.2972714Z path_b = os.path.join(archiver.input_path, "b")
2025-11-05T17:50:25.2973100Z os.mkdir(path_a)
2025-11-05T17:50:25.2973405Z os.mkdir(path_b)
2025-11-05T17:50:25.2973730Z hl_a = os.path.join(path_a, "hardlink")
2025-11-05T17:50:25.2974122Z hl_b = os.path.join(path_b, "hardlink")
2025-11-05T17:50:25.2974637Z create_regular_file(archiver.input_path, hl_a, contents=b"123456")
2025-11-05T17:50:25.2975115Z os.link(hl_a, hl_b)
2025-11-05T17:50:25.2975413Z
2025-11-05T17:50:25.2975672Z cmd(archiver, "create", "test0", "input")
2025-11-05T17:50:25.2976179Z os.unlink(hl_a) # Don't duplicate warning message - one is enough.
2025-11-05T17:50:25.2976668Z cmd(archiver, "create", "test1", "input")
2025-11-05T17:50:25.2977013Z
2025-11-05T17:50:25.2977441Z # Moral equivalent of test_multiple_link_exclusion in borg v1.x... see #8344
2025-11-05T17:50:25.2978076Z # Borg v2 doesn't have this issue comparing hard-links, so we'll defer to
2025-11-05T17:50:25.2978567Z # POSIX behavior:
2025-11-05T17:50:25.2979063Z # https://pubs.opengroup.org/onlinepubs/9799919799/functions/unlink.html
2025-11-05T17:50:25.2979791Z # Upon successful completion, unlink() shall mark for update the last data modification
2025-11-05T17:50:25.2980545Z # and last file status change timestamps of the parent directory. Also, if the
2025-11-05T17:50:25.2981194Z # file's link count is not 0, the last file status change timestamp of the
2025-11-05T17:50:25.2981858Z # file shall be marked for update.
2025-11-05T17:50:25.2982294Z output = cmd(
2025-11-05T17:50:25.2982809Z archiver, "diff", "--pattern=+ fm:input/b", "--pattern=! **/", "test0", "test1", exit_code=EXIT_SUCCESS
2025-11-05T17:50:25.2983356Z )
2025-11-05T17:50:25.2983604Z lines = output.splitlines()
2025-11-05T17:50:25.2983956Z # Directory was excluded.
2025-11-05T17:50:25.2984318Z assert_line_not_exists(lines, "input/a$")
2025-11-05T17:50:25.2984680Z # Remaining hardlink
2025-11-05T17:50:25.2985071Z assert_line_exists(lines, "ctime:.*input/b/hardlink")
2025-11-05T17:50:25.2985584Z assert_line_not_exists(lines, ".*mtime:.*input/b/hardlink")
2025-11-05T17:50:25.2986036Z # Deleted hardlink was excluded
2025-11-05T17:50:25.2986486Z assert_line_not_exists(lines, "input/a/hardlink$")
2025-11-05T17:50:25.2986869Z
2025-11-05T17:50:25.2987133Z # Now try again, except with no patterns!
2025-11-05T17:50:25.2987633Z output = cmd(archiver, "diff", "test0", "test1", exit_code=EXIT_SUCCESS)
2025-11-05T17:50:25.2988410Z lines = output.splitlines()
2025-11-05T17:50:25.2988942Z # Directory... preferably, let's not care about order differences are presented.
2025-11-05T17:50:25.2989554Z assert_line_exists(lines, "[cm]time:.*[cm]time:.*input/a")
2025-11-05T17:50:25.2989990Z # Remaining hardlink
2025-11-05T17:50:25.2990368Z assert_line_exists(lines, "ctime:.*input/b/hardlink")
2025-11-05T17:50:25.2990867Z assert_line_not_exists(lines, ".*mtime:.*input/b/hardlink")
2025-11-05T17:50:25.2991313Z # Deleted hardlink
2025-11-05T17:50:25.2991835Z assert_line_exists(lines, "removed:.*input/a/hardlink")
2025-11-05T17:50:25.2992250Z
2025-11-05T17:50:25.2992618Z # Now recreate the unlinked file as a different entity with identical
2025-11-05T17:50:25.2993089Z # contents.
2025-11-05T17:50:25.2993481Z create_regular_file(archiver.input_path, hl_a, contents=b"123456")
2025-11-05T17:50:25.2993995Z cmd(archiver, "create", "test2", "input")
2025-11-05T17:50:25.2994358Z
2025-11-05T17:50:25.2994582Z # Compare test0 and test2.
2025-11-05T17:50:25.2995039Z output = cmd(archiver, "diff", "test0", "test2", exit_code=EXIT_SUCCESS)
2025-11-05T17:50:25.2995720Z lines = output.splitlines()
2025-11-05T17:50:25.2996096Z # Adding a file changes c/mtime.
2025-11-05T17:50:25.2996540Z assert_line_exists(lines, "[cm]time:.*[cm]time:.*input/a$")
2025-11-05T17:50:25.2997104Z # Different c/mtime but no apparent changes (i.e. perms) or content
2025-11-05T17:50:25.2997745Z # modifications should be a hint that something hard-link related is going on.
2025-11-05T17:50:25.2998347Z assert_line_exists(lines, "[cm]time:.*[cm]time:.*input/a/hardlink")
2025-11-05T17:50:25.2998923Z assert_line_not_exists(lines, "modified.*B.*input/a/hardlink")
2025-11-05T17:50:25.2999459Z assert_line_not_exists(lines, "-[r-][w-][x-].*input/a/hardlink")
2025-11-05T17:50:25.3000057Z # ctime changed because the hard-link count went down. But no mtime changes
2025-11-05T17:50:25.3000693Z # because file content isn't modified. No permissions changes either.
2025-11-05T17:50:25.3001286Z # This is another hint that something hard-link related changed.
2025-11-05T17:50:25.3002012Z assert_line_exists(lines, "ctime:.*input/b/hardlink")
2025-11-05T17:50:25.3002522Z assert_line_not_exists(lines, ".*mtime:.*input/b/hardlink")
2025-11-05T17:50:25.3003079Z assert_line_not_exists(lines, "modified.*B.*input/b/hardlink")
2025-11-05T17:50:25.3003627Z assert_line_not_exists(lines, "-[r-][w-][x-].*input/b/hardlink")
2025-11-05T17:50:25.3004075Z
2025-11-05T17:50:25.3004327Z # Finally, compare test1 and test2.
2025-11-05T17:50:25.3004833Z output = cmd(archiver, "diff", "test1", "test2", exit_code=EXIT_SUCCESS)
2025-11-05T17:50:25.3005349Z lines = output.splitlines()
2025-11-05T17:50:25.3005752Z # Same situation applies as previous diff for a.
2025-11-05T17:50:25.3006260Z assert_line_exists(lines, "[cm]time:.*[cm]time:.*input/a$")
2025-11-05T17:50:25.3006811Z # From test1 to test2's POV, the a/hardlink file is a fresh new file.
2025-11-05T17:50:25.3007379Z assert_line_exists(lines, "added.*B.*input/a/hardlink")
2025-11-05T17:50:25.3007866Z # But the b/hardlink file was not modified at all.
2025-11-05T17:50:25.3008351Z > assert_line_not_exists(lines, ".*input/b/hardlink")
2025-11-05T17:50:25.3008655Z
2025-11-05T17:50:25.3008999Z /home/runner/work/borg/borg/src/borg/testsuite/archiver/diff_cmd_test.py:516:
2025-11-05T17:50:25.3009617Z _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
2025-11-05T17:50:25.3009911Z
2025-11-05T17:50:25.3010644Z lines = ['[mtime: Wed, 2025-11-05 17:45:53 +0000 -> Wed, 2025-11-05 17:45:53 +0000] [ctime: Wed, 2025-11-05 17:45:53 +0000 -> ...05 17:45:53 +0000 -> Wed, 2025-11-05 17:45:53 +0000] input/b/hardlink', 'added: 6 B input/a/hardlink']
2025-11-05T17:50:25.3012049Z expected_regexpr = '.*input/b/hardlink'
2025-11-05T17:50:25.3012331Z
2025-11-05T17:50:25.3012539Z def assert_line_not_exists(lines, expected_regexpr):
2025-11-05T17:50:25.3012995Z > assert not any(
2025-11-05T17:50:25.3013375Z re.search(expected_regexpr, line) for line in lines
2025-11-05T17:50:25.3013895Z ), f"unexpected match for {expected_regexpr} in {lines}"
2025-11-05T17:50:25.3015405Z E AssertionError: unexpected match for .*input/b/hardlink in ['[mtime: Wed, 2025-11-05 17:45:53 +0000 -> Wed, 2025-11-05 17:45:53 +0000] [ctime: Wed, 2025-11-05 17:45:53 +0000 -> Wed, 2025-11-05 17:45:53 +0000] input/a', '[ctime: Wed, 2025-11-05 17:45:53 +0000 -> Wed, 2025-11-05 17:45:53 +0000] input/b/hardlink', 'added: 6 B input/a/hardlink']
2025-11-05T17:50:25.3018750Z E assert not True
2025-11-05T17:50:25.3019341Z E + where True = any(<generator object assert_line_not_exists.<locals>.<genexpr> at 0x12f2bfd758a0>)
2025-11-05T17:50:25.3019864Z
2025-11-05T17:50:25.3020250Z /home/runner/work/borg/borg/src/borg/testsuite/archiver/__init__.py:362: AssertionError
2025-11-05T17:50:25.3021191Z =========================== short test summary info ============================
2025-11-05T17:50:25.3029458Z FAILED src/borg/testsuite/archiver/diff_cmd_test.py::test_hard_link_deletion_and_replacement[archiver] - AssertionError: unexpected match for .*input/b/hardlink in ['[mtime: Wed, 2025-11-05 17:45:53 +0000 -> Wed, 2025-11-05 17:45:53 +0000] [ctime: Wed, 2025-11-05 17:45:53 +0000 -> Wed, 2025-11-05 17:45:53 +0000] input/a', '[ctime: Wed, 2025-11-05 17:45:53 +0000 -> Wed, 2025-11-05 17:45:53 +0000] input/b/hardlink', 'added: 6 B input/a/hardlink']
2025-11-05T17:50:25.3031350Z assert not True
2025-11-05T17:50:25.3032052Z + where True = any(<generator object assert_line_not_exists.<locals>.<genexpr> at 0x12f2bfd758a0>)
2025-11-05T17:50:25.3032789Z =========== 1 failed, 1592 passed, 388 skipped in 347.92s (0:05:47) ============
Tried to fix this one:
- It seems there is a ctime change for the b hardlink for unknown reasons.
- When trying to add stat calls + debug output, the test failure vanishes.
- When removing the stat calls and the debug output again and adding a granularity_sleep, it fails again.
@cr1901 Do you have an idea? Test fails can be seen in CI for freebsd.
If we can't fix this, I tend to just remove this test, see also the troubles in #9153.