borgmatic-collective/borgmatic
9
71
Fork 49
Code Issues 55 Pull Requests 4 Actions 1 Packages Releases 157 Activity

Spot check crashes #968

New Issue
Closed
opened 2025-01-16 11:37:24 +00:00 by fuero · 10 comments
fuero commented 2025-01-16 11:37:24 +00:00
Copy Link

What I'm trying to do and why

I tried adding spot checks like this:

# List of checks to run to validate your backups.
check_last: 3
checks:
  - name: spot
    frequency: 1 week
    count_tolerance_percentage: 10
    data_sample_percentage: 1
    data_tolerance_percentage: 0.5
  - name: repository
    frequency: 1 month
  - name: archives
    frequency: 1 month

Steps to reproduce

  1. Add checks as outlined
  2. Run borgmatic check -v2 --only spot --progress -n

Actual behavior

ssh://borgbackup@backuprepo/path: Error running actions for repository
not enough values to unpack (expected 2, got 1)

Expected behavior

Passing the spot check without error

Other notes / implementation ideas

I've added logging with import traceback:

RemoteRepository: 164.11 kB bytes sent, 108.77 MB bytes received, 3104 messages sent
terminating with success status, rc 0
Traceback (most recent call last):
  File "/usr/lib/python3.13/site-packages/borgmatic/commands/borgmatic.py", line 146, in run_configuration
    yield from run_actions(
    ...<8 lines>...
    )
  File "/usr/lib/python3.13/site-packages/borgmatic/commands/borgmatic.py", line 373, in run_actions
    borgmatic.actions.check.run_check(
    ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~^
        config_filename,
        ^^^^^^^^^^^^^^^^
    ...<7 lines>...
        remote_path,
        ^^^^^^^^^^^^
    )
    ^
  File "/usr/lib/python3.13/site-packages/borgmatic/actions/check.py", line 769, in run_check
    spot_check(
    ~~~~~~~~~~^
        repository,
        ^^^^^^^^^^^
    ...<5 lines>...
        borgmatic_runtime_directory,
        ^^^^^^^^^^^^^^^^^^^^^^^^^^^^
    )
    ^
  File "/usr/lib/python3.13/site-packages/borgmatic/actions/check.py", line 625, in spot_check
    archive_paths = collect_spot_check_archive_paths(
        repository,
    ...<6 lines>...
        borgmatic_runtime_directory,
    )
  File "/usr/lib/python3.13/site-packages/borgmatic/actions/check.py", line 445, in collect_spot_check_archive_paths
    return tuple(
        path
    ...<14 lines>...
        if pathlib.Path(borgmatic_runtime_directory) not in pathlib.Path(path).parents
    )
  File "/usr/lib/python3.13/site-packages/borgmatic/actions/check.py", line 457, in <genexpr>
    for (file_type, path) in (line.split(' ', 1),)
        ^^^^^^^^^^^^^^^^^
ValueError: not enough values to unpack (expected 2, got 1)

I've dumped the output from borgmatic.borg.list.capture_archive_listing to the console with pprint:

'd /var/lib/borgmatic/borgmatic'
'd /var/lib/borgmatic/borgmatic/checks'
('d '
 '/var/lib/borgmatic/borgmatic/checks/c2d7d00aea9f53e9b1b88b86b5895a563e3d4a367165ec57cc39ce63802e6a79')
('- '
 '/var/lib/borgmatic/borgmatic/checks/c2d7d00aea9f53e9b1b88b86b5895a563e3d4a367165ec57cc39ce63802e6a79/repository')
('d '
 '/var/lib/borgmatic/borgmatic/checks/c2d7d00aea9f53e9b1b88b86b5895a563e3d4a367165ec57cc39ce63802e6a79/archives')
('- '
 '/var/lib/borgmatic/borgmatic/checks/c2d7d00aea9f53e9b1b88b86b5895a563e3d4a367165ec57cc39ce63802e6a79/archives/98e139bdce3cc101dfacb7103e51e86214b2433cee4cc884df871873c7daa0f0')
('- '
 '/var/lib/borgmatic/borgmatic/checks/c2d7d00aea9f53e9b1b88b86b5895a563e3d4a367165ec57cc39ce63802e6a79/archives/5b39eb3d2ace2c2200255dd92f1565be627b366f3fa7f32ee9113f7fd548afc6')

So I'm guessing that this output of varying types is what causes the problem.

borgmatic version

1.9.5

borgmatic installation method

pacman

Borg version

1.4.0

Python version

No response

Database version (if applicable)

3.13.1

Operating system and version

Arch Linux

### What I'm trying to do and why I tried adding `spot` checks like this: ```yaml # List of checks to run to validate your backups. check_last: 3 checks: - name: spot frequency: 1 week count_tolerance_percentage: 10 data_sample_percentage: 1 data_tolerance_percentage: 0.5 - name: repository frequency: 1 month - name: archives frequency: 1 month ``` ### Steps to reproduce 1. Add checks as outlined 2. Run `borgmatic check -v2 --only spot --progress -n` ### Actual behavior ``` ssh://borgbackup@backuprepo/path: Error running actions for repository not enough values to unpack (expected 2, got 1) ``` ### Expected behavior Passing the `spot` check without error ### Other notes / implementation ideas I've added logging with `import traceback`: ``` RemoteRepository: 164.11 kB bytes sent, 108.77 MB bytes received, 3104 messages sent terminating with success status, rc 0 Traceback (most recent call last): File "/usr/lib/python3.13/site-packages/borgmatic/commands/borgmatic.py", line 146, in run_configuration yield from run_actions( ...<8 lines>... ) File "/usr/lib/python3.13/site-packages/borgmatic/commands/borgmatic.py", line 373, in run_actions borgmatic.actions.check.run_check( ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~^ config_filename, ^^^^^^^^^^^^^^^^ ...<7 lines>... remote_path, ^^^^^^^^^^^^ ) ^ File "/usr/lib/python3.13/site-packages/borgmatic/actions/check.py", line 769, in run_check spot_check( ~~~~~~~~~~^ repository, ^^^^^^^^^^^ ...<5 lines>... borgmatic_runtime_directory, ^^^^^^^^^^^^^^^^^^^^^^^^^^^^ ) ^ File "/usr/lib/python3.13/site-packages/borgmatic/actions/check.py", line 625, in spot_check archive_paths = collect_spot_check_archive_paths( repository, ...<6 lines>... borgmatic_runtime_directory, ) File "/usr/lib/python3.13/site-packages/borgmatic/actions/check.py", line 445, in collect_spot_check_archive_paths return tuple( path ...<14 lines>... if pathlib.Path(borgmatic_runtime_directory) not in pathlib.Path(path).parents ) File "/usr/lib/python3.13/site-packages/borgmatic/actions/check.py", line 457, in <genexpr> for (file_type, path) in (line.split(' ', 1),) ^^^^^^^^^^^^^^^^^ ValueError: not enough values to unpack (expected 2, got 1) ``` I've dumped the output from `borgmatic.borg.list.capture_archive_listing` to the console with `pprint`: ``` 'd /var/lib/borgmatic/borgmatic' 'd /var/lib/borgmatic/borgmatic/checks' ('d ' '/var/lib/borgmatic/borgmatic/checks/c2d7d00aea9f53e9b1b88b86b5895a563e3d4a367165ec57cc39ce63802e6a79') ('- ' '/var/lib/borgmatic/borgmatic/checks/c2d7d00aea9f53e9b1b88b86b5895a563e3d4a367165ec57cc39ce63802e6a79/repository') ('d ' '/var/lib/borgmatic/borgmatic/checks/c2d7d00aea9f53e9b1b88b86b5895a563e3d4a367165ec57cc39ce63802e6a79/archives') ('- ' '/var/lib/borgmatic/borgmatic/checks/c2d7d00aea9f53e9b1b88b86b5895a563e3d4a367165ec57cc39ce63802e6a79/archives/98e139bdce3cc101dfacb7103e51e86214b2433cee4cc884df871873c7daa0f0') ('- ' '/var/lib/borgmatic/borgmatic/checks/c2d7d00aea9f53e9b1b88b86b5895a563e3d4a367165ec57cc39ce63802e6a79/archives/5b39eb3d2ace2c2200255dd92f1565be627b366f3fa7f32ee9113f7fd548afc6') ``` So I'm guessing that this output of varying types is what causes the problem. ### borgmatic version 1.9.5 ### borgmatic installation method pacman ### Borg version 1.4.0 ### Python version _No response_ ### Database version (if applicable) 3.13.1 ### Operating system and version Arch Linux
witten commented 2025-01-16 17:29:44 +00:00
Owner
Copy Link

Thanks for filing this—and for all the debugging! Can I get a look at your pprint statements? I'm having a hard time understanding what that output even means! For instance, if that third output line was really a tuple instead of a string, I'd expect pprint to put a comma somewhere in there...

Thanks for filing this—and for all the debugging! Can I get a look at your `pprint` statements? I'm having a hard time understanding what that output even means! For instance, if that third output line was really a tuple instead of a string, I'd expect `pprint` to put a comma somewhere in there...
fuero commented 2025-01-17 23:03:34 +00:00
Author
Copy Link

Here's what I've added (apart from the import pprint statement):

In actions/check.py, line 430:

[...]
    borgmatic_source_directory = borgmatic.config.paths.get_borgmatic_source_directory(config)

    for line in borgmatic.borg.list.capture_archive_listing(
        repository['path'],
        archive,
        config,
        local_borg_version,
        global_arguments,
        path_format='{type} /{path}{NL}',  # noqa: FS003
        local_path=local_path,
        remote_path=remote_path,
    ):
        pprint.pprint(line)

    return tuple(
[...]
Here's what I've added (apart from the `import pprint` statement): In `actions/check.py`, line 430: ```python [...] borgmatic_source_directory = borgmatic.config.paths.get_borgmatic_source_directory(config) for line in borgmatic.borg.list.capture_archive_listing( repository['path'], archive, config, local_borg_version, global_arguments, path_format='{type} /{path}{NL}', # noqa: FS003 local_path=local_path, remote_path=remote_path, ): pprint.pprint(line) return tuple( [...] ```
witten commented 2025-01-18 01:53:29 +00:00
Owner
Copy Link

I'm still at a bit of a loss as to what's going on here. In addition to the pprint(), would you mind doing a print(type(line)) as well? I can't figure out what kind of data would even result in the pprint output you included.

Also, what version of Python are you using? Thanks.

I'm still at a bit of a loss as to what's going on here. In addition to the `pprint()`, would you mind doing a `print(type(line))` as well? I can't figure out what kind of data would even result in the `pprint` output you included. Also, what version of Python are you using? Thanks.
witten commented 2025-01-18 01:57:19 +00:00
Owner
Copy Link

Aha, I think I figured out at least part of it. (You can skip the type() thing unless you'd like to verify...) I'm guessing that all the lines are actually strings, and, confusingly, the varied pprint output is what happens with super long lines vs. shorter lines. You can reproduce that behavior yourself just in an interactive Python session by pprinting a long line starting with "d " (note the space) vs. a short line that starts with "d ".

Aha, I think I figured out at least part of it. (You can skip the `type()` thing unless you'd like to verify...) I'm guessing that all the lines are actually strings, and, confusingly, the varied `pprint` output is what happens with super long lines vs. shorter lines. You can reproduce that behavior yourself just in an interactive Python session by `pprint`ing a long line starting with "d " (note the space) vs. a short line that starts with "d ".
witten commented 2025-01-18 02:11:57 +00:00
Owner
Copy Link

So another debugging thing you can do.. Right after your pprint(), try adding a pprint(line.split(' ', 1)). That will hopefully show us the line that triggers the error.

So another debugging thing you can do.. Right *after* your `pprint()`, try adding a `pprint(line.split(' ', 1))`. That will hopefully show us the line that triggers the error.
fuero commented 2025-01-18 13:41:52 +00:00
Author
Copy Link

In short: The crash seems to be caused by a line break in the file name.

Sorry for making it more compilcated, I was not aware of pprint's behaviour.

Python version is 3.13.1

I've included the pprint Statements you suggested, and also forced the code to crash immediately once it encounters an invalid line:

['d',
 '/home/fuero/.local/share/pass/xxxxxxxxxxxxxxx/xxxxxxxxxxxxxxx.1password.com/Team']
<class 'str'>
['Team']
Traceback (most recent call last):
  File "/usr/lib/python3.13/site-packages/borgmatic/commands/borgmatic.py", line 146, in run_configuration
    yield from run_actions(
    ...<8 lines>...
    )
  File "/usr/lib/python3.13/site-packages/borgmatic/commands/borgmatic.py", line 373, in run_actions
    borgmatic.actions.check.run_check(
    ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~^
        config_filename,
        ^^^^^^^^^^^^^^^^
    ...<7 lines>...
        remote_path,
        ^^^^^^^^^^^^
    )
    ^
  File "/usr/lib/python3.13/site-packages/borgmatic/actions/check.py", line 772, in run_check
    spot_check(
    ~~~~~~~~~~^
        repository,
        ^^^^^^^^^^^
    ...<5 lines>...
        borgmatic_runtime_directory,
        ^^^^^^^^^^^^^^^^^^^^^^^^^^^^
    )
    ^
  File "/usr/lib/python3.13/site-packages/borgmatic/actions/check.py", line 628, in spot_check
    archive_paths = collect_spot_check_archive_paths(
        repository,
    ...<6 lines>...
        borgmatic_runtime_directory,
    )
  File "/usr/lib/python3.13/site-packages/borgmatic/actions/check.py", line 445, in collect_spot_check_archive_paths
    for (file_type, path) in (line.split(' ', 1),):
        ^^^^^^^^^^^^^^^^^
ValueError: not enough values to unpack (expected 2, got 1)

Here's stat's output:

# stat /home/fuero/.local/share/pass/xxxxxxxxxxxxxxx/xxxxxxxxxxxxxxx.1password.com/Team*
  File: /home/fuero/.local/share/pass/xxxxxxxxxxxxxxx/xxxxxxxxxxxxxxx.1password.com/Team
  Size: 12288     	Blocks: 24         IO Block: 4096   directory
Device: 259,3	Inode: 115739607   Links: 2
Access: (0700/drwx------)  Uid: ( 1000/   fuero)   Gid: ( 1000/   fuero)
Access: 2025-01-17 23:40:53.407455702 +0100
Modify: 2024-07-29 17:23:18.472612063 +0200
Change: 2024-07-29 17:23:18.472612063 +0200
 Birth: 2024-07-29 17:23:18.462611940 +0200
  File: /home/fuero/.local/share/pass/xxxxxxxxxxxxxxx/xxxxxxxxxxxxxxx.1password.com/Team
Team
  Size: 4096      	Blocks: 8          IO Block: 4096   directory
Device: 259,3	Inode: 115739605   Links: 2
Access: (0700/drwx------)  Uid: ( 1000/   fuero)   Gid: ( 1000/   fuero)
Access: 2025-01-17 23:40:53.409455747 +0100
Modify: 2024-07-29 17:23:18.462611940 +0200
Change: 2024-07-29 17:23:18.462611940 +0200
 Birth: 2024-07-29 17:23:18.462611940 +0200

And what Python reads with os.listdir():

>>> os.listdir('/home/fuero/.local/share/pass/xxxxxxxxxxxxxxx/xxxxxxxxxxxxxxx.1password.com/')
['Team\nTeam', 'Team']
In short: The crash seems to be caused by a line break in the file name. Sorry for making it more compilcated, I was not aware of `pprint`'s behaviour. Python version is 3.13.1 I've included the `pprint` Statements you suggested, and also forced the code to crash immediately once it encounters an invalid `line`: ``` ['d', '/home/fuero/.local/share/pass/xxxxxxxxxxxxxxx/xxxxxxxxxxxxxxx.1password.com/Team'] <class 'str'> ['Team'] Traceback (most recent call last): File "/usr/lib/python3.13/site-packages/borgmatic/commands/borgmatic.py", line 146, in run_configuration yield from run_actions( ...<8 lines>... ) File "/usr/lib/python3.13/site-packages/borgmatic/commands/borgmatic.py", line 373, in run_actions borgmatic.actions.check.run_check( ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~^ config_filename, ^^^^^^^^^^^^^^^^ ...<7 lines>... remote_path, ^^^^^^^^^^^^ ) ^ File "/usr/lib/python3.13/site-packages/borgmatic/actions/check.py", line 772, in run_check spot_check( ~~~~~~~~~~^ repository, ^^^^^^^^^^^ ...<5 lines>... borgmatic_runtime_directory, ^^^^^^^^^^^^^^^^^^^^^^^^^^^^ ) ^ File "/usr/lib/python3.13/site-packages/borgmatic/actions/check.py", line 628, in spot_check archive_paths = collect_spot_check_archive_paths( repository, ...<6 lines>... borgmatic_runtime_directory, ) File "/usr/lib/python3.13/site-packages/borgmatic/actions/check.py", line 445, in collect_spot_check_archive_paths for (file_type, path) in (line.split(' ', 1),): ^^^^^^^^^^^^^^^^^ ValueError: not enough values to unpack (expected 2, got 1) ``` Here's `stat`'s output: ``` # stat /home/fuero/.local/share/pass/xxxxxxxxxxxxxxx/xxxxxxxxxxxxxxx.1password.com/Team* File: /home/fuero/.local/share/pass/xxxxxxxxxxxxxxx/xxxxxxxxxxxxxxx.1password.com/Team Size: 12288 Blocks: 24 IO Block: 4096 directory Device: 259,3 Inode: 115739607 Links: 2 Access: (0700/drwx------) Uid: ( 1000/ fuero) Gid: ( 1000/ fuero) Access: 2025-01-17 23:40:53.407455702 +0100 Modify: 2024-07-29 17:23:18.472612063 +0200 Change: 2024-07-29 17:23:18.472612063 +0200 Birth: 2024-07-29 17:23:18.462611940 +0200 File: /home/fuero/.local/share/pass/xxxxxxxxxxxxxxx/xxxxxxxxxxxxxxx.1password.com/Team Team Size: 4096 Blocks: 8 IO Block: 4096 directory Device: 259,3 Inode: 115739605 Links: 2 Access: (0700/drwx------) Uid: ( 1000/ fuero) Gid: ( 1000/ fuero) Access: 2025-01-17 23:40:53.409455747 +0100 Modify: 2024-07-29 17:23:18.462611940 +0200 Change: 2024-07-29 17:23:18.462611940 +0200 Birth: 2024-07-29 17:23:18.462611940 +0200 ``` And what Python reads with `os.listdir()`: ``` >>> os.listdir('/home/fuero/.local/share/pass/xxxxxxxxxxxxxxx/xxxxxxxxxxxxxxx.1password.com/') ['Team\nTeam', 'Team'] ```
witten commented 2025-01-18 17:29:26 +00:00
Owner
Copy Link

Ah, excellent sleuthing! A filename containing a newline would definitely make sense as to the cause here. I'll see what I can do about it. It may be a little tough because the Borg output is newline-separated....

Ah, excellent sleuthing! A filename containing a newline would definitely make sense as to the cause here. I'll see what I can do about it. It may be a little tough because the Borg output is newline-separated....
witten added the bug label 2025-01-18 17:29:33 +00:00
witten commented 2025-01-18 17:57:17 +00:00
Owner
Copy Link

Okay, this is fixed in main and will be part of the next release! I instructed Borg to separate filenames in the listing with null characters instead of newlines. That allows borgmatic to consume filenames that contain newlines when doing the spot check. Thanks again!

Okay, this is fixed in main and will be part of the next release! I instructed Borg to separate filenames in the listing with null characters instead of newlines. That allows borgmatic to consume filenames that contain newlines when doing the spot check. Thanks again!
witten commented 2025-01-23 20:15:58 +00:00
Owner
Copy Link

Released in borgmatic 1.9.7!

Released in borgmatic 1.9.7!
🎉 1
witten commented 2025-01-27 18:52:42 +00:00
Owner
Copy Link

Be aware of this related bug and fix as well: #981.

Be aware of this related bug and fix as well: #981.
Sign in to join this conversation.
No Branch/Tag Specified
Branches Tags
Labels
Clear labels
blocked
breaking
bug
data loss
design finalized
good first issue
new feature area
question / support
security
waiting for response
No Label bug
Milestone
No items
No Milestone
Assignees
Clear assignees
witten
No Assignees
2 Participants
Notifications
Due Date
No due date set.
Dependencies

No dependencies set.

Reference: borgmatic-collective/borgmatic#968
Delete Branch "%!s()"

Deleting a branch is permanent. Although the deleted branch may continue to exist for a short time before it actually gets removed, it CANNOT be undone in most cases. Continue?