Welcome! » Log In » Create A New Profile

amflush run while amdump underway tries to flush .tmp files

Posted by Nathan Stratton Treadway 
Nathan Stratton Treadway
amflush run while amdump underway tries to flush .tmp files
November 16, 2017 09:59PM
(Amanda v3.5)

I noticed that Amanda 3.5 no longer aborts amflush if amdump is
currently running (as older versions of Amanda do).

So out of curiousity I kicked of "amflush TestBackup" while amdump was
busy dumping to the holding disk... and I discovered that amflush
actually tries to go ahead and flush the ".tmp" file files that it finds
in the holding directory:

===== From /var/log/amanda/server/TestBackup/amflush.20171116200510.debug:
Thu Nov 16 20:05:17.590062176 2017: pid 26860: thd-0x2f07e00: amflush: flushing /amanda/TestBackup-holding/20171116200002/client1._.0.tmp
Thu Nov 16 20:05:17.590096226 2017: pid 26860: thd-0x2f07e00: amflush: flushing /amanda/TestBackup-holding/20171116200002/client2._.1.tmp
=====

In this case the taper failed (and thus the amflush didn't actually do
anything with the .tmp files)....:

===== From /var/log/amanda/TestBackup/amdump.1:
driver: send-cmd time 14.132 to taper0: FILE-WRITE worker0-0 00-00002 /amanda/TestBackup-holding/20171116200002/client1._.0.tmp client1 / 0 20171116200002 "" "" "" "" "" "" "" "" 0
writing taper command 'FILE-WRITE worker0-0 00-00002 /amanda/TestBackup-holding/20171116200002/client1._.0.tmp client1 / 0 20171116200002 "" "" "" "" "" "" "" "" 0
' failed: Broken pipe
=====
(There is a line break in the log file just before "' failed".)


===== From /var/log/amanda/server/TestBackup/taper.20171116200517.debug:
Thu Nov 16 20:05:18.502419601 2017: pid 26862: thd-0x4232000: taper: Building type SPLIT_FILE header of 32768-32768 bytes with name='client1' disk='/' dumplevel=0 and blocksize=32768
Thu Nov 16 20:05:22.427709157 2017: pid 26862: thd-0x4232050: taper: no next_filename
Thu Nov 16 20:05:22.427743969 2017: pid 26862: thd-0x4232050: taper: sending XMSG_CRC message
Thu Nov 16 20:05:22.427748905 2017: pid 26862: thd-0x4232050: taper: xfer-source-holding CRC: 2e4f7128 size: 249856000
Thu Nov 16 20:05:22.427757739 2017: pid 26862: thd-0x4232050: taper: xfer_queue_message: MSG: <XMsg@0x7f46b8001bf0 type=XMSG_CRC elt=<XferSourceHolding@0x4230000> version=0>
Thu Nov 16 20:05:22.427767783 2017: pid 26862: thd-0x4232050: taper: xfer-source-holding sending XMSG_DONE message
Thu Nov 16 20:05:22.427773216 2017: pid 26862: thd-0x4232050: taper: xfer_queue_message: MSG: <XMsg@0x7f46b8001f00 type=XMSG_DONE elt=<XferSourceHolding@0x4230000> version=0>
[ *** file ends abruptly here ***]
=====


..... but whether or not that indicates a bug in the taper, it seems like
amflush should not ever try to flush .tmp files from the holding disk...
(right?)



Finally, after this testing I notice that the command_file still has
FLUSH commands for those .tmp files (even though neither the files nor
the containing holding directory now exist). I've run both "amdump" and
"amflush" since then, and tried "amcleanup" as well. Is there any
(good) way to clean up these orphan commands?

===== From /etc/amanda/TestBackup/command_file:
ID 1633
1603 FLUSH TestBackup /amanda/TestBackup-holding/20171116200002/client1._.0.tmp client1 / 20171116200002 0 TestBackup WORKING:17072 TODO
1604 FLUSH TestBackup /amanda/TestBackup-holding/20171116200002/client2._.1.tmp client2 / 20171116200002 0 TestBackup WORKING:17072 TODO
=====

=====
# ls -l /amanda/TestBackup-holding/
total 0
=====


Nathan

----------------------------------------------------------------------------
Nathan Stratton Treadway - nathanst@ontko.com - Mid-Atlantic region
Ray Ontko & Co. - Software consulting services - http://www.ontko.com/
GPG Key: http://www.ontko.com/~nathanst/gpg_key.txt ID: 1023D/ECFB6239
Key fingerprint = 6AD8 485E 20B9 5C71 231C 0C32 15F3 ADCD ECFB 6239
This message was imported via the External PhorumMail Module
Jose M Calhariz
Re: amflush run while amdump underway tries to flush .tmp files
November 19, 2017 07:59AM
Hi,

I have a user that have reported this problem and with a suspection that
amflush could flush the temporary files.

I leave here the link to the bugreport:

https://bugs.debian.org/cgi-bin/bugreport.cgi?bug=881754

Kind regards
Jose M Calhariz


On Fri, Nov 17, 2017 at 12:38:12AM -0500, Nathan Stratton Treadway wrote:
> (Amanda v3.5)
>
> I noticed that Amanda 3.5 no longer aborts amflush if amdump is
> currently running (as older versions of Amanda do).
>
> So out of curiousity I kicked of "amflush TestBackup" while amdump was
> busy dumping to the holding disk... and I discovered that amflush
> actually tries to go ahead and flush the ".tmp" file files that it finds
> in the holding directory:
>
> ===== From /var/log/amanda/server/TestBackup/amflush.20171116200510.debug:
> Thu Nov 16 20:05:17.590062176 2017: pid 26860: thd-0x2f07e00: amflush: flushing /amanda/TestBackup-holding/20171116200002/client1._.0.tmp
> Thu Nov 16 20:05:17.590096226 2017: pid 26860: thd-0x2f07e00: amflush: flushing /amanda/TestBackup-holding/20171116200002/client2._.1.tmp
> =====
>
> In this case the taper failed (and thus the amflush didn't actually do
> anything with the .tmp files)....:
>
> ===== From /var/log/amanda/TestBackup/amdump.1:
> driver: send-cmd time 14.132 to taper0: FILE-WRITE worker0-0 00-00002 /amanda/TestBackup-holding/20171116200002/client1._.0.tmp client1 / 0 20171116200002 "" "" "" "" "" "" "" "" 0
> writing taper command 'FILE-WRITE worker0-0 00-00002 /amanda/TestBackup-holding/20171116200002/client1._.0.tmp client1 / 0 20171116200002 "" "" "" "" "" "" "" "" 0
> ' failed: Broken pipe
> =====
> (There is a line break in the log file just before "' failed".)
>
>
> ===== From /var/log/amanda/server/TestBackup/taper.20171116200517.debug:
> Thu Nov 16 20:05:18.502419601 2017: pid 26862: thd-0x4232000: taper: Building type SPLIT_FILE header of 32768-32768 bytes with name='client1' disk='/' dumplevel=0 and blocksize=32768
> Thu Nov 16 20:05:22.427709157 2017: pid 26862: thd-0x4232050: taper: no next_filename
> Thu Nov 16 20:05:22.427743969 2017: pid 26862: thd-0x4232050: taper: sending XMSG_CRC message
> Thu Nov 16 20:05:22.427748905 2017: pid 26862: thd-0x4232050: taper: xfer-source-holding CRC: 2e4f7128 size: 249856000
> Thu Nov 16 20:05:22.427757739 2017: pid 26862: thd-0x4232050: taper: xfer_queue_message: MSG: <XMsg@0x7f46b8001bf0 type=XMSG_CRC elt=<XferSourceHolding@0x4230000> version=0>
> Thu Nov 16 20:05:22.427767783 2017: pid 26862: thd-0x4232050: taper: xfer-source-holding sending XMSG_DONE message
> Thu Nov 16 20:05:22.427773216 2017: pid 26862: thd-0x4232050: taper: xfer_queue_message: MSG: <XMsg@0x7f46b8001f00 type=XMSG_DONE elt=<XferSourceHolding@0x4230000> version=0>
> [ *** file ends abruptly here ***]
> =====
>
>
> .... but whether or not that indicates a bug in the taper, it seems like
> amflush should not ever try to flush .tmp files from the holding disk...
> (right?)
>
>
>
> Finally, after this testing I notice that the command_file still has
> FLUSH commands for those .tmp files (even though neither the files nor
> the containing holding directory now exist). I've run both "amdump" and
> "amflush" since then, and tried "amcleanup" as well. Is there any
> (good) way to clean up these orphan commands?
>
> ===== From /etc/amanda/TestBackup/command_file:
> ID 1633
> 1603 FLUSH TestBackup /amanda/TestBackup-holding/20171116200002/client1._.0.tmp client1 / 20171116200002 0 TestBackup WORKING:17072 TODO
> 1604 FLUSH TestBackup /amanda/TestBackup-holding/20171116200002/client2._.1.tmp client2 / 20171116200002 0 TestBackup WORKING:17072 TODO
> =====
>
> =====
> # ls -l /amanda/TestBackup-holding/
> total 0
> =====
>
>
> Nathan
>
> ----------------------------------------------------------------------------
> Nathan Stratton Treadway - nathanst@ontko.com - Mid-Atlantic region
> Ray Ontko & Co. - Software consulting services - http://www.ontko.com/
> GPG Key: http://www.ontko.com/~nathanst/gpg_key.txt ID: 1023D/ECFB6239
> Key fingerprint = 6AD8 485E 20B9 5C71 231C 0C32 15F3 ADCD ECFB 6239
>

--
--
Todo homem luta com mais bravura por seus interesses do que
seus direitos.
-- Napoleao
This message was imported via the External PhorumMail Module
Jean-Louis Martineau
Re: amflush run while amdump underway tries to flush .tmp files
November 20, 2017 11:59AM
Each process should take a lock on the holding directory (a pid file),
The attached path fix it.

Please try it.


On 17/11/17 12:38 AM, Nathan Stratton Treadway wrote:
> (Amanda v3.5)
>
> I noticed that Amanda 3.5 no longer aborts amflush if amdump is
> currently running (as older versions of Amanda do).
>
> So out of curiousity I kicked of "amflush TestBackup" while amdump was
> busy dumping to the holding disk... and I discovered that amflush
> actually tries to go ahead and flush the ".tmp" file files that it finds
> in the holding directory:
>
> ===== From /var/log/amanda/server/TestBackup/amflush.20171116200510.debug:
> Thu Nov 16 20:05:17.590062176 2017: pid 26860: thd-0x2f07e00: amflush:
> flushing /amanda/TestBackup-holding/20171116200002/client1._.0.tmp
> Thu Nov 16 20:05:17.590096226 2017: pid 26860: thd-0x2f07e00: amflush:
> flushing /amanda/TestBackup-holding/20171116200002/client2._.1.tmp
> =====
>
> In this case the taper failed (and thus the amflush didn't actually do
> anything with the .tmp files)....:
>
> ===== From /var/log/amanda/TestBackup/amdump.1:
> driver: send-cmd time 14.132 to taper0: FILE-WRITE worker0-0 00-00002
> /amanda/TestBackup-holding/20171116200002/client1._.0.tmp client1 / 0
> 20171116200002 "" "" "" "" "" "" "" "" 0
> writing taper command 'FILE-WRITE worker0-0 00-00002
> /amanda/TestBackup-holding/20171116200002/client1._.0.tmp client1 / 0
> 20171116200002 "" "" "" "" "" "" "" "" 0
> ' failed: Broken pipe
> =====
> (There is a line break in the log file just before "' failed".)
>
>
> ===== From /var/log/amanda/server/TestBackup/taper.20171116200517.debug:
> Thu Nov 16 20:05:18.502419601 2017: pid 26862: thd-0x4232000: taper:
> Building type SPLIT_FILE header of 32768-32768 bytes with
> name='client1' disk='/' dumplevel=0 and blocksize=32768
> Thu Nov 16 20:05:22.427709157 2017: pid 26862: thd-0x4232050: taper:
> no next_filename
> Thu Nov 16 20:05:22.427743969 2017: pid 26862: thd-0x4232050: taper:
> sending XMSG_CRC message
> Thu Nov 16 20:05:22.427748905 2017: pid 26862: thd-0x4232050: taper:
> xfer-source-holding CRC: 2e4f7128 size: 249856000
> Thu Nov 16 20:05:22.427757739 2017: pid 26862: thd-0x4232050: taper:
> xfer_queue_message: MSG: <XMsg@0x7f46b8001bf0 type=XMSG_CRC
> elt=<XferSourceHolding@0x4230000> version=0>
> Thu Nov 16 20:05:22.427767783 2017: pid 26862: thd-0x4232050: taper:
> xfer-source-holding sending XMSG_DONE message
> Thu Nov 16 20:05:22.427773216 2017: pid 26862: thd-0x4232050: taper:
> xfer_queue_message: MSG: <XMsg@0x7f46b8001f00 type=XMSG_DONE
> elt=<XferSourceHolding@0x4230000> version=0>
> [ *** file ends abruptly here ***]
> =====
>
>
> .... but whether or not that indicates a bug in the taper, it seems like
> amflush should not ever try to flush .tmp files from the holding disk...
> (right?)
>
>
>
> Finally, after this testing I notice that the command_file still has
> FLUSH commands for those .tmp files (even though neither the files nor
> the containing holding directory now exist). I've run both "amdump" and
> "amflush" since then, and tried "amcleanup" as well. Is there any
> (good) way to clean up these orphan commands?
No, you must manually remove them. Do it when no other amanda processes
are running.

Jean-Louis
>
> ===== From /etc/amanda/TestBackup/command_file:
> ID 1633
> 1603 FLUSH TestBackup
> /amanda/TestBackup-holding/20171116200002/client1._.0.tmp client1 /
> 20171116200002 0 TestBackup WORKING:17072 TODO
> 1604 FLUSH TestBackup
> /amanda/TestBackup-holding/20171116200002/client2._.1.tmp client2 /
> 20171116200002 0 TestBackup WORKING:17072 TODO
> =====
>
> =====
> # ls -l /amanda/TestBackup-holding/
> total 0
> =====
>
>
> Nathan
>
> ----------------------------------------------------------------------------
> Nathan Stratton Treadway - nathanst@ontko.com - Mid-Atlantic region
> Ray Ontko & Co. - Software consulting services - http://www.ontko.com/
> http://www.ontko.com/
> GPG Key: http://www.ontko.com/~nathanst/gpg_key.txt
> http://www.ontko.com/~nathanst/gpg_key.txt
> ID: 1023D/ECFB6239
> Key fingerprint = 6AD8 485E 20B9 5C71 231C 0C32 15F3 ADCD ECFB 6239
This message is the property of CARBONITE, INC. and may contain confidential or privileged information.
If this message has been delivered to you by mistake, then do not copy or deliver this message to anyone. Instead, destroy it and notify me by reply e-mail
This message was imported via the External PhorumMail Module
Sorry, only registered users may post in this forum.

Click here to login