Silent REGRESSION in 1.8.10: backing up either files or database #903

Closed
opened 2024-08-05 15:08:42 +00:00 by raph-topo · 9 comments

What I'm trying to do and why

A Borgmatic container version (borgmatic >1.8.5 <= 1.8.11) stopped backing up files while no configuration file was changed (i.e. the container update from 1.8.5 to 1.8.11 alone has this effect).

This only concerns Borgmatic configurations which do include mysql_databases: or sqlite_databases: (and potentially all/other database hooks, but not tested).

When commenting that block out, files do show up with --list & do back up. Using --dry-dun makes files show up as well.

Steps to reproduce

# docker-compose.yml
  borgmatic:
    image: b3vis/borgmatic
    restart: always
    volumes:
      # Sources
      - nextcloud-data:/mnt/source/nextcloud-data:ro
      - nextcloud-config:/mnt/source/nextcloud-config:ro
      - nextcloud-themes:/mnt/source/nextcloud-themes:ro
      - nextcloud-custom_apps:/mnt/source/nextcloud-custom_apps:ro
      # Borgmatic
      - ./borgmatic.d:/etc/borgmatic.d:ro
      - borg-cache:/root/.cache/borg
      # SSH
      - $BORGMATIC_SSH_KEY:/root/.ssh/id_ed25519:ro
    environment:
      TZ: $TZ
    networks:
      - default
# config.yml

repositories:
  - path: ssh://xxxxxxxxx@xxxxxxxxx.repo.borgbase.com/./repo
    label: borgbase

working_directory: /mnt/source
source_directories:
  - .

mysql_databases:
  - name: nextcloud
    hostname: mariadb
    username: root
    password: wwwwwwwww
    options: --skip-comments

archive_name_format: yyyyyyyy@{now}
encryption_passphrase: wwwwwwwww
compression: lz4
match_archives: yyyyyyyy@*

retries: 2
retry_wait: 5
ssh_command: ssh -oStrictHostKeyChecking=accept-new

keep_within: 2m # 2 months
keep_monthly: 24
keep_yearly: 10

checks:
  - name: repository
  - name: archives
check_last: 1

healthchecks:
  ping_url: https://vvvvvvvvvvvvvvv/ping/zzzzzzzzzzzzzzzzzzzzz/backup-ci-yyyyyyyy
  ping_body_limit: 0

before_actions:
  - echo "`date` - Starting Action"
after_actions:
  - echo "`date` - Finished Action"
before_backup:
  - echo "`date` - Starting Backup"
after_backup:
  - echo "`date` - Finished Backup"
before_prune:
  - echo "`date` - Starting Prune"
after_prune:
  - echo "`date` - Finished Prune"
before_compact:
  - echo "`date` - Starting Compact"
after_compact:
  - echo "`date` - Finished Compact"
before_check:
  - echo "`date` - Starting Check"
after_check:
  - echo "`date` - Finished Check"
before_extract:
  - echo "`date` - Starting Extract"
after_extract:
  - echo "`date` - Finished Extract"

on_error:
  - echo "`date` - Borg Error"

Actual behavior

# borgmatic --version

1.8.13
# borgmatic create --list --verbosity 2

/etc/borgmatic.d/config.yml: No commands to run for pre-everything hook
BORG_PASSPHRASE=*** BORG_RSH=*** BORG_EXIT_CODES=*** borg --version --debug --show-rc
/etc/borgmatic.d/config.yml: Borg 1.4.0
/etc/borgmatic.d/config.yml: Calling healthchecks hook function initialize_monitor
/etc/borgmatic.d/config.yml: Calling healthchecks hook function ping_monitor
/etc/borgmatic.d/config.yml: Pinging Healthchecks start
/etc/borgmatic.d/config.yml: Using Healthchecks ping URL https://vvvvvvvvvvvvvvv/ping/zzzzzzzzzzzzzzzzzzzzz/backup-ci-yyyyyyyy/start
borgbase: Running actions for repository
/etc/borgmatic.d/config.yml: Running command for pre-actions hook
echo "`date` - Starting Action"
Mon Aug  5 15:56:37 CEST 2024 - Starting Action
/etc/borgmatic.d/config.yml: Running command for pre-backup hook
echo "`date` - Starting Backup"
Mon Aug  5 15:56:37 CEST 2024 - Starting Backup
borgbase: Creating archive
ssh://xxxxxxxxx@xxxxxxxxx.repo.borgbase.com/./repo: Calling mariadb_databases hook function remove_data_source_dumps
ssh://xxxxxxxxx@xxxxxxxxx.repo.borgbase.com/./repo: Removing MariaDB data source dumps
ssh://xxxxxxxxx@xxxxxxxxx.repo.borgbase.com/./repo: Calling mysql_databases hook function remove_data_source_dumps
ssh://xxxxxxxxx@xxxxxxxxx.repo.borgbase.com/./repo: Removing MySQL data source dumps
ssh://xxxxxxxxx@xxxxxxxxx.repo.borgbase.com/./repo: Calling mongodb_databases hook function remove_data_source_dumps
ssh://xxxxxxxxx@xxxxxxxxx.repo.borgbase.com/./repo: Removing MongoDB data source dumps
ssh://xxxxxxxxx@xxxxxxxxx.repo.borgbase.com/./repo: Calling postgresql_databases hook function remove_data_source_dumps
ssh://xxxxxxxxx@xxxxxxxxx.repo.borgbase.com/./repo: Removing PostgreSQL data source dumps
ssh://xxxxxxxxx@xxxxxxxxx.repo.borgbase.com/./repo: Calling sqlite_databases hook function remove_data_source_dumps
ssh://xxxxxxxxx@xxxxxxxxx.repo.borgbase.com/./repo: Removing SQLite data source dumps
ssh://xxxxxxxxx@xxxxxxxxx.repo.borgbase.com/./repo: Calling mysql_databases hook function dump_data_sources
ssh://xxxxxxxxx@xxxxxxxxx.repo.borgbase.com/./repo: Dumping MySQL databases
ssh://xxxxxxxxx@xxxxxxxxx.repo.borgbase.com/./repo: Dumping MySQL database "nextcloud" to /root/.borgmatic/mysql_databases/mariadb/nextcloud
MYSQL_PWD=*** mysqldump --skip-comments --add-drop-database --host mariadb --protocol tcp --user root --databases nextcloud --result-file /root/.borgmatic/mysql_databases/mariadb/nextcloud
ssh://xxxxxxxxx@xxxxxxxxx.repo.borgbase.com/./repo: Ignoring configured "read_special" value of false, as true is needed for database hooks.
ssh://xxxxxxxxx@xxxxxxxxx.repo.borgbase.com/./repo: Collecting special file paths
BORG_PASSPHRASE=*** BORG_RSH=*** BORG_EXIT_CODES=*** borg create --compression lz4 --one-file-system --read-special --list --filter AMEx- ssh://xxxxxxxxx@xxxxxxxxx.repo.borgbase.com/./repo::yyyyyyyy@{now} . /etc/borgmatic.d/config.yml /root/.borgmatic --dry-run --list
BORG_PASSPHRASE=*** BORG_RSH=*** BORG_EXIT_CODES=*** borg create --compression lz4 --one-file-system --read-special --list --filter AMEx- --debug --show-rc ssh://xxxxxxxxx@xxxxxxxxx.repo.borgbase.com/./repo::yyyyyyyy@{now} . /etc/borgmatic.d/config.yml /root/.borgmatic
using builtin fallback logging configuration
33 self tests completed in 0.25 seconds
SSH command line: ['ssh', '-oStrictHostKeyChecking=accept-new', 'xxxxxxxxx@xxxxxxxxx.repo.borgbase.com', 'borg', 'serve', '--debug']
Remote: using builtin fallback logging configuration
Remote: borg selftest disabled via BORG_SELFTEST env variable
Remote: using builtin fallback logging configuration
Remote: Initialized logging system for JSON-based protocol
Remote: Resolving repository path b'/./repo'
Remote: Resolved repository path to '/srv/repos/xxxxxxxxx/repo'
Remote: Verified integrity of /srv/repos/xxxxxxxxx/repo/index.51055
TAM-verified manifest
security: read previous location 'ssh://xxxxxxxxx@xxxxxxxxx.repo.borgbase.com/./repo'
security: read manifest timestamp '2024-08-05T13:52:36.934529'
security: determined newest manifest timestamp as 2024-08-05T13:52:36.934529
security: repository checks ok, allowing access
Creating archive at "ssh://xxxxxxxxx@xxxxxxxxx.repo.borgbase.com/./repo::yyyyyyyy@2024-08-05T15:56:37"
Verified integrity of /root/.cache/borg/c156080772560547047266a0d0168781f1757c455c86346e6a0798d7b8df0e51/chunks
Reading files cache ...
Verified integrity of /root/.cache/borg/c156080772560547047266a0d0168781f1757c455c86346e6a0798d7b8df0e51/files
security: read previous location 'ssh://xxxxxxxxx@xxxxxxxxx.repo.borgbase.com/./repo'
security: read manifest timestamp '2024-08-05T13:52:36.934529'
security: determined newest manifest timestamp as 2024-08-05T13:52:36.934529
security: repository checks ok, allowing access
Processing files ...
A /root/.borgmatic/bootstrap/manifest.json
A /root/.borgmatic/mysql_databases/mariadb/nextcloud
Remote: Cleaned up 0 uncommitted segment files (== everything after segment 51055).
Remote: Verified integrity of /srv/repos/xxxxxxxxx/repo/hints.51055
Remote: Storage quota: 375.92 GB out of 2.87 TB used.
Remote: check_free_space: required bytes 211581658, free bytes 15142892871680
Remote: Storage quota: 375.93 GB out of 2.87 TB used.
security: saving state for c156080772560547047266a0d0168781f1757c455c86346e6a0798d7b8df0e51 to /root/.config/borg/security/c156080772560547047266a0d0168781f1757c455c86346e6a0798d7b8df0e51
security: current location   ssh://xxxxxxxxx@xxxxxxxxx.repo.borgbase.com/./repo
security: key type           5
security: manifest timestamp 2024-08-05T13:57:08.582466
RemoteRepository: 2.58 MB bytes sent, 215.10 kB bytes received, 14 messages sent
terminating with success status, rc 0
/etc/borgmatic.d/config.yml: Calling mariadb_databases hook function remove_data_source_dumps
/etc/borgmatic.d/config.yml: Removing MariaDB data source dumps
/etc/borgmatic.d/config.yml: Calling mysql_databases hook function remove_data_source_dumps
/etc/borgmatic.d/config.yml: Removing MySQL data source dumps
/etc/borgmatic.d/config.yml: Calling mongodb_databases hook function remove_data_source_dumps
/etc/borgmatic.d/config.yml: Removing MongoDB data source dumps
/etc/borgmatic.d/config.yml: Calling postgresql_databases hook function remove_data_source_dumps
/etc/borgmatic.d/config.yml: Removing PostgreSQL data source dumps
/etc/borgmatic.d/config.yml: Calling sqlite_databases hook function remove_data_source_dumps
/etc/borgmatic.d/config.yml: Removing SQLite data source dumps
/etc/borgmatic.d/config.yml: Running command for post-backup hook
echo "`date` - Finished Backup"
Mon Aug  5 15:57:09 CEST 2024 - Finished Backup
/etc/borgmatic.d/config.yml: Running command for post-actions hook
echo "`date` - Finished Action"
Mon Aug  5 15:57:09 CEST 2024 - Finished Action
/etc/borgmatic.d/config.yml: Calling healthchecks hook function ping_monitor
/etc/borgmatic.d/config.yml: Pinging Healthchecks log
/etc/borgmatic.d/config.yml: Using Healthchecks ping URL https://vvvvvvvvvvvvvvv/ping/zzzzzzzzzzzzzzzzzzzzz/backup-ci-yyyyyyyy/log
/etc/borgmatic.d/config.yml: Calling healthchecks hook function ping_monitor
/etc/borgmatic.d/config.yml: Pinging Healthchecks finish
/etc/borgmatic.d/config.yml: Using Healthchecks ping URL https://vvvvvvvvvvvvvvv/ping/zzzzzzzzzzzzzzzzzzzzz/backup-ci-yyyyyyyy
/etc/borgmatic.d/config.yml: Calling healthchecks hook function destroy_monitor
/etc/borgmatic.d/config.yml: No commands to run for post-everything hook

summary:
/etc/borgmatic.d/config.yml: Loading configuration file
/etc/borgmatic.d/config.yml: Successfully ran configuration file
# borgmatic list --archive latest  --verbosity 2

BORG_PASSPHRASE=*** BORG_RSH=*** BORG_EXIT_CODES=*** borg --version --debug --show-rc
/etc/borgmatic.d/config.yml: Borg 1.4.0
borgbase: Running actions for repository
/etc/borgmatic.d/config.yml: Running command for pre-actions hook
echo "`date` - Starting Action"
Mon Aug  5 15:59:02 CEST 2024 - Starting Action
BORG_PASSPHRASE=*** BORG_RSH=*** BORG_EXIT_CODES=*** borg list --last 1 --short ssh://xxxxxxxxx@xxxxxxxxx.repo.borgbase.com/./repo
ssh://xxxxxxxxx@xxxxxxxxx.repo.borgbase.com/./repo: Latest archive is yyyyyyyy@2024-08-05T15:56:37
ssh://xxxxxxxxx@xxxxxxxxx.repo.borgbase.com/./repo: Listing archive yyyyyyyy@2024-08-05T15:56:37
BORG_PASSPHRASE=*** BORG_RSH=*** BORG_EXIT_CODES=*** borg list --debug --show-rc ssh://xxxxxxxxx@xxxxxxxxx.repo.borgbase.com/./repo::yyyyyyyy@2024-08-05T15:56:37
using builtin fallback logging configuration
33 self tests completed in 0.23 seconds
SSH command line: ['ssh', '-oStrictHostKeyChecking=accept-new', 'xxxxxxxxx@xxxxxxxxx.repo.borgbase.com', 'borg', 'serve', '--debug']
Remote: using builtin fallback logging configuration
Remote: borg selftest disabled via BORG_SELFTEST env variable
Remote: using builtin fallback logging configuration
Remote: Initialized logging system for JSON-based protocol
Remote: Resolving repository path b'/./repo'
Remote: Resolved repository path to '/srv/repos/xxxxxxxxx/repo'
Remote: Verified integrity of /srv/repos/xxxxxxxxx/repo/index.51059
TAM-verified manifest
security: read previous location 'ssh://xxxxxxxxx@xxxxxxxxx.repo.borgbase.com/./repo'
security: read manifest timestamp '2024-08-05T13:57:08.582466'
security: determined newest manifest timestamp as 2024-08-05T13:57:08.582466
security: repository checks ok, allowing access
Archive authentication DISABLED.
TAM-verified archive
drwxr-xr-x root   root          0 Mon, 2024-08-05 12:29:59 .
drwxr-xr-x xfs    xfs           0 Sun, 2023-03-19 23:32:48 nextcloud-config
drwxr-xr-x xfs    xfs           0 Mon, 2024-08-05 13:59:22 nextcloud-custom_apps
drwxrwx--- xfs    root          0 Fri, 2024-07-26 15:41:11 nextcloud-data
drwxr-xr-x xfs    xfs           0 Sun, 2023-02-12 18:31:34 nextcloud-themes
-rw-r--r--   1000 video      1445 Mon, 2024-08-05 15:52:02 etc/borgmatic.d/config.yml
drwxr-xr-x root   root          0 Mon, 2024-08-05 15:56:37 root/.borgmatic
drwxr-xr-x root   root          0 Wed, 2023-07-05 10:10:01 root/.borgmatic/bootstrap
-rw-r--r-- root   root         80 Mon, 2024-08-05 15:56:37 root/.borgmatic/bootstrap/manifest.json
drwxr-xr-x root   root          0 Mon, 2024-08-05 15:56:37 root/.borgmatic/mysql_databases
drwx------ root   root          0 Mon, 2024-08-05 15:56:37 root/.borgmatic/mysql_databases/mariadb
-rw------- root   root   736421728 Mon, 2024-08-05 15:56:37 root/.borgmatic/mysql_databases/mariadb/nextcloud
RemoteRepository: 318 B bytes sent, 227.77 kB bytes received, 7 messages sent
terminating with success status, rc 0
/etc/borgmatic.d/config.yml: Running command for post-actions hook
echo "`date` - Finished Action"
Mon Aug  5 15:59:05 CEST 2024 - Finished Action

summary:
/etc/borgmatic.d/config.yml: Loading configuration file
/etc/borgmatic.d/config.yml: Successfully ran configuration file

Notice that these folders are present but empty:

drwxr-xr-x xfs    xfs           0 Sun, 2023-03-19 23:32:48 nextcloud-config
drwxr-xr-x xfs    xfs           0 Mon, 2024-08-05 13:59:22 nextcloud-custom_apps
drwxrwx--- xfs    root          0 Fri, 2024-07-26 15:41:11 nextcloud-data
drwxr-xr-x xfs    xfs           0 Sun, 2023-02-12 18:31:34 nextcloud-themes

Expected behavior

Run again, after having commented out the mysql_databases: block in config.yml.

# borgmatic --version

1.8.13
# borgmatic create --list --verbosity 2

/etc/borgmatic.d/config.yml: No commands to run for pre-everything hook
BORG_PASSPHRASE=*** BORG_RSH=*** BORG_EXIT_CODES=*** borg --version --debug --show-rc
/etc/borgmatic.d/config.yml: Borg 1.4.0
/etc/borgmatic.d/config.yml: Calling healthchecks hook function initialize_monitor
/etc/borgmatic.d/config.yml: Calling healthchecks hook function ping_monitor
/etc/borgmatic.d/config.yml: Pinging Healthchecks start
/etc/borgmatic.d/config.yml: Using Healthchecks ping URL https://vvvvvvvvvvvvvvv/ping/zzzzzzzzzzzzzzzzzzzzz/backup-ci-yyyyyyyy/start
borgbase: Running actions for repository
/etc/borgmatic.d/config.yml: Running command for pre-actions hook
echo "`date` - Starting Action"
Mon Aug  5 16:07:58 CEST 2024 - Starting Action
/etc/borgmatic.d/config.yml: Running command for pre-backup hook
echo "`date` - Starting Backup"
Mon Aug  5 16:07:58 CEST 2024 - Starting Backup
borgbase: Creating archive
ssh://xxxxxxxxx@xxxxxxxxx.repo.borgbase.com/./repo: Calling mariadb_databases hook function remove_data_source_dumps
ssh://xxxxxxxxx@xxxxxxxxx.repo.borgbase.com/./repo: Removing MariaDB data source dumps
ssh://xxxxxxxxx@xxxxxxxxx.repo.borgbase.com/./repo: Calling mysql_databases hook function remove_data_source_dumps
ssh://xxxxxxxxx@xxxxxxxxx.repo.borgbase.com/./repo: Removing MySQL data source dumps
ssh://xxxxxxxxx@xxxxxxxxx.repo.borgbase.com/./repo: Calling mongodb_databases hook function remove_data_source_dumps
ssh://xxxxxxxxx@xxxxxxxxx.repo.borgbase.com/./repo: Removing MongoDB data source dumps
ssh://xxxxxxxxx@xxxxxxxxx.repo.borgbase.com/./repo: Calling postgresql_databases hook function remove_data_source_dumps
ssh://xxxxxxxxx@xxxxxxxxx.repo.borgbase.com/./repo: Removing PostgreSQL data source dumps
ssh://xxxxxxxxx@xxxxxxxxx.repo.borgbase.com/./repo: Calling sqlite_databases hook function remove_data_source_dumps
ssh://xxxxxxxxx@xxxxxxxxx.repo.borgbase.com/./repo: Removing SQLite data source dumps
BORG_PASSPHRASE=*** BORG_RSH=*** BORG_EXIT_CODES=*** borg create --compression lz4 --list --filter AMEx- --debug --show-rc ssh://xxxxxxxxx@xxxxxxxxx.repo.borgbase.com/./repo::yyyyyyyy@{now} . /etc/borgmatic.d/config.yml /root/.borgmatic
using builtin fallback logging configuration
33 self tests completed in 0.26 seconds
SSH command line: ['ssh', '-oStrictHostKeyChecking=accept-new', 'xxxxxxxxx@xxxxxxxxx.repo.borgbase.com', 'borg', 'serve', '--debug']
Remote: using builtin fallback logging configuration
Remote: borg selftest disabled via BORG_SELFTEST env variable
Remote: using builtin fallback logging configuration
Remote: Initialized logging system for JSON-based protocol
Remote: Resolving repository path b'/./repo'
Remote: Resolved repository path to '/srv/repos/xxxxxxxxx/repo'
Remote: Verified integrity of /srv/repos/xxxxxxxxx/repo/index.51059
TAM-verified manifest
security: read previous location 'ssh://xxxxxxxxx@xxxxxxxxx.repo.borgbase.com/./repo'
security: read manifest timestamp '2024-08-05T13:57:08.582466'
security: determined newest manifest timestamp as 2024-08-05T13:57:08.582466
security: repository checks ok, allowing access
Creating archive at "ssh://xxxxxxxxx@xxxxxxxxx.repo.borgbase.com/./repo::yyyyyyyy@2024-08-05T16:07:59"
Verified integrity of /root/.cache/borg/c156080772560547047266a0d0168781f1757c455c86346e6a0798d7b8df0e51/chunks
Reading files cache ...
Verified integrity of /root/.cache/borg/c156080772560547047266a0d0168781f1757c455c86346e6a0798d7b8df0e51/files
security: read previous location 'ssh://xxxxxxxxx@xxxxxxxxx.repo.borgbase.com/./repo'
security: read manifest timestamp '2024-08-05T13:57:08.582466'
security: determined newest manifest timestamp as 2024-08-05T13:57:08.582466
security: repository checks ok, allowing access
Processing files ...
A nextcloud-config/.htaccess

LOTS OF FILES

M /etc/borgmatic.d/config.yml
A /root/.borgmatic/bootstrap/manifest.json
Remote: check_free_space: required bytes 211581858, free bytes 15111968206848
Remote: Storage quota: 378.49 GB out of 2.87 TB used.
security: saving state for c156080772560547047266a0d0168781f1757c455c86346e6a0798d7b8df0e51 to /root/.config/borg/security/c156080772560547047266a0d0168781f1757c455c86346e6a0798d7b8df0e51
security: current location   ssh://xxxxxxxxx@xxxxxxxxx.repo.borgbase.com/./repo
security: key type           5
security: manifest timestamp 2024-08-05T14:40:41.081192
RemoteRepository: 2.57 GB bytes sent, 284.14 kB bytes received, 7599 messages sent
terminating with success status, rc 0
/etc/borgmatic.d/config.yml: Calling mariadb_databases hook function remove_data_source_dumps
/etc/borgmatic.d/config.yml: Removing MariaDB data source dumps
/etc/borgmatic.d/config.yml: Calling mysql_databases hook function remove_data_source_dumps
/etc/borgmatic.d/config.yml: Removing MySQL data source dumps
/etc/borgmatic.d/config.yml: Calling mongodb_databases hook function remove_data_source_dumps
/etc/borgmatic.d/config.yml: Removing MongoDB data source dumps
/etc/borgmatic.d/config.yml: Calling postgresql_databases hook function remove_data_source_dumps
/etc/borgmatic.d/config.yml: Removing PostgreSQL data source dumps
/etc/borgmatic.d/config.yml: Calling sqlite_databases hook function remove_data_source_dumps
/etc/borgmatic.d/config.yml: Removing SQLite data source dumps
/etc/borgmatic.d/config.yml: Running command for post-backup hook
echo "`date` - Finished Backup"
Mon Aug  5 16:40:45 CEST 2024 - Finished Backup
/etc/borgmatic.d/config.yml: Running command for post-actions hook
echo "`date` - Finished Action"
Mon Aug  5 16:40:45 CEST 2024 - Finished Action
/etc/borgmatic.d/config.yml: Calling healthchecks hook function ping_monitor
/etc/borgmatic.d/config.yml: Pinging Healthchecks log
/etc/borgmatic.d/config.yml: Using Healthchecks ping URL https://vvvvvvvvvvvvvvv/ping/zzzzzzzzzzzzzzzzzzzzz/backup-ci-yyyyyyyy/log
/etc/borgmatic.d/config.yml: Healthchecks error: 400 Client Error: Bad Request for url: https://vvvvvvvvvvvvvvv/ping/zzzzzzzzzzzzzzzzzzzzz/backup-ci-yyyyyyyy/log
/etc/borgmatic.d/config.yml: Calling healthchecks hook function ping_monitor
/etc/borgmatic.d/config.yml: Pinging Healthchecks finish
/etc/borgmatic.d/config.yml: Using Healthchecks ping URL https://vvvvvvvvvvvvvvv/ping/zzzzzzzzzzzzzzzzzzzzz/backup-ci-yyyyyyyy
/etc/borgmatic.d/config.yml: Healthchecks error: 400 Client Error: Bad Request for url: https://vvvvvvvvvvvvvvv/ping/zzzzzzzzzzzzzzzzzzzzz/backup-ci-yyyyyyyy
/etc/borgmatic.d/config.yml: Calling healthchecks hook function destroy_monitor
/etc/borgmatic.d/config.yml: No commands to run for post-everything hook

summary:
/etc/borgmatic.d/config.yml: Loading configuration file
/etc/borgmatic.d/config.yml: Successfully ran configuration file
# borgmatic list --archive latest --verbosity 2

BORG_PASSPHRASE=*** BORG_RSH=*** BORG_EXIT_CODES=*** borg --version --debug --show-rc
/etc/borgmatic.d/config.yml: Borg 1.4.0
borgbase: Running actions for repository
/etc/borgmatic.d/config.yml: Running command for pre-actions hook
echo "`date` - Starting Action"
Mon Aug  5 16:58:17 CEST 2024 - Starting Action
BORG_PASSPHRASE=*** BORG_RSH=*** BORG_EXIT_CODES=*** borg list --last 1 --short ssh://xxxxxxxxx@xxxxxxxxx.repo.borgbase.com/./repo
ssh://xxxxxxxxx@xxxxxxxxx.repo.borgbase.com/./repo: Latest archive is yyyyyyyy@2024-08-05T16:09:44
ssh://xxxxxxxxx@xxxxxxxxx.repo.borgbase.com/./repo: Listing archive yyyyyyyy@2024-08-05T16:09:44
BORG_PASSPHRASE=*** BORG_RSH=*** BORG_EXIT_CODES=*** borg list --debug --show-rc ssh://xxxxxxxxx@xxxxxxxxx.repo.borgbase.com/./repo::yyyyyyyy@2024-08-05T16:09:44
using builtin fallback logging configuration
33 self tests completed in 0.22 seconds
SSH command line: ['ssh', '-oStrictHostKeyChecking=accept-new', 'xxxxxxxxx@xxxxxxxxx.repo.borgbase.com', 'borg', 'serve', '--debug']
Remote: using builtin fallback logging configuration
Remote: borg selftest disabled via BORG_SELFTEST env variable
Remote: using builtin fallback logging configuration
Remote: Initialized logging system for JSON-based protocol
Remote: Resolving repository path b'/./repo'
Remote: Resolved repository path to '/srv/repos/xxxxxxxxx/repo'
Remote: Verified integrity of /srv/repos/xxxxxxxxx/repo/index.51071
TAM-verified manifest
security: read previous location 'ssh://xxxxxxxxx@xxxxxxxxx.repo.borgbase.com/./repo'
security: read manifest timestamp '2024-08-05T14:40:41.081192'
security: determined newest manifest timestamp as 2024-08-05T14:40:41.081192
security: repository checks ok, allowing access
Archive authentication DISABLED.
TAM-verified archive
drwxr-xr-x root   root          0 Mon, 2024-08-05 12:29:59 .
drwxr-xr-x xfs    xfs           0 Sun, 2023-03-19 23:32:48 nextcloud-config
-rw-r--r-- xfs    xfs         495 Sun, 2023-02-12 18:31:34 nextcloud-config/.htaccess

LOTS OF FILES

-rw-r--r--   1000 video      1457 Mon, 2024-08-05 16:07:05 etc/borgmatic.d/config.yml
drwxr-xr-x root   root          0 Mon, 2024-08-05 15:57:08 root/.borgmatic
drwxr-xr-x root   root          0 Wed, 2023-07-05 10:10:01 root/.borgmatic/bootstrap
-rw-r--r-- root   root         80 Mon, 2024-08-05 16:10:21 root/.borgmatic/bootstrap/manifest.json
RemoteRepository: 23.96 kB bytes sent, 20.56 MB bytes received, 460 messages sent
terminating with success status, rc 0
/etc/borgmatic.d/config.yml: Running command for post-actions hook
echo "`date` - Finished Action"
Mon Aug  5 17:00:30 CEST 2024 - Finished Action

summary:
/etc/borgmatic.d/config.yml: Loading configuration file
/etc/borgmatic.d/config.yml: Successfully ran configuration file

Notice that files are being backed up, but not database:

drwxr-xr-x xfs    xfs           0 Sun, 2023-03-19 23:32:48 nextcloud-config
-rw-r--r-- xfs    xfs         495 Sun, 2023-02-12 18:31:34 nextcloud-config/.htaccess
-rw-r--r--   1000 video      1457 Mon, 2024-08-05 16:07:05 etc/borgmatic.d/config.yml
drwxr-xr-x root   root          0 Mon, 2024-08-05 15:57:08 root/.borgmatic
drwxr-xr-x root   root          0 Wed, 2023-07-05 10:10:01 root/.borgmatic/bootstrap
-rw-r--r-- root   root         80 Mon, 2024-08-05 16:10:21 root/.borgmatic/bootstrap/manifest.json

Other notes / implementation ideas

Temporary solution for me: revert back to image: b3vis/borgmatic:1.8.5.

borgmatic version

1.8.11, 1.8.12, 1.8.13

borgmatic installation method

image: b3vis/borgmatic

Borg version

borg 1.2.8

Python version

Python 3.12.3

Database version (if applicable)

mysql Ver 15.1 Distrib 10.11.6-MariaDB, for Linux (x86_64) using readline 5.1

Operating system and version

Alpine Linux v3.19

### What I'm trying to do and why A Borgmatic container version (`borgmatic >1.8.5 <= 1.8.11`) stopped backing up files while no configuration file was changed (i.e. the container update from 1.8.5 to 1.8.11 alone has this effect). This only concerns Borgmatic configurations which do include `mysql_databases:` or `sqlite_databases:` (and potentially all/other database hooks, but not tested). When commenting that block out, files do show up with `--list` & do back up. Using `--dry-dun` makes files show up as well. ### Steps to reproduce ```yaml # docker-compose.yml borgmatic: image: b3vis/borgmatic restart: always volumes: # Sources - nextcloud-data:/mnt/source/nextcloud-data:ro - nextcloud-config:/mnt/source/nextcloud-config:ro - nextcloud-themes:/mnt/source/nextcloud-themes:ro - nextcloud-custom_apps:/mnt/source/nextcloud-custom_apps:ro # Borgmatic - ./borgmatic.d:/etc/borgmatic.d:ro - borg-cache:/root/.cache/borg # SSH - $BORGMATIC_SSH_KEY:/root/.ssh/id_ed25519:ro environment: TZ: $TZ networks: - default ``` ```yaml # config.yml repositories: - path: ssh://xxxxxxxxx@xxxxxxxxx.repo.borgbase.com/./repo label: borgbase working_directory: /mnt/source source_directories: - . mysql_databases: - name: nextcloud hostname: mariadb username: root password: wwwwwwwww options: --skip-comments archive_name_format: yyyyyyyy@{now} encryption_passphrase: wwwwwwwww compression: lz4 match_archives: yyyyyyyy@* retries: 2 retry_wait: 5 ssh_command: ssh -oStrictHostKeyChecking=accept-new keep_within: 2m # 2 months keep_monthly: 24 keep_yearly: 10 checks: - name: repository - name: archives check_last: 1 healthchecks: ping_url: https://vvvvvvvvvvvvvvv/ping/zzzzzzzzzzzzzzzzzzzzz/backup-ci-yyyyyyyy ping_body_limit: 0 before_actions: - echo "`date` - Starting Action" after_actions: - echo "`date` - Finished Action" before_backup: - echo "`date` - Starting Backup" after_backup: - echo "`date` - Finished Backup" before_prune: - echo "`date` - Starting Prune" after_prune: - echo "`date` - Finished Prune" before_compact: - echo "`date` - Starting Compact" after_compact: - echo "`date` - Finished Compact" before_check: - echo "`date` - Starting Check" after_check: - echo "`date` - Finished Check" before_extract: - echo "`date` - Starting Extract" after_extract: - echo "`date` - Finished Extract" on_error: - echo "`date` - Borg Error" ``` ### Actual behavior ```bash # borgmatic --version 1.8.13 ``` ```bash # borgmatic create --list --verbosity 2 /etc/borgmatic.d/config.yml: No commands to run for pre-everything hook BORG_PASSPHRASE=*** BORG_RSH=*** BORG_EXIT_CODES=*** borg --version --debug --show-rc /etc/borgmatic.d/config.yml: Borg 1.4.0 /etc/borgmatic.d/config.yml: Calling healthchecks hook function initialize_monitor /etc/borgmatic.d/config.yml: Calling healthchecks hook function ping_monitor /etc/borgmatic.d/config.yml: Pinging Healthchecks start /etc/borgmatic.d/config.yml: Using Healthchecks ping URL https://vvvvvvvvvvvvvvv/ping/zzzzzzzzzzzzzzzzzzzzz/backup-ci-yyyyyyyy/start borgbase: Running actions for repository /etc/borgmatic.d/config.yml: Running command for pre-actions hook echo "`date` - Starting Action" Mon Aug 5 15:56:37 CEST 2024 - Starting Action /etc/borgmatic.d/config.yml: Running command for pre-backup hook echo "`date` - Starting Backup" Mon Aug 5 15:56:37 CEST 2024 - Starting Backup borgbase: Creating archive ssh://xxxxxxxxx@xxxxxxxxx.repo.borgbase.com/./repo: Calling mariadb_databases hook function remove_data_source_dumps ssh://xxxxxxxxx@xxxxxxxxx.repo.borgbase.com/./repo: Removing MariaDB data source dumps ssh://xxxxxxxxx@xxxxxxxxx.repo.borgbase.com/./repo: Calling mysql_databases hook function remove_data_source_dumps ssh://xxxxxxxxx@xxxxxxxxx.repo.borgbase.com/./repo: Removing MySQL data source dumps ssh://xxxxxxxxx@xxxxxxxxx.repo.borgbase.com/./repo: Calling mongodb_databases hook function remove_data_source_dumps ssh://xxxxxxxxx@xxxxxxxxx.repo.borgbase.com/./repo: Removing MongoDB data source dumps ssh://xxxxxxxxx@xxxxxxxxx.repo.borgbase.com/./repo: Calling postgresql_databases hook function remove_data_source_dumps ssh://xxxxxxxxx@xxxxxxxxx.repo.borgbase.com/./repo: Removing PostgreSQL data source dumps ssh://xxxxxxxxx@xxxxxxxxx.repo.borgbase.com/./repo: Calling sqlite_databases hook function remove_data_source_dumps ssh://xxxxxxxxx@xxxxxxxxx.repo.borgbase.com/./repo: Removing SQLite data source dumps ssh://xxxxxxxxx@xxxxxxxxx.repo.borgbase.com/./repo: Calling mysql_databases hook function dump_data_sources ssh://xxxxxxxxx@xxxxxxxxx.repo.borgbase.com/./repo: Dumping MySQL databases ssh://xxxxxxxxx@xxxxxxxxx.repo.borgbase.com/./repo: Dumping MySQL database "nextcloud" to /root/.borgmatic/mysql_databases/mariadb/nextcloud MYSQL_PWD=*** mysqldump --skip-comments --add-drop-database --host mariadb --protocol tcp --user root --databases nextcloud --result-file /root/.borgmatic/mysql_databases/mariadb/nextcloud ssh://xxxxxxxxx@xxxxxxxxx.repo.borgbase.com/./repo: Ignoring configured "read_special" value of false, as true is needed for database hooks. ssh://xxxxxxxxx@xxxxxxxxx.repo.borgbase.com/./repo: Collecting special file paths BORG_PASSPHRASE=*** BORG_RSH=*** BORG_EXIT_CODES=*** borg create --compression lz4 --one-file-system --read-special --list --filter AMEx- ssh://xxxxxxxxx@xxxxxxxxx.repo.borgbase.com/./repo::yyyyyyyy@{now} . /etc/borgmatic.d/config.yml /root/.borgmatic --dry-run --list BORG_PASSPHRASE=*** BORG_RSH=*** BORG_EXIT_CODES=*** borg create --compression lz4 --one-file-system --read-special --list --filter AMEx- --debug --show-rc ssh://xxxxxxxxx@xxxxxxxxx.repo.borgbase.com/./repo::yyyyyyyy@{now} . /etc/borgmatic.d/config.yml /root/.borgmatic using builtin fallback logging configuration 33 self tests completed in 0.25 seconds SSH command line: ['ssh', '-oStrictHostKeyChecking=accept-new', 'xxxxxxxxx@xxxxxxxxx.repo.borgbase.com', 'borg', 'serve', '--debug'] Remote: using builtin fallback logging configuration Remote: borg selftest disabled via BORG_SELFTEST env variable Remote: using builtin fallback logging configuration Remote: Initialized logging system for JSON-based protocol Remote: Resolving repository path b'/./repo' Remote: Resolved repository path to '/srv/repos/xxxxxxxxx/repo' Remote: Verified integrity of /srv/repos/xxxxxxxxx/repo/index.51055 TAM-verified manifest security: read previous location 'ssh://xxxxxxxxx@xxxxxxxxx.repo.borgbase.com/./repo' security: read manifest timestamp '2024-08-05T13:52:36.934529' security: determined newest manifest timestamp as 2024-08-05T13:52:36.934529 security: repository checks ok, allowing access Creating archive at "ssh://xxxxxxxxx@xxxxxxxxx.repo.borgbase.com/./repo::yyyyyyyy@2024-08-05T15:56:37" Verified integrity of /root/.cache/borg/c156080772560547047266a0d0168781f1757c455c86346e6a0798d7b8df0e51/chunks Reading files cache ... Verified integrity of /root/.cache/borg/c156080772560547047266a0d0168781f1757c455c86346e6a0798d7b8df0e51/files security: read previous location 'ssh://xxxxxxxxx@xxxxxxxxx.repo.borgbase.com/./repo' security: read manifest timestamp '2024-08-05T13:52:36.934529' security: determined newest manifest timestamp as 2024-08-05T13:52:36.934529 security: repository checks ok, allowing access Processing files ... A /root/.borgmatic/bootstrap/manifest.json A /root/.borgmatic/mysql_databases/mariadb/nextcloud Remote: Cleaned up 0 uncommitted segment files (== everything after segment 51055). Remote: Verified integrity of /srv/repos/xxxxxxxxx/repo/hints.51055 Remote: Storage quota: 375.92 GB out of 2.87 TB used. Remote: check_free_space: required bytes 211581658, free bytes 15142892871680 Remote: Storage quota: 375.93 GB out of 2.87 TB used. security: saving state for c156080772560547047266a0d0168781f1757c455c86346e6a0798d7b8df0e51 to /root/.config/borg/security/c156080772560547047266a0d0168781f1757c455c86346e6a0798d7b8df0e51 security: current location ssh://xxxxxxxxx@xxxxxxxxx.repo.borgbase.com/./repo security: key type 5 security: manifest timestamp 2024-08-05T13:57:08.582466 RemoteRepository: 2.58 MB bytes sent, 215.10 kB bytes received, 14 messages sent terminating with success status, rc 0 /etc/borgmatic.d/config.yml: Calling mariadb_databases hook function remove_data_source_dumps /etc/borgmatic.d/config.yml: Removing MariaDB data source dumps /etc/borgmatic.d/config.yml: Calling mysql_databases hook function remove_data_source_dumps /etc/borgmatic.d/config.yml: Removing MySQL data source dumps /etc/borgmatic.d/config.yml: Calling mongodb_databases hook function remove_data_source_dumps /etc/borgmatic.d/config.yml: Removing MongoDB data source dumps /etc/borgmatic.d/config.yml: Calling postgresql_databases hook function remove_data_source_dumps /etc/borgmatic.d/config.yml: Removing PostgreSQL data source dumps /etc/borgmatic.d/config.yml: Calling sqlite_databases hook function remove_data_source_dumps /etc/borgmatic.d/config.yml: Removing SQLite data source dumps /etc/borgmatic.d/config.yml: Running command for post-backup hook echo "`date` - Finished Backup" Mon Aug 5 15:57:09 CEST 2024 - Finished Backup /etc/borgmatic.d/config.yml: Running command for post-actions hook echo "`date` - Finished Action" Mon Aug 5 15:57:09 CEST 2024 - Finished Action /etc/borgmatic.d/config.yml: Calling healthchecks hook function ping_monitor /etc/borgmatic.d/config.yml: Pinging Healthchecks log /etc/borgmatic.d/config.yml: Using Healthchecks ping URL https://vvvvvvvvvvvvvvv/ping/zzzzzzzzzzzzzzzzzzzzz/backup-ci-yyyyyyyy/log /etc/borgmatic.d/config.yml: Calling healthchecks hook function ping_monitor /etc/borgmatic.d/config.yml: Pinging Healthchecks finish /etc/borgmatic.d/config.yml: Using Healthchecks ping URL https://vvvvvvvvvvvvvvv/ping/zzzzzzzzzzzzzzzzzzzzz/backup-ci-yyyyyyyy /etc/borgmatic.d/config.yml: Calling healthchecks hook function destroy_monitor /etc/borgmatic.d/config.yml: No commands to run for post-everything hook summary: /etc/borgmatic.d/config.yml: Loading configuration file /etc/borgmatic.d/config.yml: Successfully ran configuration file ``` ```bash # borgmatic list --archive latest --verbosity 2 BORG_PASSPHRASE=*** BORG_RSH=*** BORG_EXIT_CODES=*** borg --version --debug --show-rc /etc/borgmatic.d/config.yml: Borg 1.4.0 borgbase: Running actions for repository /etc/borgmatic.d/config.yml: Running command for pre-actions hook echo "`date` - Starting Action" Mon Aug 5 15:59:02 CEST 2024 - Starting Action BORG_PASSPHRASE=*** BORG_RSH=*** BORG_EXIT_CODES=*** borg list --last 1 --short ssh://xxxxxxxxx@xxxxxxxxx.repo.borgbase.com/./repo ssh://xxxxxxxxx@xxxxxxxxx.repo.borgbase.com/./repo: Latest archive is yyyyyyyy@2024-08-05T15:56:37 ssh://xxxxxxxxx@xxxxxxxxx.repo.borgbase.com/./repo: Listing archive yyyyyyyy@2024-08-05T15:56:37 BORG_PASSPHRASE=*** BORG_RSH=*** BORG_EXIT_CODES=*** borg list --debug --show-rc ssh://xxxxxxxxx@xxxxxxxxx.repo.borgbase.com/./repo::yyyyyyyy@2024-08-05T15:56:37 using builtin fallback logging configuration 33 self tests completed in 0.23 seconds SSH command line: ['ssh', '-oStrictHostKeyChecking=accept-new', 'xxxxxxxxx@xxxxxxxxx.repo.borgbase.com', 'borg', 'serve', '--debug'] Remote: using builtin fallback logging configuration Remote: borg selftest disabled via BORG_SELFTEST env variable Remote: using builtin fallback logging configuration Remote: Initialized logging system for JSON-based protocol Remote: Resolving repository path b'/./repo' Remote: Resolved repository path to '/srv/repos/xxxxxxxxx/repo' Remote: Verified integrity of /srv/repos/xxxxxxxxx/repo/index.51059 TAM-verified manifest security: read previous location 'ssh://xxxxxxxxx@xxxxxxxxx.repo.borgbase.com/./repo' security: read manifest timestamp '2024-08-05T13:57:08.582466' security: determined newest manifest timestamp as 2024-08-05T13:57:08.582466 security: repository checks ok, allowing access Archive authentication DISABLED. TAM-verified archive drwxr-xr-x root root 0 Mon, 2024-08-05 12:29:59 . drwxr-xr-x xfs xfs 0 Sun, 2023-03-19 23:32:48 nextcloud-config drwxr-xr-x xfs xfs 0 Mon, 2024-08-05 13:59:22 nextcloud-custom_apps drwxrwx--- xfs root 0 Fri, 2024-07-26 15:41:11 nextcloud-data drwxr-xr-x xfs xfs 0 Sun, 2023-02-12 18:31:34 nextcloud-themes -rw-r--r-- 1000 video 1445 Mon, 2024-08-05 15:52:02 etc/borgmatic.d/config.yml drwxr-xr-x root root 0 Mon, 2024-08-05 15:56:37 root/.borgmatic drwxr-xr-x root root 0 Wed, 2023-07-05 10:10:01 root/.borgmatic/bootstrap -rw-r--r-- root root 80 Mon, 2024-08-05 15:56:37 root/.borgmatic/bootstrap/manifest.json drwxr-xr-x root root 0 Mon, 2024-08-05 15:56:37 root/.borgmatic/mysql_databases drwx------ root root 0 Mon, 2024-08-05 15:56:37 root/.borgmatic/mysql_databases/mariadb -rw------- root root 736421728 Mon, 2024-08-05 15:56:37 root/.borgmatic/mysql_databases/mariadb/nextcloud RemoteRepository: 318 B bytes sent, 227.77 kB bytes received, 7 messages sent terminating with success status, rc 0 /etc/borgmatic.d/config.yml: Running command for post-actions hook echo "`date` - Finished Action" Mon Aug 5 15:59:05 CEST 2024 - Finished Action summary: /etc/borgmatic.d/config.yml: Loading configuration file /etc/borgmatic.d/config.yml: Successfully ran configuration file ``` **Notice that these folders are present but empty:** ``` drwxr-xr-x xfs xfs 0 Sun, 2023-03-19 23:32:48 nextcloud-config drwxr-xr-x xfs xfs 0 Mon, 2024-08-05 13:59:22 nextcloud-custom_apps drwxrwx--- xfs root 0 Fri, 2024-07-26 15:41:11 nextcloud-data drwxr-xr-x xfs xfs 0 Sun, 2023-02-12 18:31:34 nextcloud-themes ``` ### Expected behavior Run again, after having commented out the `mysql_databases:` block in `config.yml`. ```bash # borgmatic --version 1.8.13 ``` ```bash # borgmatic create --list --verbosity 2 /etc/borgmatic.d/config.yml: No commands to run for pre-everything hook BORG_PASSPHRASE=*** BORG_RSH=*** BORG_EXIT_CODES=*** borg --version --debug --show-rc /etc/borgmatic.d/config.yml: Borg 1.4.0 /etc/borgmatic.d/config.yml: Calling healthchecks hook function initialize_monitor /etc/borgmatic.d/config.yml: Calling healthchecks hook function ping_monitor /etc/borgmatic.d/config.yml: Pinging Healthchecks start /etc/borgmatic.d/config.yml: Using Healthchecks ping URL https://vvvvvvvvvvvvvvv/ping/zzzzzzzzzzzzzzzzzzzzz/backup-ci-yyyyyyyy/start borgbase: Running actions for repository /etc/borgmatic.d/config.yml: Running command for pre-actions hook echo "`date` - Starting Action" Mon Aug 5 16:07:58 CEST 2024 - Starting Action /etc/borgmatic.d/config.yml: Running command for pre-backup hook echo "`date` - Starting Backup" Mon Aug 5 16:07:58 CEST 2024 - Starting Backup borgbase: Creating archive ssh://xxxxxxxxx@xxxxxxxxx.repo.borgbase.com/./repo: Calling mariadb_databases hook function remove_data_source_dumps ssh://xxxxxxxxx@xxxxxxxxx.repo.borgbase.com/./repo: Removing MariaDB data source dumps ssh://xxxxxxxxx@xxxxxxxxx.repo.borgbase.com/./repo: Calling mysql_databases hook function remove_data_source_dumps ssh://xxxxxxxxx@xxxxxxxxx.repo.borgbase.com/./repo: Removing MySQL data source dumps ssh://xxxxxxxxx@xxxxxxxxx.repo.borgbase.com/./repo: Calling mongodb_databases hook function remove_data_source_dumps ssh://xxxxxxxxx@xxxxxxxxx.repo.borgbase.com/./repo: Removing MongoDB data source dumps ssh://xxxxxxxxx@xxxxxxxxx.repo.borgbase.com/./repo: Calling postgresql_databases hook function remove_data_source_dumps ssh://xxxxxxxxx@xxxxxxxxx.repo.borgbase.com/./repo: Removing PostgreSQL data source dumps ssh://xxxxxxxxx@xxxxxxxxx.repo.borgbase.com/./repo: Calling sqlite_databases hook function remove_data_source_dumps ssh://xxxxxxxxx@xxxxxxxxx.repo.borgbase.com/./repo: Removing SQLite data source dumps BORG_PASSPHRASE=*** BORG_RSH=*** BORG_EXIT_CODES=*** borg create --compression lz4 --list --filter AMEx- --debug --show-rc ssh://xxxxxxxxx@xxxxxxxxx.repo.borgbase.com/./repo::yyyyyyyy@{now} . /etc/borgmatic.d/config.yml /root/.borgmatic using builtin fallback logging configuration 33 self tests completed in 0.26 seconds SSH command line: ['ssh', '-oStrictHostKeyChecking=accept-new', 'xxxxxxxxx@xxxxxxxxx.repo.borgbase.com', 'borg', 'serve', '--debug'] Remote: using builtin fallback logging configuration Remote: borg selftest disabled via BORG_SELFTEST env variable Remote: using builtin fallback logging configuration Remote: Initialized logging system for JSON-based protocol Remote: Resolving repository path b'/./repo' Remote: Resolved repository path to '/srv/repos/xxxxxxxxx/repo' Remote: Verified integrity of /srv/repos/xxxxxxxxx/repo/index.51059 TAM-verified manifest security: read previous location 'ssh://xxxxxxxxx@xxxxxxxxx.repo.borgbase.com/./repo' security: read manifest timestamp '2024-08-05T13:57:08.582466' security: determined newest manifest timestamp as 2024-08-05T13:57:08.582466 security: repository checks ok, allowing access Creating archive at "ssh://xxxxxxxxx@xxxxxxxxx.repo.borgbase.com/./repo::yyyyyyyy@2024-08-05T16:07:59" Verified integrity of /root/.cache/borg/c156080772560547047266a0d0168781f1757c455c86346e6a0798d7b8df0e51/chunks Reading files cache ... Verified integrity of /root/.cache/borg/c156080772560547047266a0d0168781f1757c455c86346e6a0798d7b8df0e51/files security: read previous location 'ssh://xxxxxxxxx@xxxxxxxxx.repo.borgbase.com/./repo' security: read manifest timestamp '2024-08-05T13:57:08.582466' security: determined newest manifest timestamp as 2024-08-05T13:57:08.582466 security: repository checks ok, allowing access Processing files ... A nextcloud-config/.htaccess LOTS OF FILES M /etc/borgmatic.d/config.yml A /root/.borgmatic/bootstrap/manifest.json Remote: check_free_space: required bytes 211581858, free bytes 15111968206848 Remote: Storage quota: 378.49 GB out of 2.87 TB used. security: saving state for c156080772560547047266a0d0168781f1757c455c86346e6a0798d7b8df0e51 to /root/.config/borg/security/c156080772560547047266a0d0168781f1757c455c86346e6a0798d7b8df0e51 security: current location ssh://xxxxxxxxx@xxxxxxxxx.repo.borgbase.com/./repo security: key type 5 security: manifest timestamp 2024-08-05T14:40:41.081192 RemoteRepository: 2.57 GB bytes sent, 284.14 kB bytes received, 7599 messages sent terminating with success status, rc 0 /etc/borgmatic.d/config.yml: Calling mariadb_databases hook function remove_data_source_dumps /etc/borgmatic.d/config.yml: Removing MariaDB data source dumps /etc/borgmatic.d/config.yml: Calling mysql_databases hook function remove_data_source_dumps /etc/borgmatic.d/config.yml: Removing MySQL data source dumps /etc/borgmatic.d/config.yml: Calling mongodb_databases hook function remove_data_source_dumps /etc/borgmatic.d/config.yml: Removing MongoDB data source dumps /etc/borgmatic.d/config.yml: Calling postgresql_databases hook function remove_data_source_dumps /etc/borgmatic.d/config.yml: Removing PostgreSQL data source dumps /etc/borgmatic.d/config.yml: Calling sqlite_databases hook function remove_data_source_dumps /etc/borgmatic.d/config.yml: Removing SQLite data source dumps /etc/borgmatic.d/config.yml: Running command for post-backup hook echo "`date` - Finished Backup" Mon Aug 5 16:40:45 CEST 2024 - Finished Backup /etc/borgmatic.d/config.yml: Running command for post-actions hook echo "`date` - Finished Action" Mon Aug 5 16:40:45 CEST 2024 - Finished Action /etc/borgmatic.d/config.yml: Calling healthchecks hook function ping_monitor /etc/borgmatic.d/config.yml: Pinging Healthchecks log /etc/borgmatic.d/config.yml: Using Healthchecks ping URL https://vvvvvvvvvvvvvvv/ping/zzzzzzzzzzzzzzzzzzzzz/backup-ci-yyyyyyyy/log /etc/borgmatic.d/config.yml: Healthchecks error: 400 Client Error: Bad Request for url: https://vvvvvvvvvvvvvvv/ping/zzzzzzzzzzzzzzzzzzzzz/backup-ci-yyyyyyyy/log /etc/borgmatic.d/config.yml: Calling healthchecks hook function ping_monitor /etc/borgmatic.d/config.yml: Pinging Healthchecks finish /etc/borgmatic.d/config.yml: Using Healthchecks ping URL https://vvvvvvvvvvvvvvv/ping/zzzzzzzzzzzzzzzzzzzzz/backup-ci-yyyyyyyy /etc/borgmatic.d/config.yml: Healthchecks error: 400 Client Error: Bad Request for url: https://vvvvvvvvvvvvvvv/ping/zzzzzzzzzzzzzzzzzzzzz/backup-ci-yyyyyyyy /etc/borgmatic.d/config.yml: Calling healthchecks hook function destroy_monitor /etc/borgmatic.d/config.yml: No commands to run for post-everything hook summary: /etc/borgmatic.d/config.yml: Loading configuration file /etc/borgmatic.d/config.yml: Successfully ran configuration file ``` ```bash # borgmatic list --archive latest --verbosity 2 BORG_PASSPHRASE=*** BORG_RSH=*** BORG_EXIT_CODES=*** borg --version --debug --show-rc /etc/borgmatic.d/config.yml: Borg 1.4.0 borgbase: Running actions for repository /etc/borgmatic.d/config.yml: Running command for pre-actions hook echo "`date` - Starting Action" Mon Aug 5 16:58:17 CEST 2024 - Starting Action BORG_PASSPHRASE=*** BORG_RSH=*** BORG_EXIT_CODES=*** borg list --last 1 --short ssh://xxxxxxxxx@xxxxxxxxx.repo.borgbase.com/./repo ssh://xxxxxxxxx@xxxxxxxxx.repo.borgbase.com/./repo: Latest archive is yyyyyyyy@2024-08-05T16:09:44 ssh://xxxxxxxxx@xxxxxxxxx.repo.borgbase.com/./repo: Listing archive yyyyyyyy@2024-08-05T16:09:44 BORG_PASSPHRASE=*** BORG_RSH=*** BORG_EXIT_CODES=*** borg list --debug --show-rc ssh://xxxxxxxxx@xxxxxxxxx.repo.borgbase.com/./repo::yyyyyyyy@2024-08-05T16:09:44 using builtin fallback logging configuration 33 self tests completed in 0.22 seconds SSH command line: ['ssh', '-oStrictHostKeyChecking=accept-new', 'xxxxxxxxx@xxxxxxxxx.repo.borgbase.com', 'borg', 'serve', '--debug'] Remote: using builtin fallback logging configuration Remote: borg selftest disabled via BORG_SELFTEST env variable Remote: using builtin fallback logging configuration Remote: Initialized logging system for JSON-based protocol Remote: Resolving repository path b'/./repo' Remote: Resolved repository path to '/srv/repos/xxxxxxxxx/repo' Remote: Verified integrity of /srv/repos/xxxxxxxxx/repo/index.51071 TAM-verified manifest security: read previous location 'ssh://xxxxxxxxx@xxxxxxxxx.repo.borgbase.com/./repo' security: read manifest timestamp '2024-08-05T14:40:41.081192' security: determined newest manifest timestamp as 2024-08-05T14:40:41.081192 security: repository checks ok, allowing access Archive authentication DISABLED. TAM-verified archive drwxr-xr-x root root 0 Mon, 2024-08-05 12:29:59 . drwxr-xr-x xfs xfs 0 Sun, 2023-03-19 23:32:48 nextcloud-config -rw-r--r-- xfs xfs 495 Sun, 2023-02-12 18:31:34 nextcloud-config/.htaccess LOTS OF FILES -rw-r--r-- 1000 video 1457 Mon, 2024-08-05 16:07:05 etc/borgmatic.d/config.yml drwxr-xr-x root root 0 Mon, 2024-08-05 15:57:08 root/.borgmatic drwxr-xr-x root root 0 Wed, 2023-07-05 10:10:01 root/.borgmatic/bootstrap -rw-r--r-- root root 80 Mon, 2024-08-05 16:10:21 root/.borgmatic/bootstrap/manifest.json RemoteRepository: 23.96 kB bytes sent, 20.56 MB bytes received, 460 messages sent terminating with success status, rc 0 /etc/borgmatic.d/config.yml: Running command for post-actions hook echo "`date` - Finished Action" Mon Aug 5 17:00:30 CEST 2024 - Finished Action summary: /etc/borgmatic.d/config.yml: Loading configuration file /etc/borgmatic.d/config.yml: Successfully ran configuration file ``` **Notice that files are being backed up, but not database:** ``` drwxr-xr-x xfs xfs 0 Sun, 2023-03-19 23:32:48 nextcloud-config -rw-r--r-- xfs xfs 495 Sun, 2023-02-12 18:31:34 nextcloud-config/.htaccess -rw-r--r-- 1000 video 1457 Mon, 2024-08-05 16:07:05 etc/borgmatic.d/config.yml drwxr-xr-x root root 0 Mon, 2024-08-05 15:57:08 root/.borgmatic drwxr-xr-x root root 0 Wed, 2023-07-05 10:10:01 root/.borgmatic/bootstrap -rw-r--r-- root root 80 Mon, 2024-08-05 16:10:21 root/.borgmatic/bootstrap/manifest.json ``` ### Other notes / implementation ideas Temporary solution for me: revert back to `image: b3vis/borgmatic:1.8.5`. ### borgmatic version 1.8.11, 1.8.12, 1.8.13 ### borgmatic installation method image: b3vis/borgmatic ### Borg version borg 1.2.8 ### Python version Python 3.12.3 ### Database version (if applicable) mysql Ver 15.1 Distrib 10.11.6-MariaDB, for Linux (x86_64) using readline 5.1 ### Operating system and version Alpine Linux v3.19
raph-topo changed title from Regression after 1.8.5: backing up either files or database to Silent regression after 1.8.5: backing up either files or database 2024-08-05 15:09:56 +00:00
raph-topo changed title from Silent regression after 1.8.5: backing up either files or database to Silent REGRESSION after 1.8.5: backing up either files or database 2024-08-05 15:10:02 +00:00
Owner

So I have an idea about why you're seeing this behavior (files not getting backed up when databases are enabled), but I have no idea how this previously ever worked for you with older versions of borgmatic.

When databases are enabled, borgmatic implicitly enables the one_file_system configuration option. This tells Borg not to cross filesystem boundaries, which has the side effect of preventing Borg from reading the contents of your source directories. You can confirm or disprove this theory by commenting out the database configuration and then adding one_file_system: true to your configuration. If that also causes your source files to get omitted, then you have your answer.

The workaround for this limitation is to be explicit about the directory paths to include instead of expecting Borg to cross those filesystem boundaries. Example:

source_directories:
  - /mnt/source/nextcloud-data
  - /mnt/source/nextcloud-config
  - /mnt/source/nextcloud-themes
  - /mnt/source/nextcloud-custome_apps

The real mystery here is how this ever worked with borgmatic 1.8.5. My wild guess is something must have changed with the container construction that impacted how filesystem paths got mounted. And if you'd like to get to the bottom of that, my recommendation would be to ask the developers of that container image. EDIT: Although see the comment below...

I hope that helps!

So I have an idea about why you're seeing this behavior (files not getting backed up when databases are enabled), but I have no idea how this previously ever worked for you with older versions of borgmatic. When databases are enabled, borgmatic [implicitly enables](https://torsion.org/borgmatic/docs/how-to/backup-your-databases/#limitations) the `one_file_system` configuration option. This tells Borg not to cross filesystem boundaries, which has the side effect of preventing Borg from reading the contents of your source directories. You can confirm or disprove this theory by commenting out the database configuration and then adding `one_file_system: true` to your configuration. If that also causes your source files to get omitted, then you have your answer. The workaround for this limitation is to be explicit about the directory paths to include instead of expecting Borg to cross those filesystem boundaries. Example: ```yaml source_directories: - /mnt/source/nextcloud-data - /mnt/source/nextcloud-config - /mnt/source/nextcloud-themes - /mnt/source/nextcloud-custome_apps ``` The real mystery here is how this ever worked with borgmatic 1.8.5. My wild guess is something must have changed with the container construction that impacted how filesystem paths got mounted. And if you'd like to get to the bottom of that, my recommendation would be to ask the [developers of that container image](https://github.com/borgmatic-collective/docker-borgmatic). EDIT: Although see the comment below... I hope that helps!
witten added the
question / support
label 2024-08-08 04:38:27 +00:00
Owner

Okay, so one thing that did change in borgmatic 1.8.6 is that the SQLite hook switched from dumping to an intermediate file on the filesystem to instead streaming dumps directly to Borg like all the other database hooks do (for performance / disk space reasons). This also means that as of borgmatic 1.8.6, configurations with SQLite started implicitly enabling one_file_system like the other database hooks. And that could in theory explain the behavior you're seeing with Borg not crossing filesystem boundaries to grab source files.

Major aside, mostly for myself: I'll also note the idea (as of yet unexplored) that borgmatic could maybe stop implicitly enabling one_file_system in database hooks. IIRC, the original reason for that was to prevent the (also implicitly enabled) read_special option from trying to read all sorts of special files on separate filesystems and thereby causing Borg to hang. But somewhere along the way, borgmatic got the ability to detect and automatically omit special files from the source directories even when read_special is enabled. So it's possible that implicitly enabling one_file_system isn't necessary anymore to prevent hangs.

Okay, so one thing that _did_ change in borgmatic 1.8.6 is that the SQLite hook switched from dumping to an intermediate file on the filesystem to instead streaming dumps directly to Borg like all the other database hooks do (for performance / disk space reasons). This also means that as of borgmatic 1.8.6, configurations with SQLite started implicitly enabling `one_file_system` like the other database hooks. And that could in theory explain the behavior you're seeing with Borg not crossing filesystem boundaries to grab source files. Major aside, mostly for myself: I'll also note the idea (as of yet unexplored) that borgmatic could maybe stop implicitly enabling `one_file_system` in database hooks. IIRC, the original reason for that was to prevent the (also implicitly enabled) `read_special` option from trying to read all sorts of special files on separate filesystems and thereby causing Borg to hang. But somewhere along the way, borgmatic got the ability to detect and automatically omit special files from the source directories even when `read_special` is enabled. So it's possible that implicitly enabling `one_file_system` isn't necessary anymore to prevent hangs.
Author

Thanks for your quick reply!

I had indeed seen that that remark, but figured the same way as you that it then should not have worked in 1.8.5 (and numerous versions before) either.

When databases are enabled, borgmatic implicitly enables the one_file_system configuration option. This tells Borg not to cross filesystem boundaries, which has the side effect of preventing Borg from reading the contents of your source directories. You can confirm or disprove this theory by commenting out the database configuration and then adding one_file_system: true to your configuration. If that also causes your source files to get omitted, then you have your answer.

I do confirm that no database configured + one_file_system: true prevents files from being included in the backup.

The workaround for this limitation is to be explicit about the directory paths to include instead of expecting Borg to cross those filesystem boundaries. Example:

source_directories:
  - /mnt/source/nextcloud-data
  - /mnt/source/nextcloud-config
  - /mnt/source/nextcloud-themes
  - /mnt/source/nextcloud-custom_apps

That does indeed work as well.

Thanks for your quick reply! I had indeed seen that that remark, but figured the same way as you that it then should not have worked in 1.8.5 (and numerous versions before) either. > When databases are enabled, borgmatic [implicitly enables](https://torsion.org/borgmatic/docs/how-to/backup-your-databases/#limitations) the `one_file_system` configuration option. This tells Borg not to cross filesystem boundaries, which has the side effect of preventing Borg from reading the contents of your source directories. You can confirm or disprove this theory by commenting out the database configuration and then adding `one_file_system: true` to your configuration. If that also causes your source files to get omitted, then you have your answer. I do confirm that _no database configured_ + `one_file_system: true` prevents files from being included in the backup. > The workaround for this limitation is to be explicit about the directory paths to include instead of expecting Borg to cross those filesystem boundaries. Example: > > ```yaml > source_directories: > - /mnt/source/nextcloud-data > - /mnt/source/nextcloud-config > - /mnt/source/nextcloud-themes > - /mnt/source/nextcloud-custom_apps > ``` That does indeed work as well.
Author

Okay, so one thing that did change in borgmatic 1.8.6 is that the SQLite hook switched from dumping to an intermediate file on the filesystem to instead streaming dumps directly to Borg like all the other database hooks do (for performance / disk space reasons). This also means that as of borgmatic 1.8.6, configurations with SQLite started implicitly enabling one_file_system like the other database hooks. And that could in theory explain the behavior you're seeing with Borg not crossing filesystem boundaries to grab source files.

It fails with mysql_databases: as well though.

I thought I'd test all versions to narrow down, all with the config shown in first post, only change is image: b3vis/borgmatic:1.8.5:

  • 1.8.5: works
  • 1.8.6: manifest for b3vis/borgmatic:1.8.6 not found: manifest unknown: manifest unknown (not on Docker Hub anymore)
  • 1.8.7: works
  • 1.8.8: works
  • 1.8.9: works
  • 1.8.10: does not work
  • 1.8.11: does not work
  • 1.8.12: does not work
  • 1.8.13: does not work

If the container versions are perfect mirrors of releases of this repo, then it must be somewhere in 1.8.10's commits.

If not, it could be in borgmatic-collective/docker-borgmatic as you mentioned, which includes the bump from borgbackup==1.2.7 to borgbackup==1.2.8, but at that point I'm lost in code without a clue.

> Okay, so one thing that _did_ change in borgmatic 1.8.6 is that the SQLite hook switched from dumping to an intermediate file on the filesystem to instead streaming dumps directly to Borg like all the other database hooks do (for performance / disk space reasons). This also means that as of borgmatic 1.8.6, configurations with SQLite started implicitly enabling `one_file_system` like the other database hooks. And that could in theory explain the behavior you're seeing with Borg not crossing filesystem boundaries to grab source files. It fails with `mysql_databases:` as well though. I thought I'd test all versions to narrow down, all with the config shown in first post, only change is `image: b3vis/borgmatic:1.8.5`: - 1.8.5: works - 1.8.6: `manifest for b3vis/borgmatic:1.8.6 not found: manifest unknown: manifest unknown` (not on Docker Hub anymore) - 1.8.7: works - 1.8.8: works - 1.8.9: works - **1.8.10: does not work** - 1.8.11: does not work - 1.8.12: does not work - 1.8.13: does not work If the container versions are perfect mirrors of releases of this repo, then it must be somewhere in [1.8.10's commits](https://projects.torsion.org/borgmatic-collective/borgmatic/compare/1.8.9...1.8.10). If not, it could be in [borgmatic-collective/docker-borgmatic](https://github.com/borgmatic-collective/docker-borgmatic/compare/1.8.9...1.8.10) as you mentioned, which includes the bump from [`borgbackup==1.2.7` to `borgbackup==1.2.8`](https://github.com/borgbackup/borg/compare/1.2.7...1.2.8), but at that point I'm lost in code without a clue.
Author

It seems that the "streaming" part you mentioned is actually in 1.8.10?

It seems that the "streaming" part you mentioned is [actually in 1.8.10](https://projects.torsion.org/borgmatic-collective/borgmatic/compare/1.8.9...1.8.10#diff-76189065136b97d52161115ac70e1f71839646be)?
raph-topo changed title from Silent REGRESSION after 1.8.5: backing up either files or database to Silent REGRESSION in 1.8.10: backing up either files or database 2024-08-16 09:21:19 +00:00
Owner

It fails with mysql_databases: as well though.

As far as I recall, the borgmatic MySQL hook has always enabled one_file_system implicitly.

1.8.9: works
1.8.10: does not work

Interesting! Thanks for taking the time to narrow this down. But I don't immediately see anything in borgmatic's own 1.8.10 changelog that would readily explain the behavior you're seeing. It's possible that some of the refactoring that was part of the spot check (in 1.8.10) could've impacted something, but that's just speculation at this point.

It seems that the "streaming" part you mentioned is actually in 1.8.10?

Actually, no, that was just making the existing streaming status (enabled/disabled) available to other parts of borgmatic.

If the container versions are perfect mirrors of releases of this repo, then it must be somewhere in 1.8.10's commits.

The container versions AFAIK do use unmodified versions of borgmatic, but they also layer additional software on top of it (e.g. for scheduling, environment variables, etc.). I don't know how inconvenient it would be for you, but have you tried installing borgmatic temporarily without a container to see if you get the same behavior difference between 1.8.9 and 1.8.10? That could at least rule out the container as a factor (or rule it in).

> It fails with mysql_databases: as well though. As far as I recall, the borgmatic MySQL hook has always enabled `one_file_system` implicitly. > 1.8.9: works > 1.8.10: does not work Interesting! Thanks for taking the time to narrow this down. But I don't immediately see anything in borgmatic's own 1.8.10 changelog that would readily explain the behavior you're seeing. It's _possible_ that some of the refactoring that was part of the `spot` check (in 1.8.10) could've impacted something, but that's just speculation at this point. > It seems that the "streaming" part you mentioned is actually in 1.8.10? Actually, no, that was just making the existing streaming status (enabled/disabled) available to other parts of borgmatic. > If the container versions are perfect mirrors of releases of this repo, then it must be somewhere in 1.8.10's commits. The container versions AFAIK do use unmodified versions of borgmatic, but they also layer additional software on top of it (e.g. for scheduling, environment variables, etc.). I don't know how inconvenient it would be for you, but have you tried installing borgmatic temporarily without a container to see if you get the same behavior difference between 1.8.9 and 1.8.10? That could at least rule out the container as a factor (or rule it in).
Author

The container versions AFAIK do use unmodified versions of borgmatic, but they also layer additional software on top of it (e.g. for scheduling, environment variables, etc.). I don't know how inconvenient it would be for you, but have you tried installing borgmatic temporarily without a container to see if you get the same behavior difference between 1.8.9 and 1.8.10? That could at least rule out the container as a factor (or rule it in).

Running borgmatic on host and still accessing data in volumes without a container, yet not modifying the config to accurately test versions, seemed too complicated, if not impossible.

As such, I rather kept

    image: b3vis/borgmatic:1.8.9

and updated borgmatic inside the container:

 pip install borgmatic==1.8.10

Is that okay?

Result: does work (database and files in backup).
The bug or regression must be something in the container, I sent the issue downstream: https://github.com/borgmatic-collective/docker-borgmatic/issues/355

> The container versions AFAIK do use unmodified versions of borgmatic, but they also layer additional software on top of it (e.g. for scheduling, environment variables, etc.). I don't know how inconvenient it would be for you, but have you tried installing borgmatic temporarily without a container to see if you get the same behavior difference between 1.8.9 and 1.8.10? That could at least rule out the container as a factor (or rule it in). Running borgmatic on host and still accessing data in volumes without a container, yet not modifying the config to accurately test versions, seemed too complicated, if not impossible. As such, I rather kept ```yaml image: b3vis/borgmatic:1.8.9 ``` and updated borgmatic inside the container: ```bash pip install borgmatic==1.8.10 ``` Is that okay? Result: **does work** (database and files in backup). The bug or regression must be something in the container, I sent the issue downstream: https://github.com/borgmatic-collective/docker-borgmatic/issues/355
Owner

I think updating borgmatic inside the container with pip should be sufficient for temporary testing like this. You should be able to confirm that the new version of borgmatic is actually getting used by changing your crontab.txt to run borgmatic --version instead of just borgmatic. Newer versions of the container might print the borgmatic version in use, but that doesn't help you here.

Anyway, I'll close this ticket for now in favor of the docker-borgmatic ticket you've filed. Thanks for your patience and persistence here.

I think updating borgmatic inside the container with pip should be sufficient for temporary testing like this. You should be able to confirm that the new version of borgmatic is actually getting used by changing your `crontab.txt` to run `borgmatic --version` instead of just `borgmatic`. *Newer* versions of the container might print the borgmatic version in use, but that doesn't help you here. Anyway, I'll close this ticket for now in favor of the docker-borgmatic ticket you've filed. Thanks for your patience and persistence here.
Owner

This is very likely fixed by borgmatic 1.9.0 via #918.

This is very likely fixed by borgmatic 1.9.0 via #918.
Sign in to join this conversation.
2 Participants
Notifications
Due Date
No due date set.
Dependencies

No dependencies set.

Reference: borgmatic-collective/borgmatic#903
No description provided.