amvault hanging
Orion Poplawski <[email protected]>
| Newsgroups | gmane.comp.archivers.amanda.devel |
|---|---|
| Message-ID | <[email protected]> |
Just updated my backup server to EL7.3 and built amanda-3.4.4 on it. Trying
to run amvault but it's hanging. strace shows:
[pid 1015] futex(0x36f6c58, FUTEX_WAIT_PRIVATE, 0, NULL <unfinished ...>
[pid 1014] futex(0x3c605a8, FUTEX_WAIT_PRIVATE, 0, NULL <unfinished ...>
[pid 1006] restart_syscall(<... resuming interrupted call ...>) = 0
[pid 1006] lseek(7, 0, SEEK_SET) = 0
[pid 1006] lseek(7, 0, SEEK_CUR) = 0
[pid 1006] write(7, "0 ", 6) = 6
[pid 1006] poll([{fd=4, events=POLLIN}], 1, 14999) = 0 (Timeout)
[pid 1006] lseek(7, 0, SEEK_SET) = 0
[pid 1006] lseek(7, 0, SEEK_CUR) = 0
[pid 1006] write(7, "0 ", 6) = 6
[pid 1006] poll([{fd=4, events=POLLIN}], 1, 15000
amvault 1006 amandabackup 0r CHR 1,3 0t0 2052 /dev/null
amvault 1006 amandabackup 1w REG 253,57 34042 4864
/var/lib/amanda/offsite-vault.log
amvault 1006 amandabackup 2w REG 253,57 34042 4864
/var/lib/amanda/offsite-vault.log
amvault 1006 amandabackup 3w REG 253,57 0 14693639
/var/lib/amanda/Offsite/amdump.20170518155701
amvault 1006 amandabackup 4u a_inode 0,9 0 6935 [eventfd]
amvault 1006 amandabackup 5r REG 8,49 6288303908968 976684770
/mnt/amanda/data/00005.alxdisk1ib._export_clouds.0
amvault 1006 amandabackup 6r REG 253,3 68654 1062575
/usr/share/perl5/vendor_perl/JSON.pm
amvault 1006 amandabackup 7u REG 253,23 6 3673456
/var/log/amanda/taper_status_file_PP1UyF
amvault 1006 amandabackup 8u REG 8,17 32768 212626
/mnt/vault/slot1/00001.alxdisk1ib._export_clouds.0
amvault 1006 amandabackup 10w REG 253,23 5300 50721
/var/log/amanda/server/Offsite/amvault.20170518155701.debug
So it looks like it's waiting for something from it's eventfd ? Not sure what
to check for now.
# cat /var/log/amanda/server/Offsite/amvault.20170518155701.debug
Thu May 18 15:57:01.356176952 2017: pid 1006: thd-0x2246800: amvault: pid 1006
ruid 27120 euid 27120 version 3.4.4: start at Thu May 18 15:57:01 2017
Thu May 18 15:57:01.356276295 2017: pid 1006: thd-0x2246800: amvault:
Arguments: --exact-match --fulls-only Offsite alxdisk1ib /export/clouds
20170513031353 0
Thu May 18 15:57:01.357081813 2017: pid 1006: thd-0x2246800: amvault: reading
config file /etc/amanda/Offsite/amanda.conf
Thu May 18 15:57:01.357208800 2017: pid 1006: thd-0x2246800: amvault: reading
config file /etc/amanda/Offsite/../vault.conf
Thu May 18 15:57:01.357554736 2017: pid 1006: thd-0x2246800: amvault: reading
config file /etc/amanda/Offsite/../dumptypes.conf
Thu May 18 15:57:01.360352028 2017: pid 1006: thd-0x2246800: amvault: pid 1006
ruid 27120 euid 27120 version 3.4.4: rename at Thu May 18 15:57:01 2017
Thu May 18 15:57:01.368312889 2017: pid 1006: thd-0x2246800: amvault:
/usr/lib64/perl5/vendor_perl/Amanda/Vault.pm:218:info:2500001 The amdump log
file is '/var/lib/amanda/Offsite/amdump.20170518155701'
Thu May 18 15:57:01.368531509 2017: pid 1006: thd-0x2246800: amvault:
/usr/lib64/perl5/vendor_perl/Amanda/Vault.pm:224:info:2500000 The trace log
file is '/var/lib/amanda/Offsite/log.20170518155701.0'
Thu May 18 15:57:01.374962138 2017: pid 1006: thd-0x2246800: amvault:
dir_name: /mnt/amanda/data/
Thu May 18 15:57:01.425375866 2017: pid 1006: thd-0x2246800: amvault:
chg-disk: Dir /mnt/vault
Thu May 18 15:57:01.425398497 2017: pid 1006: thd-0x2246800: amvault:
chg-disk: Using statefile '/mnt/vault/state'
Thu May 18 15:57:01.432150840 2017: pid 1006: thd-0x2246800: amvault:
Amanda::Taper::Scan::traditional stage 1: search for oldest reusable volume
Thu May 18 15:57:01.432566852 2017: pid 1006: thd-0x2246800: amvault:
Amanda::Taper::Scan::traditional no oldest reusable volume
Thu May 18 15:57:01.432721323 2017: pid 1006: thd-0x2246800: amvault:
Amanda::Taper::Scan::traditional stage 2: scan for any reusable volume
Thu May 18 15:57:01.433899554 2017: pid 1006: thd-0x2246800: amvault:
dir_name: /mnt/vault/slot1/
Thu May 18 15:57:01.434413898 2017: pid 1006: thd-0x2246800: amvault: Device
file:/mnt/vault/slot1 error = 'File 0 not found'
Thu May 18 15:57:01.434445620 2017: pid 1006: thd-0x2246800: amvault: Device
file:/mnt/vault/slot1 setting status flag(s): DEVICE_STATUS_VOLUME_UNLABELED
Thu May 18 15:57:01.435240699 2017: pid 1006: thd-0x2246800: amvault: Slot 1
without label can be labeled
Thu May 18 15:57:01.436413235 2017: pid 1006: thd-0x2246800: amvault:
Amanda::Taper::Scan::traditional result: 'OVault-045' on file:/mnt/vault/slot1
slot 1, mode 2
Thu May 18 15:57:01.436991733 2017: pid 1006: thd-0x2246800: amvault:
Amanda::Recovery::Clerk: loading volume 'Offsite-01'
Thu May 18 15:57:01.437282951 2017: pid 1006: thd-0x2246800: amvault:
find_volume labeled 'Offsite-01'
Thu May 18 15:57:01.437408911 2017: pid 1006: thd-0x2246800: amvault:
parse_inventory: load slot 1
Thu May 18 15:57:01.437564433 2017: pid 1006: thd-0x2246800: amvault:
/usr/lib64/perl5/vendor_perl/Amanda/Recovery/Scan.pm:420:info:1200000 slot 1
Thu May 18 15:57:01.437840627 2017: pid 1006: thd-0x2246800: amvault:
dir_name: /mnt/amanda/data/
Thu May 18 15:57:01.439155575 2017: pid 1006: thd-0x2246800: amvault:
/usr/lib64/perl5/vendor_perl/Amanda/Recovery/Scan.pm:459:info:1200001 Offsite-01
Thu May 18 15:57:05.163649337 2017: pid 1006: thd-0x2246800: amvault:
Amanda::Recovery::Clerk: successfully located first part for recovery
Thu May 18 15:57:05.164245159 2017: pid 1006: thd-0x2246800: amvault:
Amanda::Taper::Scribe preparing to write, part size 0, using LEOM detection
(no caching) (splitter) (LEOM supported)
Thu May 18 15:57:05.165573737 2017: pid 1006: thd-0x2246800: amvault: Starting
<Xfer@0x3ac7e60 (<XferSourceRecovery@0x3c68000> ->
<XferDestTaperSplitter@0x3c69000>)>
Thu May 18 15:57:05.165636216 2017: pid 1006: thd-0x2246800: amvault: Final
linkage: <XferSourceRecovery@0x3c68000> -(PULL_BUFFER)->
<XferElementGlue@0x3c6d030> -(PUSH_BUFFER)-> <XferDestTaperSplitter@0x3c69000>
Thu May 18 15:57:05.165656538 2017: pid 1006: thd-0x2246800: amvault:
setup_impl: 3, 5
Thu May 18 15:57:05.165790153 2017: pid 1006: thd-0x2246800: amvault:
xfer_queue_message: MSG: <XMsg@0x3c5f700 type=XMSG_READY
elt=<XferSourceRecovery@0x3c68000> version=0>
Thu May 18 15:57:05.165849314 2017: pid 1006: thd-0x2246800: amvault:
Amanda::Recovery::Clerk: starting recovery
Thu May 18 15:57:05.165998194 2017: pid 1006: thd-0x3c5f850: amvault:
pull_and_push
Thu May 18 15:57:05.170351738 2017: pid 1006: thd-0x2246800: amvault: Building
type TAPESTART header of 32768-32768 bytes with name='OVault-045' disk=''
dumplevel=0 and blocksize=32768
Thu May 18 15:57:05.173511208 2017: pid 1006: thd-0x3c5f800: amvault: Building
type FILE header of 32768-32768 bytes with name='alxdisk1ib'
disk='/export/clouds' dumplevel=0 and blocksize=32768
Thu May 18 15:57:05.174957340 2017: pid 1006: thd-0x2246800: amvault:
/usr/lib64/perl5/vendor_perl/Amanda/Vault.pm:1177:info:2500016 Reading
Offsite-01:5: FILE: date 20170513031353 host alxdisk1ib disk /export/clouds
lev 0 comp cust program APPLICATION server_custom_compress
/usr/local/bin/pigz-fast
Thu May 18 15:57:05.175402191 2017: pid 1006: thd-0x2246800: amvault:
Amanda::Recovery::Clerk: reading file 5 on 'Offsite-01'
--
Orion Poplawski
Technical Manager 720-772-5637
NWRA, Boulder/CoRA Office FAX: 303-415-9702
3380 Mitchell Lane [email protected]
Boulder, CO 80301 http://www.nwra.com