no metrics pushed on failed operation backup #161
Description
npbackup 3.0.1-linux-cli-x64-public-3.12-c 2025032101
Ubuntu 22.10 linux.
here I am again! All restic backup and check cronjobs are replaced with npbackup cron jobs.
I made one change to the cron timing since I saw something intereting when running a */15 * * * * backup job on a 24/7 server. Basically that makes a daily backup, but it jumps +15mins each day.
Enfin, on to the thing I wanted to report:
steps to reproduce
- create two independent but time-conflicting npbackup backup jobs (could work with other actions as well but mine are backup), example:
00 2 * * * /path/to/first.repo.npbackup_backup.sh */15 * * * * /path/to/second.repo.npbackup_backup.sh - wait until executing is finished.
- observe the logfile, there is a conflicting time at 02:00 where both are launched:
~/npbackup$ grep "2025-05-13 02:00:" npbackup-cli.log 2025-05-13 02:00:01,366 :: INFO :: npbackup 3.0.1-linux-cli-x64-public-3.12-c 2025032101 - Copyright (C) 2022-2025 NetInvent running as root 2025-05-13 02:00:01,368 :: INFO :: npbackup 3.0.1-linux-cli-x64-public-3.12-c 2025032101 - Copyright (C) 2022-2025 NetInvent running as root 2025-05-13 02:00:01,391 :: INFO :: Loaded config 115C631B in /home/ubuntu/npbackup/npbackup.x300server.v3.conf 2025-05-13 02:00:01,399 :: INFO :: Searching for a backup newer than 1 day, 0:00:00 ago 2025-05-13 02:00:01,407 :: INFO :: Loaded config 115C631B in /home/ubuntu/npbackup/npbackup.x300server.v3.conf 2025-05-13 02:00:01,422 :: CRITICAL :: There is already an operation running by NPBackup. Will not launch operation backup to avoid concurrency 2025-05-13 02:00:01,422 :: INFO :: Runner took 0.000786 seconds for backup 2025-05-13 02:00:01,422 :: ERROR :: Operation finished 2025-05-13 02:00:01,434 :: INFO :: ExecTime = 0:00:00.068268, finished, state is: critical. 2025-05-13 02:00:03,112 :: INFO :: Snapshots listed successfully 2025-05-13 02:00:03,112 :: INFO :: Recent snapshot 591676ff of 2025-05-12T02:00:04.156897706+02:00 exists ! 2025-05-13 02:00:03,112 :: INFO :: Most recent backup in repo syncthing is from 2025-05-12 02:00:04.156897+02:00 2025-05-13 02:00:03,112 :: INFO :: Runner took 1.713357 seconds for has_recent_snapshot 2025-05-13 02:00:03,113 :: INFO :: No backup necessary 2025-05-13 02:00:03,113 :: INFO :: Runner took 1.713966 seconds for backup 2025-05-13 02:00:03,113 :: INFO :: Operation finished 2025-05-13 02:00:03,119 :: INFO :: ExecTime = 0:00:01.754559, finished, state is: success. - observe results.
- one backup was skipped since a ¨recent backup" was found. >>> no metrics expected.
- one backup failed since "There is aleady an operation running by npbackup". >>> yes metrics expected. failed operation.
- metrics pushed to the dashboard? no 13th May fail operations are logged (since no metrics are pushed).
expected behaviour
when npbackup can conclude on a failed execution, that should be logged as a failed backup / operation metrics.
p.s. not sure why npbackup cannot be launced twice at the same time. FYI - I use the same config file but two different repos. If there is a limitation it is easy to work around it ( I moved the cron times a bit) but would be good to mention in the docs and/or wiki.