Hooks are all executed at the same time. #473

New Issue

DonRichie · 2021-12-05T14:13:45Z

DonRichie commented

2021-12-05 14:13:45 +00:00

Hey,

I am currently trying to measure time using the hooks. For example how much time the checks take in comparison to the backups.

The problem is that the before checks and the after checks are called in two groups at the same time.

1. First the before hooks are called:

/srv/backups/pi_ssd_borgmatic.conf: Running command for pre-everything hook
/srv/backups/pi_ssd_borgmatic.conf: Running command for pre-prune hook
/srv/backups/pi_ssd_borgmatic.conf: Running command for pre-backup hook
/srv/backups/pi_ssd_borgmatic.conf: Running command for pre-check hook

2. Then the work happens
backup + checks + prune

3. Then the after hooks are called:

/srv/backups/pi_ssd_borgmatic.conf: Running command for post-prune hook
/srv/backups/pi_ssd_borgmatic.conf: Running command for post-backup hook
/srv/backups/pi_ssd_borgmatic.conf: Running command for post-check hook
/srv/backups/pi_ssd_borgmatic.conf: Running command for post-everything hook

I believe something is programmed wrong. The before and after hook for a piece of work should be executed right before and after it.

for example: 
	pre-everything 
    	-> pre-check 
        -> do check work 
        -> post-check 
        -> pre-backup 
        -> do backup work 
        -> post-backup 
    -> post-everything

Can someone please check and fix it?

Hey, I am currently trying to measure time using the hooks. For example how much time the checks take in comparison to the backups. The problem is that the before checks and the after checks are called in two groups at the same time. **1. First the before hooks are called:** ``` /srv/backups/pi_ssd_borgmatic.conf: Running command for pre-everything hook /srv/backups/pi_ssd_borgmatic.conf: Running command for pre-prune hook /srv/backups/pi_ssd_borgmatic.conf: Running command for pre-backup hook /srv/backups/pi_ssd_borgmatic.conf: Running command for pre-check hook ``` **2. Then the work happens** backup + checks + prune **3. Then the after hooks are called:** ``` /srv/backups/pi_ssd_borgmatic.conf: Running command for post-prune hook /srv/backups/pi_ssd_borgmatic.conf: Running command for post-backup hook /srv/backups/pi_ssd_borgmatic.conf: Running command for post-check hook /srv/backups/pi_ssd_borgmatic.conf: Running command for post-everything hook ``` I believe something is programmed wrong. The before and after hook for a piece of work should be executed right before and after it. ``` for example: pre-everything -> pre-check -> do check work -> post-check -> pre-backup -> do backup work -> post-backup -> post-everything ``` Can someone please check and fix it?

👍 2

Nikos410 commented

2021-12-06 12:39:10 +00:00

Hey there, I just encountered the same Issue.

I'm trying to pause a few containers before creating a backup and unpause them afterwards. But the after_backup hook don't run immediately after the backup completes, but only after the integrity checks have completed. I tried using the before_check hook to unpause the containers before the integrity checks start (-> after creating the backup has finished), but that hook runs before the backup job runs.

For me this is not really usable like this, since the integrity checks take a few hours, since some of my archives are pretty big. That would mean that my containers are paused for a few hours, which is not necessary, since creating the backup itself only takes a few minutes.

Taking a look at the relevant code it seems like this is the intended behaviour: All before_{action} hooks run at the start, next the actions are run, then the after_{action} hooks run at the end.

I don't think that this is the behaviour most users would expect. I would suggest changing it like @DonRichie suggested: before_prune -> prune -> after_prune -> before_backup -> backup -> after_backup -> before_check -> check -> after_check

I'm aware that this is probably a breaking change, but I think it is worth it, since it would make borgmatic much more flexible, enabling scenarios like the one I described above.

Or maybe there is another way to achieve what I described above?

Hey there, I just encountered the same Issue. I'm trying to pause a few containers before creating a backup and unpause them afterwards. But the `after_backup` hook don't run immediately after the backup completes, but only after the integrity checks have completed. I tried using the `before_check` hook to unpause the containers before the integrity checks start (-> after creating the backup has finished), but that hook runs before the backup job runs. For me this is not really usable like this, since the integrity checks take a few hours, since some of my archives are pretty big. That would mean that my containers are paused for a few hours, which is not necessary, since creating the backup itself only takes a few minutes. Taking a look at the [relevant code](https://projects.torsion.org/borgmatic-collective/borgmatic/src/branch/master/borgmatic/commands/borgmatic.py#L75) it seems like this is the intended behaviour: All `before_{action}` hooks run at the start, next the actions are run, then the `after_{action}` hooks run at the end. I don't think that this is the behaviour most users would expect. I would suggest changing it like @DonRichie suggested: `before_prune` -> `prune` -> `after_prune` -> `before_backup` -> `backup` -> `after_backup` -> `before_check` -> `check` -> `after_check` I'm aware that this is probably a breaking change, but I think it is worth it, since it would make borgmatic much more flexible, enabling scenarios like the one I described above. Or maybe there is another way to achieve what I described above?

timvahlbrock commented

2021-12-06 13:11:33 +00:00

Maybe the current behavior could be achieved with an alternate syntax like:

hooks:
  before_everything:
    if_prune:
      - echo "Start of all actions, prune will be performed."

Maybe the current behavior could be achieved with an alternate syntax like: ```yml hooks: before_everything: if_prune: - echo "Start of all actions, prune will be performed." ```

witten commented

2021-12-06 19:25:20 +00:00

@Nikos410 You are correct that the existing hook behavior is by design. The idea is that before and after hooks run once per configuration file. So if you have multiple repositories in a single configuration file and run multiple actions on them, the resulting invocations might look something like this:

Run before_backup hook.
Run before_check hook.
Run borg create on repository 1
Run borg check on repository 1
Run borg create on repository 2
Run borg check on repository 2
Run borg create on repository 3
Run borg check on repository 3
Run after_check hook.
Run after_backup hook.

That way, the before/after hooks don't run repeatedly. However, I could see potentially reorganzing things to run more like the following, which would be a fairly major reorganization from the code perspective:

Run before_backup hook.
Run borg create on repository 1
Run borg create on repository 2
Run borg create on repository 3
Run after_backup hook.
Run before_check hook.
Run borg check on repository 1
Run borg check on repository 2
Run borg check on repository 3
Run after_check hook.

However that may still not satisfy the desired use cases, because you're not able to either time a single create invocation or, as per the @Nikos410 case, pause/restart containers for a single repository. Still, might be sufficient for most cases?

@DonRichie Might it make sense to add action durations to borgmatic logs as an in-built feature?

@Nikos410 You are correct that the existing hook behavior is by design. The idea is that `before` and `after` hooks run [once per configuration file](https://torsion.org/borgmatic/docs/how-to/add-preparation-and-cleanup-steps-to-backups/). So if you have multiple repositories in a single configuration file and run multiple actions on them, the resulting invocations might look something like this: * Run `before_backup` hook. * Run `before_check` hook. * Run `borg create` on repository 1 * Run `borg check` on repository 1 * Run `borg create` on repository 2 * Run `borg check` on repository 2 * Run `borg create` on repository 3 * Run `borg check` on repository 3 * Run `after_check` hook. * Run `after_backup` hook. That way, the `before`/`after` hooks don't run repeatedly. However, I could see potentially reorganzing things to run more like the following, which would be a fairly major reorganization from the code perspective: * Run `before_backup` hook. * Run `borg create` on repository 1 * Run `borg create` on repository 2 * Run `borg create` on repository 3 * Run `after_backup` hook. * Run `before_check` hook. * Run `borg check` on repository 1 * Run `borg check` on repository 2 * Run `borg check` on repository 3 * Run `after_check` hook. However that may still not satisfy the desired use cases, because you're not able to either time a single `create` invocation or, as per the @Nikos410 case, pause/restart containers for a single repository. Still, might be sufficient for most cases? @DonRichie Might it make sense to add action durations to borgmatic logs as an in-built feature?

DonRichie commented

2021-12-07 06:23:15 +00:00

Need for reorganization
I reread the documentation and feel like currently the three before_* hooks are only useful to find out if a check, prune or backup happened at all. I read the text as for example the prune hook is skipped if no prune action happened.

I would like the regorganization because this still preserves the information mentioned above. At the same time it gives the additional information when exactly the single actions started and added. Thats an improvement!

How to cover all use cases for hooks
Regarding my use case and the healthcheck stuff i am trying: The prune check would still fail since the prune hook won't be executed if there is no prune happening. But I am fine with that behaviour since there might be use cases taking advantage of it.

In a perfect world I would like to have the cartesian product like this:
{success,fail,always}x{before,after}x{everything,backup,check,prune}
Each possible combination as a single hook in the configuration. Thats 3 * 2 * 4 = 24 combinations.
Little bit much to be honest. Maybe there is a data structure in the configuration suitable to make that flexible?
But maybe it would be also sufficient to have it documented well, like "if you want success+before+backup hook you need to set success_before_backup_hook = ...".

Durations measurement
Regarding your question @witten: Lets say I want to find out the last checks duration as a user. First I would execute "borg info ..." on my repository. But that isn't providing any information about how much time the last check took. Next step would be calling "journalctl -u backupjob.service" giving your logs. Therefore I want to agree and wish for some duration measurements in the log output.

As I already mentioned in the other issue a statistics hook would be nice. That would require configs settings for http url, http body (with templating) and http headers".

**Need for reorganization** I reread the documentation and feel like currently the three before_* hooks are only useful to find out if a check, prune or backup happened at all. I read the text as for example the prune hook is skipped if no prune action happened. I would like the regorganization because this still preserves the information mentioned above. At the same time it gives the additional information when exactly the single actions started and added. Thats an improvement! ---- **How to cover all use cases for hooks** Regarding my use case and the healthcheck stuff i am trying: The prune check would still fail since the prune hook won't be executed if there is no prune happening. But I am fine with that behaviour since there might be use cases taking advantage of it. In a perfect world I would like to have the cartesian product like this: `{success,fail,always}x{before,after}x{everything,backup,check,prune}` Each possible combination as a single hook in the configuration. Thats `3 * 2 * 4 = 24` combinations. Little bit much to be honest. Maybe there is a data structure in the configuration suitable to make that flexible? But maybe it would be also sufficient to have it documented well, like "if you want success+before+backup hook you need to set success_before_backup_hook = ...". ---- **Durations measurement** Regarding your question @witten: Lets say I want to find out the last checks duration as a user. First I would execute "borg info ..." on my repository. But that isn't providing any information about how much time the last check took. Next step would be calling "journalctl -u backupjob.service" giving your logs. Therefore I want to agree and wish for some duration measurements in the log output. As I already mentioned in the other issue a statistics hook would be nice. That would require configs settings for http url, http body (with templating) and http headers".

timvahlbrock referenced this issue

2021-12-08 10:08:22 +00:00

on_error hook needs corresponding on_success hook #475

timvahlbrock commented

2021-12-08 10:45:05 +00:00

Alternate Syntax
I think we have a conflict between ease of configuration and versatility of the configuration. Maybe this can be resolved with a syntax like this (here for the pausing/unpausing use case that @Nikos410 and I are using):

hooks:
  pause-containers:
    task: 'create'
    timing: 'before'
    execute:
      - echo "Pausing containers"
      - docker container ps --filter 'label=backup.pause' --format '{{.ID}}' | xargs -r -n1 docker container pause
  unpause-containers:
    task: 'create'
    timing: 'after'
    execute:
      - echo "Unpausing containers"
      - docker container ps --filter 'label=backup.pause' --format '{{.ID}}' | xargs -r -n1 docker container unpause

task then could be create | prune | check | extract | everything | any. The any case would be used for hooks that should run before each individual task, but it doesn't matter which one. In the same manner, before | after | before-all | after-all | any could be used to run a hook before or after each single task, or before or after all of the tasks of this type. before and beforeAll in combination with everything in the task option would then do the same. Alternatively, the old syntax style could be used, but before-any-any doesn't quite read as nice.

Statistics
To gather statistics data a hook with task: any and timing: any or a dedicated hook-name could be used. Similar to pre-commit and pre-push hooks in git, addtional information, about the repository, the command, which actions are about to run and the hook name could be passed as parameters into the script. Maybe it would be useful to just be able to pass the path to a bash script to execute to the execute param.

Evaluation
Advantages:

Old hooks can stay supported, so no breaking change is created.
High flexibility, but no need to check for each hook type explicitly when parsing.
Hooks become more powerful due to additional options being passed.

Disadvantages:

New hook syntax differs from old one, which might be a bit confusing when reading the configuration file (Can possible resolved by versioning config file syntax, like docker-compose does).
Larger implementation effort.

Needs further discussion:

Execution order

**Alternate Syntax** I think we have a conflict between ease of configuration and versatility of the configuration. Maybe this can be resolved with a syntax like this (here for the pausing/unpausing use case that @Nikos410 and I are using): ```yml hooks: pause-containers: task: 'create' timing: 'before' execute: - echo "Pausing containers" - docker container ps --filter 'label=backup.pause' --format '{{.ID}}' | xargs -r -n1 docker container pause unpause-containers: task: 'create' timing: 'after' execute: - echo "Unpausing containers" - docker container ps --filter 'label=backup.pause' --format '{{.ID}}' | xargs -r -n1 docker container unpause ``` `task` then could be `create | prune | check | extract | everything | any`. The `any` case would be used for hooks that should run before each individual task, but it doesn't matter which one. In the same manner, `before | after | before-all | after-all | any` could be used to run a hook before or after each single task, or before or after all of the tasks of this type. `before` and `beforeAll` in combination with `everything` in the task option would then do the same. Alternatively, the old syntax style could be used, but `before-any-any` doesn't quite read as nice. ----- **Statistics** To gather statistics data a hook with `task: any` and `timing: any` or a dedicated hook-name could be used. Similar to pre-commit and pre-push hooks in git, addtional information, about the repository, the command, which actions are about to run and the hook name could be passed as parameters into the script. Maybe it would be useful to just be able to pass the path to a bash script to execute to the `execute` param. ----- **Evaluation** Advantages: * Old hooks can stay supported, so no breaking change is created. * High flexibility, but no need to check for each hook type explicitly when parsing. * Hooks become more powerful due to additional options being passed. ----- Disadvantages: * New hook syntax differs from old one, which might be a bit confusing when reading the configuration file (Can possible resolved by versioning config file syntax, like docker-compose does). * Larger implementation effort. ----- Needs further discussion: * Execution order

👍 2

timvahlbrock commented

2021-12-08 11:12:57 +00:00

What i forgot: the result.

Could be implemented in a similar fashion to task and timing, but will only be allowed if timing is after or afterAll or any. Possible values: success | failure | any

What i forgot: the result. Could be implemented in a similar fashion to task and timing, but will only be allowed if timing is after or afterAll or any. Possible values: `success | failure | any`

Nikos410 commented

2022-02-05 14:12:26 +00:00

Hey, is there any update about this issue? @witten what do you think about the solution @timvahlbrock suggested?

witten commented

2022-02-05 23:59:57 +00:00

I think it's a cool idea in terms of the syntax, but I don't think it's needed to solve the underlying issue here. Specifically, the problem as I understand it is nicely summarized in the the current ticket title: "Hooks are all executed at the same time." Meaning, in this case, after_backup runs after consistency checks along with all other after_* hooks rather than immediately after backups (create), making container unpausing after backups and before consistency checks difficult. I realize the proposal above includes both before and beforeAll timings to address that, but I don't know that we need both. I think we just need them to run directly before the corresponding action (create, etc).

So I think the solution is to fix that issue, and then the syntax ideas could be discussed on a separate ticket. Personally, I'm not married to any existing borgmatic syntax. If it needs to evolve to satisfy changing requirements, great. I'd also recommend filing the statistics hook ask as a separate issue so it can be implemented on its own.

Let me know your thoughts!

I think it's a cool idea in terms of the syntax, but I don't think it's needed to solve the underlying issue here. Specifically, the problem as I understand it is nicely summarized in the the current ticket title: "Hooks are all executed at the same time." Meaning, in this case, `after_backup` runs after consistency checks along with all other `after_*` hooks rather than immediately after backups (`create`), making container unpausing after backups and before consistency checks difficult. I realize the proposal above includes both `before` and `beforeAll` timings to address that, but I don't know that we need both. I think we just need them to run directly before the corresponding action (`create`, etc). So I think the solution is to fix *that* issue, and then the syntax ideas could be discussed on a separate ticket. Personally, I'm not married to any existing borgmatic syntax. If it needs to evolve to satisfy changing requirements, great. I'd also recommend filing the statistics hook ask as a separate issue so it can be implemented on its own. Let me know your thoughts!

timvahlbrock commented

2022-02-06 00:12:26 +00:00

So you're proposing to adapt the current behavior of the hooks? As far as I'm concerned, that would be a breaking change for some existing configurations. Right?

witten commented

2022-02-06 00:25:13 +00:00

I am proposing that as a fix, yes. It is "breaking" in the sense that this would run the hooks at a different time, but the current timing is "incorrect" as folks here have pointed out (even if it is by design). I would hope there aren't many users relying on that timing. I'd probably have to bump borgmatic's major or minor version to indicate the change.

R0cketM0nster commented

2022-04-02 12:25:25 +00:00

Came here to log this issue also. Great to see it is already being looked at! Any update on when this is likely to be fixed as some of my checks run for a couple of hours and the service is down until these complete, whereas the backups themselves might only take 15-20 minutes.

witten commented

2022-04-22 05:08:10 +00:00

This has been implemented in master! Beta testers wanted! See below.

Now, instead of executing "before" command hooks before all borgmatic actions run (and "after" hooks after), borgmatic executes these hooks right before/after the corresponding action. E.g., "before_check" now runs immediately before the "check" action.

Here's an example run with these changes in place and a bunch of echo commands configured for the various hooks (The echos are "Starting ...", "Finished ...", etc.):

[root@flux tmp]# borgmatic -c test.yaml -v 1
test.yaml: Running command for pre-everything hook
Starting actions.
test.yaml: Running command for pre-prune hook
Starting pruning.
test.borg: Pruning archives
test.yaml: Running command for post-prune hook
Finished pruning.
test.yaml: Running command for pre-compact hook
Starting compaction.
test.borg: Compacting segments
compaction freed about 2.90 kB repository space.
test.yaml: Running command for post-compact hook
Finished compaction.
test.yaml: Running command for pre-backup hook
Starting backup.
test.borg: Creating archive
Creating archive at "test.borg::flux-2022-04-21T21:55:25.588108"
test.yaml: Running command for post-backup hook
Finished a backup.
test.yaml: Running command for pre-check hook
Starting checks.
test.borg: Running consistency checks
Starting repository check
finished segment check at segment 208
Starting repository index check
Index object count match.
Finished full repository check, no problems found.
Starting archive consistency check...
Analyzing archive flux-2022-04-20T15:50:32.061146 (1/4)
Analyzing archive flux-2022-04-20T16:00:37.856820 (2/4)
Analyzing archive flux-2022-04-21T20:01:46.295056 (3/4)
Analyzing archive flux-2022-04-21T21:55:25.588108 (4/4)
Orphaned objects check skipped (needs all archives checked).
Archive consistency check complete, no problems found.
test.yaml: Running command for post-check hook
Finished checks.
test.yaml: Running command for post-everything hook
Completed actions.

summary:
test.yaml: Successfully ran configuration file

A side effect of these changes: before/after command hooks now run once for each configured repository instead of once per configuration file. This means your hooks may run more than once if you have multiple repositories configured! Additionally, the "repositories" interpolated variable has been changed to "repository", containing the path to the current repository for the hook. This means you can perform appropriate per-repository logic in your hooks if you like.

Since these are some pretty major changes, I'm looking for beta testers to try them out before release. Anyone have a non-production repository or three they'd like to try this on? This is your opportunity to make sure the feature meets your requirements before it's released!

Thanks for all of your ideas and patience with this feature.

This has been implemented in master! **Beta testers wanted!** See below. Now, instead of executing "before" command hooks before *all* borgmatic actions run (and "after" hooks after), borgmatic executes these hooks right before/after the corresponding action. E.g., "before_check" now runs immediately before the "check" action. Here's an example run with these changes in place and a bunch of `echo` commands configured for the various hooks (The echos are "Starting ...", "Finished ...", etc.): ``` [root@flux tmp]# borgmatic -c test.yaml -v 1 test.yaml: Running command for pre-everything hook Starting actions. test.yaml: Running command for pre-prune hook Starting pruning. test.borg: Pruning archives test.yaml: Running command for post-prune hook Finished pruning. test.yaml: Running command for pre-compact hook Starting compaction. test.borg: Compacting segments compaction freed about 2.90 kB repository space. test.yaml: Running command for post-compact hook Finished compaction. test.yaml: Running command for pre-backup hook Starting backup. test.borg: Creating archive Creating archive at "test.borg::flux-2022-04-21T21:55:25.588108" test.yaml: Running command for post-backup hook Finished a backup. test.yaml: Running command for pre-check hook Starting checks. test.borg: Running consistency checks Starting repository check finished segment check at segment 208 Starting repository index check Index object count match. Finished full repository check, no problems found. Starting archive consistency check... Analyzing archive flux-2022-04-20T15:50:32.061146 (1/4) Analyzing archive flux-2022-04-20T16:00:37.856820 (2/4) Analyzing archive flux-2022-04-21T20:01:46.295056 (3/4) Analyzing archive flux-2022-04-21T21:55:25.588108 (4/4) Orphaned objects check skipped (needs all archives checked). Archive consistency check complete, no problems found. test.yaml: Running command for post-check hook Finished checks. test.yaml: Running command for post-everything hook Completed actions. summary: test.yaml: Successfully ran configuration file ``` A side effect of these changes: before/after command hooks now run once for each configured repository instead of once per configuration file. This means your hooks may run more than once if you have multiple repositories configured! Additionally, the "repositories" interpolated variable has been changed to "repository", containing the path to the current repository for the hook. This means you can perform appropriate per-repository logic in your hooks if you like. Since these are some pretty major changes, I'm looking for beta testers to try them out before release. Anyone have a non-production repository or three they'd like to try this on? This is your opportunity to make sure the feature meets your requirements before it's released! Thanks for all of your ideas and patience with this feature.

witten referenced this issue from a commit

2022-04-22 05:08:41 +00:00

Instead of executing "before" command hooks before all borgmatic actions run (and "after" hooks after), execute these hooks right before/after the corresponding action (#473).

witten referenced this issue

2022-04-22 06:18:46 +00:00

[question] Is it possible to run before_backup hook not only once, but everytime a repo starts #320

witten referenced this issue

2022-04-23 02:56:05 +00:00

Add context for various hooks. #469

witten commented

2022-04-26 17:10:20 +00:00

Released in borgmatic 1.6.0! Please let me know if you have any problems with this change or have any feedback about it.