amrecover cannot restore from multiple tapes, it hangs after the second tape is requested.
Ubuntu 20.04.3 LTS Amanda 3.5.1-2build3 The dumps were made with amgtar and the DLE spans multiple tapes. Restoring selected files from the first tape succeeds but when the next tape is provided the amrecover program hangs indefinitely and the tape is not read. -- amrecover terminal follows -- > amrecover archive AMRECOVER Version 3.5.1. Contacting server on localhost ... 220 ubuntu AMANDA index server (3.5.1) ready. Setting restore date to today (2022-01-03) 200 Working date set to 2022-01-03. 200 Config set to archive. 200 Dump host set to localhost. Use the setdisk command to choose dump disk to recover amrecover> setdisk tank 200 Disk set to tank. amrecover> add random.bin Added file /random.bin amrecover> extract Extracting files using tape drive chg-single:tape:/dev/st1 on host localhost. The following tapes are needed: Archive-01 Archive-02 Archive-03 Archive-04 Archive-05 Extracting files using tape drive chg-single:tape:/dev/st1 on host localhost.Load tape Archive-01 now Continue [?/Y/n/s/d]? y Restoring files into directory /root Continue [?/Y/n]? y ./random.bin 179360 kb Source Volume 'Archive-02' not found Load tape Archive-02 now Continue [?/Y/n/d]? y -- amidxtaped.debug follows -- Mon Jan 03 04:08:18.881163446 2022: pid 28841: thd-0x563436fe5000: amidxtaped: pid 28841 ruid 34 euid 34 version 3.5.1: start at Mon Jan 3 04:08:18 2022 Mon Jan 03 04:08:18.883498914 2022: pid 28841: thd-0x563436fe5000: amidxtaped: CTL << FEATURES=ffffffff9efefbfffffffffffffff3fffbf71f Mon Jan 03 04:08:18.883731487 2022: pid 28841: thd-0x563436fe5000: amidxtaped: CTL << CONFIG=archive Mon Jan 03 04:08:18.883836138 2022: pid 28841: thd-0x563436fe5000: amidxtaped: CTL << LABEL=archive:Archive-01:1;archive:Archive-02:1;archive:Archive-03:1;archive:Archive-04:1;archive:Archive-05:1,2 Mon Jan 03 04:08:18.883858449 2022: pid 28841: thd-0x563436fe5000: amidxtaped: CTL << FSF=1 Mon Jan 03 04:08:18.883878489 2022: pid 28841: thd-0x563436fe5000: amidxtaped: CTL << HEADER Mon Jan 03 04:08:18.883914179 2022: pid 28841: thd-0x563436fe5000: amidxtaped: CTL << DEVICE=chg-single:tape:/dev/st1 Mon Jan 03 04:08:18.883941020 2022: pid 28841: thd-0x563436fe5000: amidxtaped: CTL << HOST=^localhost$ Mon Jan 03 04:08:18.883962280 2022: pid 28841: thd-0x563436fe5000: amidxtaped: CTL << DISK=^tank$ Mon Jan 03 04:08:18.883991790 2022: pid 28841: thd-0x563436fe5000: amidxtaped: CTL << DATESTAMP=20220103040525 Mon Jan 03 04:08:18.884008130 2022: pid 28841: thd-0x563436fe5000: amidxtaped: CTL << END Mon Jan 03 04:08:18.884041801 2022: pid 28841: thd-0x563436fe5000: amidxtaped: their_features have fe_amrecover_stream_state Mon Jan 03 04:08:18.884146322 2022: pid 28841: thd-0x563436fe5000: amidxtaped: reading config file /etc/amanda/archive/amanda.conf Mon Jan 03 04:08:18.884164653 2022: pid 28841: thd-0x563436fe5000: amidxtaped: reading config file /etc/amanda/archive/../amanda-defaults.conf Mon Jan 03 04:08:18.884841291 2022: pid 28841: thd-0x563436fe5000: amidxtaped: pid 28841 ruid 34 euid 34 version 3.5.1: rename at Mon Jan 3 04:08:18 2022 Mon Jan 03 04:08:18.885158484 2022: pid 28841: thd-0x563436fe5000: amidxtaped: beginning trace log: /amanda/archive/state/log/log.20220103040818.0 Mon Jan 03 04:08:18.885599660 2022: pid 28841: thd-0x563436fe5000: amidxtaped: new Amanda::Changer::Error: type='fatal', message='Storage 'chg-single:tape:/dev/st1' not found' Mon Jan 03 04:08:18.898319015 2022: pid 28841: thd-0x563436fe5000: amidxtaped: Amanda::Recovery::Clerk: loading volume 'Archive-01' Mon Jan 03 04:08:18.898532637 2022: pid 28841: thd-0x563436fe5000: amidxtaped: find_volume labeled 'Archive-01' Mon Jan 03 04:08:18.898598568 2022: pid 28841: thd-0x563436fe5000: amidxtaped: parse_inventory: load slot 1 Mon Jan 03 04:08:18.898701889 2022: pid 28841: thd-0x563436fe5000: amidxtaped: /usr/lib/x86_64-linux-gnu/amanda/perl/Amanda/Recovery/Scan.pm:420:info:1200000 slot 1 Mon Jan 03 04:08:19.003198757 2022: pid 28841: thd-0x563436fe5000: amidxtaped: Device tape:/dev/st1 error = 'Tape device /dev/st1 is not ready or is empty' Mon Jan 03 04:08:19.003258188 2022: pid 28841: thd-0x563436fe5000: amidxtaped: Device tape:/dev/st1 setting status flag(s): DEVICE_STATUS_VOLUME_MISSING Mon Jan 03 04:08:19.003914906 2022: pid 28841: thd-0x563436fe5000: amidxtaped: /usr/lib/x86_64-linux-gnu/amanda/perl/Amanda/Recovery/Scan.pm:471:error:1200002 Tape device /dev/st1 is not ready or is empty Mon Jan 03 04:08:19.004249740 2022: pid 28841: thd-0x563436fe5000: amidxtaped: new Amanda::Changer::Error: type='fatal', message='Tape device /dev/st1 is not ready or is empty' Mon Jan 03 04:08:19.005083711 2022: pid 28841: thd-0x563436fe5000: amidxtaped: CTL >> MESSAGE Tape device /dev/st1 is not ready or is empty Mon Jan 03 04:08:19.005278423 2022: pid 28841: thd-0x563436fe5000: amidxtaped: CTL >> FEEDME Archive-01 Mon Jan 03 04:08:35.400118137 2022: pid 28841: thd-0x563436fe5000: amidxtaped: CTL << TAPE chg-single:tape:/dev/st1 Mon Jan 03 04:08:35.400709374 2022: pid 28841: thd-0x563436fe5000: amidxtaped: parse_inventory: load slot 1 Mon Jan 03 04:08:35.400795006 2022: pid 28841: thd-0x563436fe5000: amidxtaped: /usr/lib/x86_64-linux-gnu/amanda/perl/Amanda/Recovery/Scan.pm:420:info:1200000 slot 1 Mon Jan 03 04:08:35.478839892 2022: pid 28841: thd-0x563436fe5000: amidxtaped: Device is in variable block size Mon Jan 03 04:08:35.481812868 2022: pid 28841: thd-0x563436fe5000: amidxtaped: /usr/lib/x86_64-linux-gnu/amanda/perl/Amanda/Recovery/Scan.pm:459:info:1200001 Archive-01 Mon Jan 03 04:08:35.482067100 2022: pid 28841: thd-0x563436fe5000: amidxtaped: ignoring spurious Amanda::Recovery::Scan abort call Mon Jan 03 04:08:35.485652593 2022: pid 28841: thd-0x563436fe5000: amidxtaped: Amanda::Recovery::Clerk: successfully located first part for recovery Mon Jan 03 04:08:35.513143630 2022: pid 28841: thd-0x563436fe5000: amidxtaped: Building type SPLIT_FILE header of 128-32768 bytes with name='localhost' disk='tank' dumplevel=0 and blocksize=0 Mon Jan 03 04:08:35.513391003 2022: pid 28841: thd-0x563436fe5000: amidxtaped: Building type FILE header of 128-32768 bytes with name='localhost' disk='tank' dumplevel=0 and blocksize=32768 Mon Jan 03 04:08:35.513423853 2022: pid 28841: thd-0x563436fe5000: amidxtaped: CTL >> HEADER-SEND-SIZE 884 Mon Jan 03 04:08:35.513749877 2022: pid 28841: thd-0x563436fe5000: amidxtaped: CTL << HEADER-READY Mon Jan 03 04:08:37.016151539 2022: pid 28841: thd-0x563436fe5000: amidxtaped: CTL << HEADER-DONE Mon Jan 03 04:08:37.016376002 2022: pid 28841: thd-0x563436fe5000: amidxtaped: CTL >> STATE-SEND Mon Jan 03 04:08:37.016716656 2022: pid 28841: thd-0x563436fe5000: amidxtaped: CTL << STATE-READY Mon Jan 03 04:08:37.021603914 2022: pid 28841: thd-0x563436fe5000: amidxtaped: CTL << STATE-DONE Mon Jan 03 04:08:37.021689844 2022: pid 28841: thd-0x563436fe5000: amidxtaped: CTL >> USE-DAR YES Mon Jan 03 04:08:37.021917388 2022: pid 28841: thd-0x563436fe5000: amidxtaped: CTL << USE-DAR YES Mon Jan 03 04:08:37.022002478 2022: pid 28841: thd-0x563436fe5000: amidxtaped: CTL << AVAIL-DATAPATH AMANDA Mon Jan 03 04:08:37.022305032 2022: pid 28841: thd-0x563436fe5000: amidxtaped: Starting <Xfer@0x563436be7dd0 (<XferSourceRecovery@0x563437f6a000> -> <XferDestFd@0x5634382ed800>)> Mon Jan 03 04:08:37.022339812 2022: pid 28841: thd-0x563436fe5000: amidxtaped: Final linkage: <XferSourceRecovery@0x563437f6a000> -(PULL_BUFFER)-> <XferElementGlue@0x5634382ef010> -(WRITEFD)-> <XferDestFd@0x5634382ed800> Mon Jan 03 04:08:37.022379443 2022: pid 28841: thd-0x563436fe5000: amidxtaped: setup_impl: 3, 2 Mon Jan 03 04:08:37.022460874 2022: pid 28841: thd-0x563436fe5000: amidxtaped: xfer_queue_message: MSG: <XMsg@0x5634382ee960 type=XMSG_READY elt=<XferSourceRecovery@0x563437f6a000> version=0> Mon Jan 03 04:08:37.022496014 2022: pid 28841: thd-0x563436fe5000: amidxtaped: CTL >> USE-DATAPATH AMANDA Mon Jan 03 04:08:37.022567735 2022: pid 28841: thd-0x563437e8b980: amidxtaped: pull_and_write Mon Jan 03 04:08:37.024087873 2022: pid 28841: thd-0x563436fe5000: amidxtaped: CTL << DATAPATH-OK Mon Jan 03 04:08:37.026990268 2022: pid 28841: thd-0x563436fe5000: amidxtaped: CTL >> DATA-SEND Mon Jan 03 04:08:37.027291452 2022: pid 28841: thd-0x563436fe5000: amidxtaped: CTL << DATA-READY Mon Jan 03 04:08:37.027460834 2022: pid 28841: thd-0x563436fe5000: amidxtaped: Amanda::Recovery::Clerk: starting recovery Mon Jan 03 04:08:37.029324915 2022: pid 28841: thd-0x563436fe5000: amidxtaped: Amanda::Recovery::Clerk: reading file 1 on 'Archive-01' Mon Jan 03 04:08:37.034674349 2022: pid 28841: thd-0x563436fe5000: amidxtaped: ctl line: DAR 0:-1 Mon Jan 03 04:08:37.035189184 2022: pid 28841: thd-0x563436fe5000: amidxtaped: Amanda::Recovery::Clerk: reading file 1 on 'Archive-01' Mon Jan 03 04:08:37.035378898 2022: pid 28841: thd-0x563436fe5000: amidxtaped: ctl line: DAR-DONE Mon Jan 03 04:08:38.398461688 2022: pid 28841: thd-0x563437e8b980: amidxtaped: Device tape:/dev/st1 error = 'EOF' Mon Jan 03 04:08:38.398487189 2022: pid 28841: thd-0x563437e8b980: amidxtaped: xfer_queue_message: MSG: <XMsg@0x7f35ac001cf0 type=XMSG_CRC elt=<XferSourceRecovery@0x563437f6a000> version=0> Mon Jan 03 04:08:38.398501899 2022: pid 28841: thd-0x563437e8b980: amidxtaped: xfer_queue_message: MSG: <XMsg@0x7f35ac002f10 type=XMSG_PART_DONE elt=<XferSourceRecovery@0x563437f6a000> version=0> Mon Jan 03 04:08:38.398814973 2022: pid 28841: thd-0x563436fe5000: amidxtaped: source_crc: 4298717e:262144000 Mon Jan 03 04:08:38.398898813 2022: pid 28841: thd-0x563436fe5000: amidxtaped: Amanda::Recovery::Clerk: done reading file 1 on 'Archive-01' Mon Jan 03 04:08:38.399534831 2022: pid 28841: thd-0x563436fe5000: amidxtaped: Amanda::Recovery::Clerk: loading volume 'Archive-02' Mon Jan 03 04:08:38.399677013 2022: pid 28841: thd-0x563436fe5000: amidxtaped: find_volume labeled 'Archive-02' Mon Jan 03 04:08:38.399805184 2022: pid 28841: thd-0x563436fe5000: amidxtaped: new Amanda::Changer::Error: type='failed', reason='notfound', message='Source Volume 'Archive-02' not found' Mon Jan 03 04:08:38.399937856 2022: pid 28841: thd-0x563436fe5000: amidxtaped: CTL >> MESSAGE Source Volume 'Archive-02' not found Mon Jan 03 04:08:38.400019567 2022: pid 28841: thd-0x563436fe5000: amidxtaped: CTL >> FEEDME Archive-02 Mon Jan 03 04:08:52.036750012 2022: pid 28841: thd-0x563436fe5000: amidxtaped: /usr/lib/x86_64-linux-gnu/amanda/perl/Amanda/Restore.pm:1719:info:4900000 256000 kb Mon Jan 03 04:08:53.115018398 2022: pid 28841: thd-0x563436fe5000: amidxtaped: ctl line: TP h-igetp:dvs
