borgmatic hangs when location.patterns includes /root/.borgmatic and database hooks are active #582

New Issue

Kritzefitz · 2022-09-08T13:50:27Z

Kritzefitz commented

2022-09-08 13:50:27 +00:00

What I'm trying to do and why

Trying to use database hooks while location.patterns contains R /root.

Steps to reproduce (if a bug)

# borg init -e none /repo
# mkdir /the-files
# echo 'the content' > /the-files/the-file
# cat /etc/borgmatic/config.yaml
location:
    patterns:
      - 'R /root'
    repositories:
        - /repo
hooks:
  postgresql_databases:
    - name: test
      hostname: host.containers.internal
      username: test
      password: "12345"
# borgmatic create -v2 --progress

Actual behavior (if a bug)

The last step in the reproduction section will hang forever as follows:

# borgmatic create -v2 --progress
Ensuring legacy configuration is upgraded
/etc/borgmatic/config.yaml: No commands to run for pre-everything hook
borg --version --debug --show-rc
/etc/borgmatic/config.yaml: No commands to run for pre-actions hook
/etc/borgmatic/config.yaml: No commands to run for pre-backup hook
/repo: Creating archive
/repo: Calling postgresql_databases hook function remove_database_dumps
/repo: Removing PostgreSQL database dumps
/repo: Calling postgresql_databases hook function dump_databases
/repo: Dumping PostgreSQL databases
/repo: Dumping PostgreSQL database test to /root/.borgmatic/postgresql_databases/host.containers.internal/test
pg_dump --no-password --clean --if-exists --host host.containers.internal --username test --format custom test > /root/.borgmatic/postgresql_databases/host.containers.internal/test
borg create --patterns-from /tmp/tmpk9n4uulx --one-file-system --read-special --debug --show-rc --progress /repo::{hostname}-{now:%Y-%m-%dT%H:%M:%S.%f} > 
using builtin fallback logging configuration
35 self tests completed in 0.07 seconds
Verified integrity of /repo/index.25
TAM-verified manifest
security: read previous location '/repo'
security: read manifest timestamp '2022-09-08T13:26:37.798194'
security: determined newest manifest timestamp as 2022-09-08T13:26:37.798194
security: repository checks ok, allowing access
Creating archive at "/repo::{hostname}-{now:%Y-%m-%dT%H:%M:%S.%f}"
Verified integrity of /root/.cache/borg/801b033f859448a6351002613917f45c8c1be1a93604c52604bc489aaee6dee7/chunks
Reading files cache ...
Verified integrity of /root/.cache/borg/801b033f859448a6351002613917f45c8c1be1a93604c52604bc489aaee6dee7/files
security: read previous location '/repo'
security: read manifest timestamp '2022-09-08T13:26:37.798194'
security: determined newest manifest timestamp as 2022-09-08T13:26:37.798194
security: repository checks ok, allowing access
Processing files ...
Cleaned up 0 uncommitted segment files (== everything after segment 25).                                             
Verified integrity of /repo/hints.25

Expected behavior (if a bug)

The backup should complete as usual.

Other notes / implementation ideas

The patterns file generated by borgmatic looks like this:

# cat /tmp/tmpk9n4uulx 
R /root
R /root/.borgmatic

Apparently this causes borg to attempt to backup the pipes in /root/.borgmatic/*_databases twice. One time as a subdirectory of R /root and a second time for R /root/.borgmatic.

straceing the borg process reveals that the process is indeed stuck on trying to open one of the named pipes:

# strace -p 117715
strace: Process 117715 attached
openat(9, "test", O_RDONLY|O_NOCTTY|O_NOFOLLOW|O_NOATIME|O_CLOEXEC

Watching the output of --progress on a sufficiently large database, it is visible that borg makes a backup of the pipe once and later tries to open the pipe again and gets stuck.

Apparently this doesn't happen when using locations.source_directories instead. My guess is that borg deduplicates directories passed on the command line, but doesn't deduplicate roots passed in patterns.

This might be related to #578, but isn't solvable by deleting the pipes manually, since the error state is reproducibly generated by borgmatic at startup.

Environment

borgmatic version: 1.7.1

borgmatic installation method: pip

Borg version: 1.2.2

Python version: 3.10.7

Database version (if applicable): 14.5 (but probably not relevant)

operating system and version: Docker container docker.io/library/python:3-bullseye

#### What I'm trying to do and why Trying to use database hooks while `location.patterns` contains `R /root`. #### Steps to reproduce (if a bug) ``` # borg init -e none /repo # mkdir /the-files # echo 'the content' > /the-files/the-file # cat /etc/borgmatic/config.yaml location: patterns: - 'R /root' repositories: - /repo hooks: postgresql_databases: - name: test hostname: host.containers.internal username: test password: "12345" # borgmatic create -v2 --progress ``` #### Actual behavior (if a bug) The last step in the reproduction section will hang forever as follows: ``` # borgmatic create -v2 --progress Ensuring legacy configuration is upgraded /etc/borgmatic/config.yaml: No commands to run for pre-everything hook borg --version --debug --show-rc /etc/borgmatic/config.yaml: No commands to run for pre-actions hook /etc/borgmatic/config.yaml: No commands to run for pre-backup hook /repo: Creating archive /repo: Calling postgresql_databases hook function remove_database_dumps /repo: Removing PostgreSQL database dumps /repo: Calling postgresql_databases hook function dump_databases /repo: Dumping PostgreSQL databases /repo: Dumping PostgreSQL database test to /root/.borgmatic/postgresql_databases/host.containers.internal/test pg_dump --no-password --clean --if-exists --host host.containers.internal --username test --format custom test > /root/.borgmatic/postgresql_databases/host.containers.internal/test borg create --patterns-from /tmp/tmpk9n4uulx --one-file-system --read-special --debug --show-rc --progress /repo::{hostname}-{now:%Y-%m-%dT%H:%M:%S.%f} > using builtin fallback logging configuration 35 self tests completed in 0.07 seconds Verified integrity of /repo/index.25 TAM-verified manifest security: read previous location '/repo' security: read manifest timestamp '2022-09-08T13:26:37.798194' security: determined newest manifest timestamp as 2022-09-08T13:26:37.798194 security: repository checks ok, allowing access Creating archive at "/repo::{hostname}-{now:%Y-%m-%dT%H:%M:%S.%f}" Verified integrity of /root/.cache/borg/801b033f859448a6351002613917f45c8c1be1a93604c52604bc489aaee6dee7/chunks Reading files cache ... Verified integrity of /root/.cache/borg/801b033f859448a6351002613917f45c8c1be1a93604c52604bc489aaee6dee7/files security: read previous location '/repo' security: read manifest timestamp '2022-09-08T13:26:37.798194' security: determined newest manifest timestamp as 2022-09-08T13:26:37.798194 security: repository checks ok, allowing access Processing files ... Cleaned up 0 uncommitted segment files (== everything after segment 25). Verified integrity of /repo/hints.25 ``` #### Expected behavior (if a bug) The backup should complete as usual. #### Other notes / implementation ideas The patterns file generated by borgmatic looks like this: ``` # cat /tmp/tmpk9n4uulx R /root R /root/.borgmatic ``` Apparently this causes borg to attempt to backup the pipes in `/root/.borgmatic/*_databases` twice. One time as a subdirectory of `R /root` and a second time for `R /root/.borgmatic`. `strace`ing the borg process reveals that the process is indeed stuck on trying to open one of the named pipes: ``` # strace -p 117715 strace: Process 117715 attached openat(9, "test", O_RDONLY|O_NOCTTY|O_NOFOLLOW|O_NOATIME|O_CLOEXEC ``` Watching the output of `--progress` on a sufficiently large database, it is visible that borg makes a backup of the pipe once and later tries to open the pipe again and gets stuck. Apparently this doesn't happen when using `locations.source_directories` instead. My guess is that borg deduplicates directories passed on the command line, but doesn't deduplicate roots passed in patterns. This might be related to #578, but isn't solvable by deleting the pipes manually, since the error state is reproducibly generated by borgmatic at startup. #### Environment **borgmatic version:** 1.7.1 **borgmatic installation method:** pip **Borg version:** 1.2.2 **Python version:** 3.10.7 **Database version (if applicable):** 14.5 (but probably not relevant) **operating system and version:** Docker container docker.io/library/python:3-bullseye

witten commented

2022-09-08 15:44:43 +00:00

Ugh! Thank you for reporting this and providing all the details. Borg actually doesn't deduplicate source_directories at all—but borgmatic does! Unfortunately nothing is deduplicating the contents of patterns. So I guess that's a new thing borgmatic will need to do as part of this ticket. Or at least make sure not to add ~/.borgmatic if a parent directory is already present in patterns.

~/.borgmatic getting injected into patterns (when used) was introduced by #574 to work around a Borg bug.

Ugh! Thank you for reporting this and providing all the details. Borg actually doesn't deduplicate `source_directories` at all—but borgmatic does! Unfortunately nothing is deduplicating the contents of `patterns`. So I guess that's a new thing borgmatic will need to do as part of this ticket. Or at least make sure not to add `~/.borgmatic` if a parent directory is already present in `patterns`. `~/.borgmatic` getting injected into `patterns` (when used) was introduced by #574 to work around a Borg bug.

witten added the

bug

label 2022-09-08 15:44:55 +00:00

witten referenced this issue from a commit

2022-09-08 17:17:01 +00:00

Fix hang when database hooks are enabled and "patterns" contains a parent directory of "~/.borgmatic" (#582).

witten commented

2022-09-08 17:24:42 +00:00

I've just pushed a fix for this to master. The gist is that pattern root directories are now considered when injecting ~/.borgmatic into patterns—it won't get injected if a parent/grandparent/etc directory is already present as a root directory in patterns. The caveat is that non-root patterns are not considered; borgmatic isn't trying to parse through + /this and - /that, so it is still possible to hang yourself. It's just less likely unless you explicitly try to do so.

Thanks again for reporting this! Release forthcoming.

I've just pushed a fix for this to master. The gist is that `pattern` root directories are now considered when injecting `~/.borgmatic` into `patterns`—it won't get injected if a parent/grandparent/etc directory is already present as a root directory in `patterns`. The caveat is that non-root patterns are not considered; borgmatic isn't trying to parse through `+ /this` and `- /that`, so it is still possible to hang yourself. It's just less likely unless you explicitly try to do so. Thanks again for reporting this! Release forthcoming.

witten commented

2022-09-08 17:31:07 +00:00

Just released in borgmatic 1.7.2!

witten closed this issue

2022-09-08 17:31:07 +00:00

Sign in to join this conversation.