Re: Amvault hangs while trying to vault backups from holding disk.

I do the same as you for amvault command line invocation i.e.
--latest-fulls --dest-storage.  However I am vaulting from the vtl
directories only, not the holding disk.  Without some details on your
amanda.conf I don't know if that's part of the problem but you appear to
never get to loading a (vtl) slot to read /from/.

My output goes like this:


Sat Oct 09 13:00:43.952721726 2021: pid 4031574: thd-0x558e5a458a00:
amvault: Amanda::Taper::Scan::traditional stage 1: search for oldest
reusable volume
Sat Oct 09 13:00:43.957348285 2021: pid 4031574: thd-0x558e5a458a00:
amvault: Amanda::Taper::Scan::traditional oldest reusable volume is
'Vault-1'
Sat Oct 09 13:00:43.957795520 2021: pid 4031574: thd-0x558e5a458a00:
amvault: Amanda::Taper::Scan::traditional changer is not
fast-searchable; skipping to stage 2
Sat Oct 09 13:00:43.958013506 2021: pid 4031574: thd-0x558e5a458a00:
amvault: Amanda::Taper::Scan::traditional stage 2: scan for any reusable
volume
Sat Oct 09 13:00:43.958171915 2021: pid 4031574: thd-0x558e5a458a00:
amvault: warning: "/dev/nst0" uses deprecated device naming convention;
using "tape:/dev/nst0" instead.

Sat Oct 09 13:00:43.960571475 2021: pid 4031574: thd-0x558e5a458a00:
amvault: Device is in fixed block size of 32768
Sat Oct 09 13:00:43.965927459 2021: pid 4031574: thd-0x558e5a458a00:
amvault: Slot 1 with label Vault-7 is usable
Sat Oct 09 13:00:43.966108460 2021: pid 4031574: thd-0x558e5a458a00:
amvault: Amanda::Taper::Scan::traditional result: 'Vault-7' on /dev/nst0
slot 1, mode 2
Sat Oct 09 13:00:43.966999371 2021: pid 4031574: thd-0x558e5a458a00:
amvault: Amanda::Recovery::Clerk: loading volume 'vtl1'
Sat Oct 09 13:00:43.967333303 2021: pid 4031574: thd-0x558e5a458a00:
amvault: find_volume labeled 'vtl1'
Sat Oct 09 13:00:44.591343047 2021: pid 4031574: thd-0x558e5a458a00:
amvault: parse_inventory: load slot 1 with label 'vtl1'
Sat Oct 09 13:00:44.591609582 2021: pid 4031574: thd-0x558e5a458a00:
amvault:
/usr/lib/x86_64-linux-gnu/amanda/perl/Amanda/Recovery/Scan.pm:307:info:1200000
slot 1
Sat Oct 09 13:00:44.597276267 2021: pid 4031574: thd-0x558e5a458a00:
amvault: dir_name: /amandatapes/slot1/
Sat Oct 09 13:00:44.656621198 2021: pid 4031574: thd-0x558e5a458a00:
amvault:
/usr/lib/x86_64-linux-gnu/amanda/perl/Amanda/Recovery/Scan.pm:459:info:1200001
vtl1
Sat Oct 09 13:00:44.664182154 2021: pid 4031574: thd-0x558e5a458a00:
amvault: Amanda::Recovery::Clerk: successfully located first part for
recovery
Sat Oct 09 13:00:44.664832388 2021: pid 4031574: thd-0x558e5a458a00:
amvault: Amanda::Taper::Scribe preparing to write, part size 0, using
LEOM detection (no caching) (splitter)  (LEOM supported)
Sat Oct 09 13:00:44.665859394 2021: pid 4031574: thd-0x558e5a458a00:
amvault: Starting <Xfer@0x558e5c0382e0
(<XferSourceRecovery@0x558e5c151000> ->
<XferDestTaperSplitter@0x558e5c2bd0b0>)>



On 2021-10-11 6:51 a.m., Rami Lehti wrote:
> Hi all,
>
> I have a setup where I have a holding disk and vtapes. Then I try to use
> amvault to copy the latest full backups to tape.
> This works if I use amvault's --fulls-only with --src-storage parameter
> and use the vtapes as the source.
> But if I try to vault backups that are still on the holding disk by
> using --latest-fulls. Amvault tries to copy the first full to tape but
> hangs indefinitely.
>
> The full redacted command line is
> sudo -u backup amvault --dest-storage tapelibrary --latest-fulls backupset
>
> Here's the relevant part of the redacted log file.
>
> ma loka 11 09:23:13.626028751 2021: pid 1126324: thd-0x562b5502a400:
> amvault: Amanda::Taper::Scan::traditional result: 'redacted-vault-1014'
> on tape:/dev/nst0 slot 8, mode 2
> ma loka 11 09:23:13.627741696 2021: pid 1126324: thd-0x562b5502a400:
> amvault:
> /usr/lib/x86_64-linux-gnu/amanda/perl/Amanda/Vault.pm:1196:info:2500017
> Reading '/backup/amanda/holding/20211004180502/<redacted>._.0': FILE:
> date 20211004180502 host <redacted> disk / lev 0 comp .gz program
> /bin/tar crypt enc client_encrypt /usr/sbin/amcrypt-ossl
> client_decrypt_option -d
> ma loka 11 09:23:13.627958672 2021: pid 1126324: thd-0x562b5502a400:
> amvault: Amanda::Recovery::Clerk: successfully located holding file for
> recovery
> ma loka 11 09:23:13.628001640 2021: pid 1126324: thd-0x562b5502a400:
> amvault: start_recovery called
> ma loka 11 09:23:13.628634814 2021: pid 1126324: thd-0x562b5502a400:
> amvault: Amanda::Taper::Scribe preparing to write, part size 0, using
> LEOM detection (no caching) (splitter)  (LEOM supported)
> ma loka 11 09:23:13.639842536 2021: pid 1126324: thd-0x562b5502a400:
> amvault: Starting <Xfer@0x562b572a4850
> (<XferSourceHolding@0x562b57f15010> ->
> <XferDestTaperSplitter@0x562b57fdf060>)>
> ma loka 11 09:23:13.639865559 2021: pid 1126324: thd-0x562b5502a400:
> amvault: Final linkage: <XferSourceHolding@0x562b57f15010> -(MEM_RING)->
> <XferDestTaperSplitter@0x562b57fdf060>
> ma loka 11 09:23:13.639986931 2021: pid 1126324: thd-0x562b5502a400:
> amvault: Amanda::Recovery::Clerk: starting recovery
> ma loka 11 09:23:13.641060521 2021: pid 1126324: thd-0x562b5502a400:
> amvault: start_recovery called
>
> And then nothing.
>
> Is this a bug or am I doing something wrong?
>
> Kind regards,
> Rami Lehti
>