Bug 36435 - Prevent warnings from interrupting koha-run-backups when deleting old backup files
Summary: Prevent warnings from interrupting koha-run-backups when deleting old backup ...
Status: Signed Off
Alias: None
Product: Koha
Classification: Unclassified
Component: Command-line Utilities (show other bugs)
Version: Main
Hardware: All All
: P5 - low major
Assignee: Danyon Sewell
QA Contact: Testopia
URL:
Keywords:
Depends on: 30627
Blocks:
  Show dependency treegraph
 
Reported: 2024-03-27 02:01 UTC by Aleisha Amohia
Modified: 2024-09-09 09:12 UTC (History)
7 users (show)

See Also:
Change sponsored?: Sponsored
Patch complexity: ---
Documentation contact:
Documentation submission:
Text to go in the release notes:
Version(s) released in:
Circulation function:


Attachments
Bug 36435: Specify to not show warnings if file changed while koha-dump running (1.09 KB, patch)
2024-03-27 02:53 UTC, Aleisha Amohia
Details | Diff | Splinter Review
Bug 36435: Always delete old backup files (2.10 KB, patch)
2024-04-02 08:42 UTC, Aleisha Amohia
Details | Diff | Splinter Review
Bug 36435: Always delete old backup files (1.34 KB, patch)
2024-04-08 02:24 UTC, Danyon Sewell
Details | Diff | Splinter Review
Bug 36435: [alternative] Catch harmless errors in koha-dump (1.92 KB, patch)
2024-05-01 02:20 UTC, Aleisha Amohia
Details | Diff | Splinter Review
Bug 36435: Always delete old backup files (2.81 KB, patch)
2024-05-01 02:22 UTC, Aleisha Amohia
Details | Diff | Splinter Review
Bug 36435: [alternative] Catch harmless errors in koha-dump (1.96 KB, patch)
2024-05-01 07:23 UTC, David Nind
Details | Diff | Splinter Review
Bug 36435: Always delete old backup files (2.85 KB, patch)
2024-05-01 07:23 UTC, David Nind
Details | Diff | Splinter Review
Bug 36435: [alternative] Catch harmless errors in koha-dump (3.58 KB, patch)
2024-09-09 09:07 UTC, Michał
Details | Diff | Splinter Review
Bug 36435: Always delete old backup files (3.02 KB, patch)
2024-09-09 09:08 UTC, Michał
Details | Diff | Splinter Review

Note You need to log in before you can comment on or make changes to this bug.
Description Aleisha Amohia 2024-03-27 02:01:35 UTC
Since the changes at Bug 30627, sometimes backup files older than X days don't get deleted as they are meant to.

In our case, this happens when:

- koha-dump does not return a success status
- because `tar -c` throws a warning "tar: var/log/koha/INSTANCENAME/opac-access.log: file changed as we read it"

The new dump is created, but the warning is enough to interrupt koha-run-backups before it gets to deleting old backups.

This causes excess backups to be stored and fills up the disk.
Comment 1 Aleisha Amohia 2024-03-27 02:53:00 UTC
Created attachment 163970 [details] [review]
Bug 36435: Specify to not show warnings if file changed while koha-dump running

This patch adds a switch to the tar --create command called by koha-dump to prevent 'file changed' warnings, which stop koha-dump from returning a success status, which interrupts koha-run-backups before it can delete old backup files.

Sponsored-by: Catalyst IT
Comment 2 Aleisha Amohia 2024-03-27 20:01:38 UTC
This fix did not work unfortunately, will propose an alternative
Comment 3 Aleisha Amohia 2024-04-02 08:42:02 UTC
Created attachment 164240 [details] [review]
Bug 36435: Always delete old backup files

Recently this step was moved inside the condition so would only run if koha-dump returned a success status.

If a log file is being written to while koha-dump runs tar, tar returns a warning and a non-zero exit status. When this happens, koha-dump still completes but the success status condition is not true, so the old backups files are not deleted.

There is no nice way to ignore the non-zero exit status from tar, and large libraries receive enough traffic for the tar 'file changed as we read it' warning to cause enough problems that old backup files begin to fill up the disk.

This patch moves the step to delete old backup files outside of the koha-dump condition. This returns the script to the behaviour before it was changed in Bug 30627.

Sponsored-by: Catalyst IT
Comment 4 Danyon Sewell 2024-04-08 02:24:39 UTC
Created attachment 164491 [details] [review]
Bug 36435: Always delete old backup files
Comment 5 Danyon Sewell 2024-04-08 02:28:22 UTC
Have written patch to break the conditional that koha-dump was inside so that the deletion of old logs will still happen.

As Aleisha pointed out this has essentially changed the behavior back to how it was prior to the enhancement being written.

Test plan:
1. Create a number of backups and edit their modify time to being older than 2 days
2. run the koha-run-backups script and try and write to one of the files it includes while it's being backed up (you'll trigger a warning from tar saying the file changed as it was being read)
3. verify that the older backups are not being cleaned up and deleted despite new backups being made.
4. Apply this patch
5. Complete steps 1-2 again and then go and look to see if the older backups are being deleted.
Comment 6 Fridolin Somers 2024-04-24 05:35:36 UTC
Rise importance to major since it can break the server
Comment 7 Andreas Jonsson 2024-04-26 00:27:11 UTC
I think is more important that old backups are not deleted unless a new backup have been created and that we should instead catch errors that are harmless.

diff --git a/debian/scripts/koha-dump b/debian/scripts/koha-dump
index 29f02bc45a..85ffc7e4d4 100755
--- a/debian/scripts/koha-dump
+++ b/debian/scripts/koha-dump
@@ -124,6 +124,10 @@ dump_instance()
         output="$output to $metadump"
         [ "$quiet" = "no" ] && echo "$output"
 
+        # tar has exit status 1 if any file has changed while being read,
+        # which is likely to happen as the logfiles are included.
+        set +e
+
         tar -czf "$metadump" -C / $excludes \
             "etc/koha/sites/$name" \
             "etc/apache2/sites-available/$instancefile" \
@@ -133,6 +137,12 @@ dump_instance()
             $uploaded_files_dir \
             $uploaded_temp_files_dir
 
+        if [ "$?" != "1" -a "$?" != "0" ]; then
+            exit $?
+        fi
+
+        set -e
+
         chown "root:$name-koha" "$metadump"
         chmod g+r "$metadump"
Comment 8 David Nind 2024-04-30 22:41:50 UTC
I'm getting a sha1/fake ancestor error when trying to apply the pacth 8-(...

git bz apply 36435

Bug 36435 - Prevent warnings from interrupting koha-run-backups when deleting old backup files

164491 - Bug 36435: Always delete old backup files

Apply? [(y)es, (n)o, (i)nteractive] y
Applying: Bug 36435: Always delete old backup files
.git/rebase-apply/patch:23: trailing whitespace.
    
error: sha1 information is lacking or useless (debian/scripts/koha-run-backups).
error: could not build fake ancestor
Patch failed at 0001 Bug 36435: Always delete old backup files

Testing notes (using KTD):

1. I used the script in bug 30627#c9 to create the backups with different dates.

2. I couldn't replicate the issue, as the backup with the sample data in KTD runs too fast! Is there a way to slow down the backup?
Comment 9 Aleisha Amohia 2024-05-01 02:20:16 UTC
Created attachment 165936 [details] [review]
Bug 36435: [alternative] Catch harmless errors in koha-dump

tar has exit status 1 if any file has changed while being read, which is likely to happen as the logfiles are included. this patch will catch these harmless errors so that koha-dump will still return a success code.

Test plan:
1. Create a number of backups and edit their modify time to being older than 2 days
2. run the koha-run-backups script and try and write to one of the files it includes while it's being backed up (you'll trigger a warning from tar saying the file changed as it was being read)
3. verify that the older backups are not being cleaned up and deleted despite new backups being made.
4. Apply this patch
5. Complete steps 1-2 again and then go and look to see if the older backups are being deleted.

Sponsored-by: Catalyst IT
Comment 10 Aleisha Amohia 2024-05-01 02:22:46 UTC
Created attachment 165937 [details] [review]
Bug 36435: Always delete old backup files

Recently this step was moved inside the condition so would only run if koha-dump returned a success status.

If a log file is being written to while koha-dump runs tar, tar returns a warning and a non-zero exit status. When this happens, koha-dump still completes but the success status condition is not true, so the old backups files are not deleted.

There is no nice way to ignore the non-zero exit status from tar, and large libraries receive enough traffic for the tar 'file changed as we read it' warning to cause enough problems that old backup files begin to fill up the disk.

This patch removes the koha-dump conditional. This returns the script to the behaviour before it was changed in Bug 30627.

Test plan:
1. Create a number of backups and edit their modify time to being older than 2 days
2. run the koha-run-backups script and try and write to one of the files it includes while it's being backed up (you'll trigger a warning from tar saying the file changed as it was being read)
3. verify that the older backups are not being cleaned up and deleted despite new backups being made.
4. Apply this patch
5. Complete steps 1-2 again and then go and look to see if the older backups are being deleted.

Sponsored-by: Catalyst IT
Comment 11 Aleisha Amohia 2024-05-01 02:23:53 UTC
(In reply to David Nind from comment #8)
> I'm getting a sha1/fake ancestor error when trying to apply the pacth 8-(...
> 
> git bz apply 36435
> 
> Bug 36435 - Prevent warnings from interrupting koha-run-backups when
> deleting old backup files
> 
> 164491 - Bug 36435: Always delete old backup files
> 
> Apply? [(y)es, (n)o, (i)nteractive] y
> Applying: Bug 36435: Always delete old backup files
> .git/rebase-apply/patch:23: trailing whitespace.
>     
> error: sha1 information is lacking or useless
> (debian/scripts/koha-run-backups).
> error: could not build fake ancestor
> Patch failed at 0001 Bug 36435: Always delete old backup files
> 
> Testing notes (using KTD):
> 
> 1. I used the script in bug 30627#c9 to create the backups with different
> dates.
> 
> 2. I couldn't replicate the issue, as the backup with the sample data in KTD
> runs too fast! Is there a way to slow down the backup?

I've attached Andreas' suggestion as an alternative patch, and fixed Danyon's patch.

I think from memory the only way we were able to write to the logs fast enough was by accessing the OPAC so the opac-access.log or opac-access-ssl.log was written to!
Comment 12 David Nind 2024-05-01 07:23:21 UTC
Created attachment 165943 [details] [review]
Bug 36435: [alternative] Catch harmless errors in koha-dump

tar has exit status 1 if any file has changed while being read, which is likely to happen as the logfiles are included. this patch will catch these harmless errors so that koha-dump will still return a success code.

Test plan:
1. Create a number of backups and edit their modify time to being older than 2 days
2. run the koha-run-backups script and try and write to one of the files it includes while it's being backed up (you'll trigger a warning from tar saying the file changed as it was being read)
3. verify that the older backups are not being cleaned up and deleted despite new backups being made.
4. Apply this patch
5. Complete steps 1-2 again and then go and look to see if the older backups are being deleted.

Sponsored-by: Catalyst IT
Signed-off-by: David Nind <david@davidnind.com>
Comment 13 David Nind 2024-05-01 07:23:24 UTC
Created attachment 165944 [details] [review]
Bug 36435: Always delete old backup files

Recently this step was moved inside the condition so would only run if koha-dump returned a success status.

If a log file is being written to while koha-dump runs tar, tar returns a warning and a non-zero exit status. When this happens, koha-dump still completes but the success status condition is not true, so the old backups files are not deleted.

There is no nice way to ignore the non-zero exit status from tar, and large libraries receive enough traffic for the tar 'file changed as we read it' warning to cause enough problems that old backup files begin to fill up the disk.

This patch removes the koha-dump conditional. This returns the script to the behaviour before it was changed in Bug 30627.

Test plan:
1. Create a number of backups and edit their modify time to being older than 2 days
2. run the koha-run-backups script and try and write to one of the files it includes while it's being backed up (you'll trigger a warning from tar saying the file changed as it was being read)
3. verify that the older backups are not being cleaned up and deleted despite new backups being made.
4. Apply this patch
5. Complete steps 1-2 again and then go and look to see if the older backups are being deleted.

Sponsored-by: Catalyst IT
Signed-off-by: David Nind <david@davidnind.com>
Comment 14 David Nind 2024-05-01 07:27:06 UTC
I've signed off both patches, despite not being able to replicate the issue. (Not able to successfully interrupt backup by reloading the OPAC home or running a search at the same time)

Backups are still run successfully with the updated changes and older backups are deleted.

Feel free to change back to needs sign off if that is not sufficient, or more rigorous testing is required.
Comment 15 Danyon Sewell 2024-05-02 22:50:31 UTC
After applying the patch to one of our more active clients that gets a lot of traffic it seems this doesn't seem to fix the issue. It did remove the oldest DB backup but not the .tar.gz file due to the same reasons as before `tar: var/log/koha/<instance>/plack.log: file changed as we read it`
Comment 16 Andreas Jonsson 2024-05-05 14:19:19 UTC
If the sql-file is deleted but not the tar.gz-file, it is due to bug 36425 (because the tar.gz file will be newer than the sql.gz file, and you are hitting time interval between n x 24 hours after the sql dump but before n x 24 hours after the tar.gz file is created.)
Comment 17 Michał 2024-08-14 13:25:48 UTC
I confirm that we face the same issue as described in the bug. As for reproduction, it's worth noting that our opac/plack can be as big as 500+ MB in size, it's worth accounting for that as it has to take some time for full file to be read to more easily hit this problem. And the OPAC should be refreshed in the background with some script that does it rapidly, think each 100 ms rather than 1+ sec.

To address the comments 15 and 16: if the issue mentioned by Danyon is indeed bug 36425 and not this one, can we change the status of this bug back to Signed Off?

Danyon, could you please confirm this? If I understand correctly, if it's the case of bug 36425, then the .tar.gz file from 2 days ago wouldn't be removed, but the next one then should, giving you an odd (not even) number of files, but still no files older than N+1 days of configured backup retention, so no older than 3 days... Whereas if this primary bug still occurs, you'd see files not getting deleted at all like we see now, no matter how many days pass.

Logically speaking, with this patch, the outcome of koha-dump should not affect the attempt of deletion of old backups at all in fact. Meaning that if backups still fail to get deleted, it has to be due to some other problem unrelated to this bug and its fix, despite the warning message still logged in the process possibly suggesting otherwise.
Comment 18 Michał 2024-08-14 13:36:27 UTC
I confirmed that the patch fixes the issues for us too now, I'll probably sign-off the patch on Monday and change the bug's status back to move it forward, unless we receive some follow-up feedback that something in it is still broken by that time...
Comment 19 Danyon Sewell 2024-08-14 21:08:56 UTC
(In reply to Michał from comment #18)
> I confirmed that the patch fixes the issues for us too now, I'll probably
> sign-off the patch on Monday and change the bug's status back to move it
> forward, unless we receive some follow-up feedback that something in it is
> still broken by that time...

(In reply to Michał from comment #17)
> I confirm that we face the same issue as described in the bug. As for
> reproduction, it's worth noting that our opac/plack can be as big as 500+ MB
> in size, it's worth accounting for that as it has to take some time for full
> file to be read to more easily hit this problem. And the OPAC should be
> refreshed in the background with some script that does it rapidly, think
> each 100 ms rather than 1+ sec.
> 
> To address the comments 15 and 16: if the issue mentioned by Danyon is
> indeed bug 36425 and not this one, can we change the status of this bug back
> to Signed Off?
> 
> Danyon, could you please confirm this? If I understand correctly, if it's
> the case of bug 36425, then the .tar.gz file from 2 days ago wouldn't be
> removed, but the next one then should, giving you an odd (not even) number
> of files, but still no files older than N+1 days of configured backup
> retention, so no older than 3 days... Whereas if this primary bug still
> occurs, you'd see files not getting deleted at all like we see now, no
> matter how many days pass.
> 
> Logically speaking, with this patch, the outcome of koha-dump should not
> affect the attempt of deletion of old backups at all in fact. Meaning that
> if backups still fail to get deleted, it has to be due to some other problem
> unrelated to this bug and its fix, despite the warning message still logged
> in the process possibly suggesting otherwise.


Hi Michal.

Yes you are correct, the behavior we experience is also better described in 36425
Comment 20 Michał 2024-09-09 09:07:47 UTC
Created attachment 171178 [details] [review]
Bug 36435: [alternative] Catch harmless errors in koha-dump

tar has exit status 1 if any file has changed while being read, which is likely to happen as the logfiles are included. this patch will catch these harmless errors so that koha-dump will still return a success code.

Test plan:
1. Create a number of backups and edit their modify time to being older than 2 days
2. run the koha-run-backups script and try and write to one of the files it includes while it's being backed up (you'll trigger a warning from tar saying the file changed as it was being read)
3. verify that the older backups are not being cleaned up and deleted despite new backups being made.
4. Apply this patch
5. Complete steps 1-2 again and then go and look to see if the older backups are being deleted.

Sponsored-by: Catalyst IT
Signed-off-by: David Nind <david@davidnind.com>
Co-authored-by: Michał Kula <148193449+mkibp@users.noreply.github.com>
Signed-off-by: Michał Kula <148193449+mkibp@users.noreply.github.com>
Comment 21 Michał 2024-09-09 09:08:36 UTC
Created attachment 171179 [details] [review]
Bug 36435: Always delete old backup files

Recently this step was moved inside the condition so would only run if koha-dump returned a success status.

If a log file is being written to while koha-dump runs tar, tar returns a warning and a non-zero exit status. When this happens, koha-dump still completes but the success status condition is not true, so the old backups files are not deleted.

There is no nice way to ignore the non-zero exit status from tar, and large libraries receive enough traffic for the tar 'file changed as we read it' warning to cause enough problems that old backup files begin to fill up the disk.

This patch removes the koha-dump conditional. This returns the script to the behaviour before it was changed in Bug 30627.

Test plan:
1. Create a number of backups and edit their modify time to being older than 2 days
2. run the koha-run-backups script and try and write to one of the files it includes while it's being backed up (you'll trigger a warning from tar saying the file changed as it was being read)
3. verify that the older backups are not being cleaned up and deleted despite new backups being made.
4. Apply this patch
5. Complete steps 1-2 again and then go and look to see if the older backups are being deleted.

Sponsored-by: Catalyst IT
Signed-off-by: David Nind <david@davidnind.com>
Signed-off-by: Michał Kula <148193449+mkibp@users.noreply.github.com>
Comment 22 Michał 2024-09-09 09:12:48 UTC
As discussed above, reverting status back to Signed Off now (took me a bit of delay, but we got there).

I rebased the two patches on top of current main. For the "[alternative]" patch touching koha-dump script, I also sorted out some problems with previous patch there that caused some code duplication and broken whitespacing, so that now it's looking all neat again (and thus also added myself to Co-authored-by, since I technically changed the original commit a bit, hopefully that's okay? if not, feel free to remove that line from commit message...).