Page 1 of 3 123 LastLast
Results 1 to 10 of 28

Thread: amrecover with S3 tape stops after 2 blocks

  1. #1
    Join Date
    Mar 2017
    Posts
    14

    Default amrecover with S3 tape stops after 2 blocks

    We are using Amanda 3.4.3 with an "S3" tape ( actually implemented via EMC ATMOS - so using STORAGE_API "S3" ).

    Backups are working fine, and we can recover files using amrecover when the tapes are 1 or 2 blocks ( blocksize set to 50M ).

    However if we try to recover files from a tape that has more than 2 blocks, amrecover just hangs and never completes (I've waited for more than 1 hour... ).

    These are the last entries in the amidxtaped debug log:

    Code:
    ...
    Tue Mar 07 11:49:38.583421260 2017: pid 29133: thd-0x1dc1690: amidxtaped: parse_inventory: load slot 16 with label 'ProdSet-16'
    Tue Mar 07 11:49:38.602256436 2017: pid 29133: thd-0x1dc1690: amidxtaped: /usr/local/share/perl5/Amanda/Recovery/Scan.pm:307:info:1200000 slot 16
    Tue Mar 07 11:49:38.603489703 2017: pid 29133: thd-0x1dc1690: amidxtaped: S3 driver using bucket 'prod-backups', prefix 'ProdSet/slot-16/tape'
    Tue Mar 07 11:49:38.603514074 2017: pid 29133: thd-0x1dc1690: amidxtaped: curl version: libcurl/7.53.1 OpenSSL/1.0.1e zlib/1.2.3 c-ares/1.12.0 libssh2/1.8.0 nghttp2/1.6.0
    Tue Mar 07 11:49:38.603523865 2017: pid 29133: thd-0x1dc1690: amidxtaped: curl compiled for OPENSSL
    Tue Mar 07 11:49:38.608284630 2017: pid 29133: thd-0x1dc1690: amidxtaped: Create 6 threads
    Tue Mar 07 11:49:39.080822231 2017: pid 29133: thd-0x1dc1690: amidxtaped: Building type TAPESTART header of 0-52428800 bytes with name='ProdSet-16' disk='' dumplevel=0 and blocksize=0
    Tue Mar 07 11:49:39.082250014 2017: pid 29133: thd-0x1dc1690: amidxtaped: /usr/local/share/perl5/Amanda/Recovery/Scan.pm:459:info:1200001 ProdSet-16
    Tue Mar 07 11:49:39.082534856 2017: pid 29133: thd-0x1dc1690: amidxtaped: ignoring spurious Amanda::Recovery::Scan abort call
    Tue Mar 07 11:49:39.502133244 2017: pid 29133: thd-0x1dc1690: amidxtaped: Amanda::Recovery::Clerk: successfully located first part for recovery
    Tue Mar 07 11:49:39.508682900 2017: pid 29133: thd-0x1dc1690: amidxtaped: Building type FILE header of 128-32768 bytes with name='server.example.com' disk='/opt' dumplevel=0 and blocksize=32768
    Tue Mar 07 11:49:39.508801525 2017: pid 29133: thd-0x1dc1690: amidxtaped: CTL >> HEADER-SEND-SIZE 551
    Tue Mar 07 11:49:39.509333878 2017: pid 29133: thd-0x1dc1690: amidxtaped: CTL << HEADER-READY
    Tue Mar 07 11:49:41.228676865 2017: pid 29133: thd-0x1dc1690: amidxtaped: CTL << HEADER-DONE
    Tue Mar 07 11:49:41.228870784 2017: pid 29133: thd-0x1dc1690: amidxtaped: CTL >> STATE-SEND
    Tue Mar 07 11:49:41.229378230 2017: pid 29133: thd-0x1dc1690: amidxtaped: CTL << STATE-READY
    Tue Mar 07 11:49:41.230058205 2017: pid 29133: thd-0x1dc1690: amidxtaped: CTL << STATE-DONE
    Tue Mar 07 11:49:41.230139287 2017: pid 29133: thd-0x1dc1690: amidxtaped: CTL >> USE-DAR NO
    Tue Mar 07 11:49:41.230473653 2017: pid 29133: thd-0x1dc1690: amidxtaped: CTL << USE-DAR NO
    Tue Mar 07 11:49:41.230585459 2017: pid 29133: thd-0x1dc1690: amidxtaped: CTL << AVAIL-DATAPATH AMANDA
    Tue Mar 07 11:49:41.231037363 2017: pid 29133: thd-0x1dc1690: amidxtaped: Starting <Xfer@0x2ed9550 (<XferSourceRecovery@0x2ecd000> -> <XferDestFd@0x2cde800>)>
    Tue Mar 07 11:49:41.231084087 2017: pid 29133: thd-0x1dc1690: amidxtaped: Final linkage: <XferSourceRecovery@0x2ecd000> -(PULL_BUFFER)-> <XferElementGlue@0x2e72010> -(WRITEFD)-> <XferDestFd@0x2cde800>
    Tue Mar 07 11:49:41.231107431 2017: pid 29133: thd-0x1dc1690: amidxtaped: setup_impl: 3, 2
    Tue Mar 07 11:49:41.231235341 2017: pid 29133: thd-0x1dc1690: amidxtaped: xfer_queue_message: MSG: <XMsg@0x2cdf350 type=XMSG_READY elt=<XferSourceRecovery@0x2ecd000> version=0>
    Tue Mar 07 11:49:41.231267481 2017: pid 29133: thd-0x2cdf5c0: amidxtaped: pull_and_write
    Tue Mar 07 11:49:41.231320900 2017: pid 29133: thd-0x1dc1690: amidxtaped: CTL >> USE-DATAPATH AMANDA
    Tue Mar 07 11:49:41.232664610 2017: pid 29133: thd-0x1dc1690: amidxtaped: CTL << DATAPATH-OK
    Tue Mar 07 11:49:41.232778307 2017: pid 29133: thd-0x1dc1690: amidxtaped: CTL >> DATA-SEND
    Tue Mar 07 11:49:41.233137055 2017: pid 29133: thd-0x1dc1690: amidxtaped: CTL << DATA-READY
    Tue Mar 07 11:49:41.233220578 2017: pid 29133: thd-0x1dc1690: amidxtaped: Amanda::Recovery::Clerk: starting recovery
    Tue Mar 07 11:49:41.235146117 2017: pid 29133: thd-0x1dc1690: amidxtaped: Amanda::Recovery::Clerk: reading file 55 on 'ProdSet-16'
    Tue Mar 07 11:49:56.241680180 2017: pid 29133: thd-0x1dc1690: amidxtaped: /usr/local/share/perl5/Amanda/Restore.pm:1698:info:4900000 86755 kb
    Tue Mar 07 11:50:11.256969517 2017: pid 29133: thd-0x1dc1690: amidxtaped: /usr/local/share/perl5/Amanda/Restore.pm:1698:info:4900000 102400 kb
    Tue Mar 07 11:50:26.271854228 2017: pid 29133: thd-0x1dc1690: amidxtaped: /usr/local/share/perl5/Amanda/Restore.pm:1698:info:4900000 102400 kb
    Tue Mar 07 11:50:41.287620042 2017: pid 29133: thd-0x1dc1690: amidxtaped: /usr/local/share/perl5/Amanda/Restore.pm:1698:info:4900000 102400 kb
    Tue Mar 07 11:50:56.295778675 2017: pid 29133: thd-0x1dc1690: amidxtaped: /usr/local/share/perl5/Amanda/Restore.pm:1698:info:4900000 102400 kb
    Tue Mar 07 11:51:11.304232529 2017: pid 29133: thd-0x1dc1690: amidxtaped: /usr/local/share/perl5/Amanda/Restore.pm:1698:info:4900000 102400 kb
    ....
    I've done a few tests to try to troubleshoot the issue, but haven't got anywhere:

    • amfetchdump works fine retrieving the the full DLE that we are trying to recover. I can then manually extract our backed up files ok.
    • enabling the VERBOSE S3 device parameter shows the 2 blocks successfully retrieved, but no attempt to retrieve the third block
    • increasing the NB_RECOVERY_THREAD S3 device parameter increases the number of blocks retrieved to 2 x the number of threads ( eg 6 threads causes 12 blocks to be retrieved )

    Does anyone have any ideas what could be wrong?

    Happy to supply more information if that helps.

    Kind Regards
    Dave

  2. #2
    Join Date
    Mar 2017
    Posts
    14

    Default

    Just to add - this behaviour was the same in 3.4.1. I upgraded to 3.4.3 to see if it would help, which it didn't.

  3. #3
    Join Date
    Nov 2005
    Location
    Canada
    Posts
    1,044

    Default

    Can you attach gdb to the running amidxtaped and get the stack trace of all threads?

    $ gdb -p 'pid of amidxtaped'
    (gdb) thread apply all bt
    ...
    (gdb) quit

  4. #4
    Join Date
    Mar 2017
    Posts
    14

    Default

    Thanks for that, here's the output:

    Code:
    (gdb) thread apply all bt
    
    Thread 2 (Thread 0x7f335a4ec700 (LWP 5252)):
    #0  0x0000003dd7a0e7cd in write () from /lib64/libpthread.so.0
    #1  0x0000003a9d25d226 in safe_write () from /usr/lib64/amanda/libamanda-3.4.3.so
    #2  0x0000003a9d25ca8e in full_write () from /usr/lib64/amanda/libamanda-3.4.3.so
    #3  0x0000003a9da069d9 in ?? () from /usr/lib64/amanda/libamxfer-3.4.3.so
    #4  0x0000003a9da09c36 in ?? () from /usr/lib64/amanda/libamxfer-3.4.3.so
    #5  0x0000003dd8e6a374 in ?? () from /lib64/libglib-2.0.so.0
    #6  0x0000003dd7a07aa1 in start_thread () from /lib64/libpthread.so.0
    #7  0x0000003dd76e8aad in clone () from /lib64/libc.so.6
    
    Thread 1 (Thread 0x7f335e4de700 (LWP 5058)):
    #0  0x0000003dd76df283 in poll () from /lib64/libc.so.6
    #1  0x0000003dd8e449f9 in ?? () from /lib64/libglib-2.0.so.0
    #2  0x0000003dd8e44e4c in g_main_context_iteration () from /lib64/libglib-2.0.so.0
    #3  0x0000003a9d2393b1 in ?? () from /usr/lib64/amanda/libamanda-3.4.3.so
    #4  0x00007f335c9fb42d in _wrap_run_c () from /usr/local/share/perl5/auto/Amanda/MainLoop/libMainLoop.so
    #5  0x0000003e3daa6815 in Perl_pp_entersub () from /usr/lib64/perl5/CORE/libperl.so
    #6  0x0000003e3daa4b06 in Perl_runops_standard () from /usr/lib64/perl5/CORE/libperl.so
    #7  0x0000003e3da4d0d8 in perl_run () from /usr/lib64/perl5/CORE/libperl.so
    #8  0x0000000000400e74 in main ()
    (gdb) quit
    Let me know if you need more information

  5. #5
    Join Date
    Nov 2005
    Location
    Canada
    Posts
    1,044

    Default

    It is hang in a write.
    This write is to either a software decryption/decompression program, do your data is compressed or encrypted?
    or it is a write to the amandad process.

  6. #6
    Join Date
    Mar 2017
    Posts
    14

    Default

    The data is compressed - but not encrypted

  7. #7
    Join Date
    Nov 2005
    Location
    Canada
    Posts
    1,044

    Default

    client or server compressed?
    Which compression are you using?
    What the decompression program is doing? Get a stack trace of it.

    The data go from amidxtaped -> decompression -> amandad -> amrecover -> application

    As amidxtaped is hang in a write, then it is one of the others processes that do not read the data.

  8. #8
    Join Date
    Mar 2017
    Posts
    14

    Default

    We are using "client fast" compression.

    I can't see the decompression program running ( I guess I should be looking for gzip? )

    Here's the process list and all the stack traces I can get:

    Code:
    [root@localhost template.d]# ps -fu amandabackup
    UID        PID  PPID  C STIME TTY          TIME CMD
    490      12839 12836  0 14:18 ?        00:00:00 sshd: amandabackup@notty
    490      12840 12839  0 14:18 ?        00:00:00 /usr/libexec/amanda/amandad -auth=ssh amindexd amidxtaped
    490      12849 12840  0 14:18 ?        00:00:00 /usr/libexec/amanda/amindexd amandad ssh
    490      12850 12840  0 14:18 ?        00:00:00 [amandad] <defunct>
    490      13682 12840 10 14:22 ?        00:00:04 /usr/bin/perl /usr/libexec/amanda/amidxtaped amandad ssh
    490      13683 12840  0 14:22 ?        00:00:00 [amandad] <defunct>
    [root@localhost template.d]# pstack 12840
    #0  0x0000003dd76e0b5b in writev () from /lib64/libc.so.6
    #1  0x0000003a9d253fe3 in full_writev () from /usr/lib64/amanda/libamanda-3.4.3.so
    #2  0x0000003a9d24c7a1 in tcpm_send_token () from /usr/lib64/amanda/libamanda-3.4.3.so
    #3  0x0000003a9d24c916 in tcpm_stream_write () from /usr/lib64/amanda/libamanda-3.4.3.so
    #4  0x0000000000406553 in ?? ()
    #5  0x0000003a9d239206 in ?? () from /usr/lib64/amanda/libamanda-3.4.3.so
    #6  0x0000003dd8e40642 in g_main_context_dispatch () from /lib64/libglib-2.0.so.0
    #7  0x0000003dd8e44c98 in ?? () from /lib64/libglib-2.0.so.0
    #8  0x0000003dd8e44e4c in g_main_context_iteration () from /lib64/libglib-2.0.so.0
    #9  0x0000003a9d2393b1 in ?? () from /usr/lib64/amanda/libamanda-3.4.3.so
    #10 0x0000000000402be4 in main ()
    [root@localhost template.d]# pstack 12849
    #0  0x0000003dd76db670 in __read_nocancel () from /lib64/libc.so.6
    #1  0x0000003dd7671ca8 in _IO_new_file_underflow () from /lib64/libc.so.6
    #2  0x0000003dd76737ae in _IO_default_uflow_internal () from /lib64/libc.so.6
    #3  0x0000003dd7667e8a in _IO_getline_info_internal () from /lib64/libc.so.6
    #4  0x0000003dd7666ce9 in fgets () from /lib64/libc.so.6
    #5  0x0000003a9d23a761 in debug_pgets () from /usr/lib64/amanda/libamanda-3.4.3.so
    #6  0x00000000004066e6 in main ()
    [root@localhost template.d]# pstack 13682
    Thread 2 (Thread 0x7f2896b4d700 (LWP 13692)):
    #0  0x0000003dd7a0e7cd in write () from /lib64/libpthread.so.0
    #1  0x0000003a9d25d226 in safe_write () from /usr/lib64/amanda/libamanda-3.4.3.so
    #2  0x0000003a9d25ca8e in full_write () from /usr/lib64/amanda/libamanda-3.4.3.so
    #3  0x0000003a9da069d9 in ?? () from /usr/lib64/amanda/libamxfer-3.4.3.so
    #4  0x0000003a9da09c36 in ?? () from /usr/lib64/amanda/libamxfer-3.4.3.so
    #5  0x0000003dd8e6a374 in ?? () from /lib64/libglib-2.0.so.0
    #6  0x0000003dd7a07aa1 in start_thread () from /lib64/libpthread.so.0
    #7  0x0000003dd76e8aad in clone () from /lib64/libc.so.6
    Should I be concerned by the defunct amandad processes?

  9. #9
    Join Date
    Nov 2005
    Location
    Canada
    Posts
    1,044

    Default

    defunct process are correct, amanda do not wait for all its child processes.
    The gzip should be on the machine you are running amrecover
    Can you also get the stacktrace of amrecover? and that gzip?
    Post the amrecover debug file.

  10. #10
    Join Date
    Mar 2017
    Posts
    14

    Default

    I am running amrecover on the backup server , but I get the same issue if running it remotely. Note: We are using ssh authentication for amrecover.

    Here's the process listing for amrecover:

    Code:
    [root@localhost amandad]# ps -fu root | grep pts/0
    root      4862  4836  0 13:41 pts/0    00:00:00 su -
    root      4876  4862  0 13:41 pts/0    00:00:00 -bash
    root     12833  4876  0 14:18 pts/0    00:00:00 amrecover
    root     12834 12833  0 14:18 pts/0    00:00:00 /usr/bin/ssh -x -o BatchMode=yes -o PreferredAuthentications=publickey -l amandabackup localhost /usr/libexec/amanda/amandad -auth=ssh
    root     13693 12833  0 14:22 pts/0    00:00:00 /bin/gzip -dc
    root     13695 12833  0 14:22 pts/0    00:00:00 tar --ignore-zeros --numeric-owner -xpGvf - .
    Stacktraces for amrecover and gzip:

    Code:
    [root@localhost amandad]# pstack 13693
    #0  0x0000003dd76db6d0 in __write_nocancel () from /lib64/libc.so.6
    #1  0x000000000040aade in ?? ()
    #2  0x000000000040ab88 in ?? ()
    #3  0x00000000004062a2 in ?? ()
    #4  0x0000000000406b37 in ?? ()
    #5  0x00000000004072d2 in ?? ()
    #6  0x000000000040a22d in ?? ()
    #7  0x0000000000403fb7 in ?? ()
    #8  0x0000000000405b9a in ?? ()
    #9  0x0000003dd761ed1d in __libc_start_main () from /lib64/libc.so.6
    #10 0x0000000000401729 in ?? ()
    #11 0x00007ffe70f55dc8 in ?? ()
    #12 0x000000000000001c in ?? ()
    #13 0x0000000000000002 in ?? ()
    #14 0x00007ffe70f5793a in ?? ()
    #15 0x00007ffe70f57944 in ?? ()
    #16 0x0000000000000000 in ?? ()
    
    
    [root@localhost amandad]# pstack 12833
    Thread 3 (Thread 0x7f6a2a689700 (LWP 12835)):
    #0  0x0000003dd7a0e82d in read () from /lib64/libpthread.so.0
    #1  0x0000003dd8e41c9b in ?? () from /lib64/libglib-2.0.so.0
    #2  0x0000003dd8e6a374 in ?? () from /lib64/libglib-2.0.so.0
    #3  0x0000003dd7a07aa1 in start_thread () from /lib64/libpthread.so.0
    #4  0x0000003dd76e8aad in clone () from /lib64/libc.so.6
    Thread 2 (Thread 0x7f6a23df5700 (LWP 13694)):
    #0  0x0000003dd7a0e7cd in write () from /lib64/libpthread.so.0
    #1  0x0000003a9d25d226 in safe_write () from /usr/lib64/amanda/libamanda-3.4.3.so
    #2  0x0000003a9d25ca8e in full_write () from /usr/lib64/amanda/libamanda-3.4.3.so
    #3  0x0000000000409e76 in ?? ()
    #4  0x0000003dd8e6a374 in ?? () from /lib64/libglib-2.0.so.0
    #5  0x0000003dd7a07aa1 in start_thread () from /lib64/libpthread.so.0
    #6  0x0000003dd76e8aad in clone () from /lib64/libc.so.6
    Thread 1 (Thread 0x7f6a2a8987c0 (LWP 12833)):
    #0  0x0000003dd7a0e7cd in write () from /lib64/libpthread.so.0
    #1  0x0000003a9d25d226 in safe_write () from /usr/lib64/amanda/libamanda-3.4.3.so
    #2  0x0000003a9d25ca8e in full_write () from /usr/lib64/amanda/libamanda-3.4.3.so
    #3  0x000000000040e1db in ?? ()
    #4  0x0000003a9d249c26 in ?? () from /usr/lib64/amanda/libamanda-3.4.3.so
    #5  0x0000003a9d24b965 in ?? () from /usr/lib64/amanda/libamanda-3.4.3.so
    #6  0x0000003a9d239206 in ?? () from /usr/lib64/amanda/libamanda-3.4.3.so
    #7  0x0000003dd8e40642 in g_main_context_dispatch () from /lib64/libglib-2.0.so.0
    #8  0x0000003dd8e44c98 in ?? () from /lib64/libglib-2.0.so.0
    #9  0x0000003dd8e44e4c in g_main_context_iteration () from /lib64/libglib-2.0.so.0
    #10 0x0000003a9d2393b1 in ?? () from /usr/lib64/amanda/libamanda-3.4.3.so
    #11 0x0000003a9d24c595 in tcpm_stream_read_sync () from /usr/lib64/amanda/libamanda-3.4.3.so
    #12 0x00000000004082ca in get_amidxtaped_line ()
    #13 0x000000000040e8b5 in writer_intermediary ()
    #14 0x000000000040f86e in extract_files ()
    #15 0x000000000041421a in yyparse ()
    #16 0x0000000000415279 in process_line ()
    #17 0x0000000000406eb3 in main ()
    and the last lines of the amrecover debug log

    Code:
    Wed Mar 08 14:22:08.027125634 2017: pid 12833: thd-0x1782350: amrecover: append_to_tapelist(tapelist=(nil), storage='ProdSet', label='ProdSet-7', file=-1, partnum=-1,  isafile=0)
    Wed Mar 08 14:22:08.027159285 2017: pid 12833: thd-0x1782350: amrecover: append_to_tapelist(tapelist=0x17c8790, storage='ProdSet', label='ProdSet-7', file=124, partnum=-1,  isafile=0)
    Wed Mar 08 14:22:08.027185789 2017: pid 12833: thd-0x1782350: amrecover: append_to_tapelist(tapelist=(nil), storage='ProdSet', label='ProdSet-7', file=-1, partnum=-1,  isafile=0)
    Wed Mar 08 14:22:08.027198438 2017: pid 12833: thd-0x1782350: amrecover: append_to_tapelist(tapelist=0x17c8790, storage='ProdSet', label='ProdSet-7', file=124, partnum=-1,  isafile=0)
    Wed Mar 08 14:22:08.027226141 2017: pid 12833: thd-0x1782350: amrecover: Requesting tape ProdSet-7 from user
    Wed Mar 08 14:22:09.426134029 2017: pid 12833: thd-0x1782350: amrecover: User prompt: 'Continue [?/Y/n/s/d]? '; response: 'y'
    Wed Mar 08 14:22:09.426217116 2017: pid 12833: thd-0x1782350: amrecover: security_getdriver(name=ssh) returns 0x3a9d48d2a0
    Wed Mar 08 14:22:09.426239316 2017: pid 12833: thd-0x1782350: amrecover: security_handleinit(handle=0x17cc650, driver=0x3a9d48d2a0 (SSH))
    Wed Mar 08 14:22:09.426263522 2017: pid 12833: thd-0x1782350: amrecover: security_streaminit(stream=0x17ceb30, driver=0x3a9d48d2a0 (SSH))
    Wed Mar 08 14:22:09.722214283 2017: pid 12833: thd-0x1782350: amrecover: security_streaminit(stream=0x17d6bd0, driver=0x3a9d48d2a0 (SSH))
    Wed Mar 08 14:22:09.722241069 2017: pid 12833: thd-0x1782350: amrecover: amidxtaped_streams[0].fd = 0x17d6bd0
    Wed Mar 08 14:22:09.722277781 2017: pid 12833: thd-0x1782350: amrecover: security_streaminit(stream=0x17dec70, driver=0x3a9d48d2a0 (SSH))
    Wed Mar 08 14:22:09.722291107 2017: pid 12833: thd-0x1782350: amrecover: amidxtaped_streams[1].fd = 0x17dec70
    Wed Mar 08 14:22:09.722337534 2017: pid 12833: thd-0x1782350: amrecover: security_streaminit(stream=0x17e6d10, driver=0x3a9d48d2a0 (SSH))
    Wed Mar 08 14:22:09.722353586 2017: pid 12833: thd-0x1782350: amrecover: amidxtaped_streams[2].fd = 0x17e6d10
    Wed Mar 08 14:22:09.722362280 2017: pid 12833: thd-0x1782350: amrecover: security_close(handle=0x17cc650, driver=0x3a9d48d2a0 (SSH))
    Wed Mar 08 14:22:09.722371312 2017: pid 12833: thd-0x1782350: amrecover: security_stream_close(0x17ceb30)
    Wed Mar 08 14:22:09.722399058 2017: pid 12833: thd-0x1782350: amrecover: send_to_tape_server: FEATURES=ffffffff9efefbfffffffffffffff3fffbf70f
    
    Wed Mar 08 14:22:09.722512107 2017: pid 12833: thd-0x1782350: amrecover: ignoring close stream 2
    Wed Mar 08 14:22:09.722959836 2017: pid 12833: thd-0x1782350: amrecover: send_to_tape_server: CONFIG=ProdSet
    
    Wed Mar 08 14:22:09.722998558 2017: pid 12833: thd-0x1782350: amrecover: send_to_tape_server: LABEL=ProdSet:ProdSet-7:124
    
    Wed Mar 08 14:22:09.723031232 2017: pid 12833: thd-0x1782350: amrecover: send_to_tape_server: FSF=124
    
    Wed Mar 08 14:22:09.723062502 2017: pid 12833: thd-0x1782350: amrecover: send_to_tape_server: HEADER
    
    Wed Mar 08 14:22:09.723082581 2017: pid 12833: thd-0x1782350: amrecover: send_to_tape_server: DEVICE=changer
    
    Wed Mar 08 14:22:09.723094186 2017: pid 12833: thd-0x1782350: amrecover: send_to_tape_server: HOST=^localhost.example.com$
    
    Wed Mar 08 14:22:09.723105152 2017: pid 12833: thd-0x1782350: amrecover: send_to_tape_server: DISK=^/opt$
    
    Wed Mar 08 14:22:09.723115621 2017: pid 12833: thd-0x1782350: amrecover: send_to_tape_server: DATESTAMP=20170307183001
    
    Wed Mar 08 14:22:09.723126099 2017: pid 12833: thd-0x1782350: amrecover: send_to_tape_server: END
    
    Wed Mar 08 14:22:10.979256953 2017: pid 12833: thd-0x1782350: amrecover: get amidxtaped line: HEADER-SEND-SIZE 551
    Wed Mar 08 14:22:10.979303434 2017: pid 12833: thd-0x1782350: amrecover: send_to_tape_server: HEADER-READY
    
    Wed Mar 08 14:22:10.979680303 2017: pid 12833: thd-0x1782350: amrecover: read header 551 => 551 (551)
    Wed Mar 08 14:22:14.250123055 2017: pid 12833: thd-0x1782350: amrecover: User prompt: 'Continue [?/Y/n]? '; response: 'y'
    Wed Mar 08 14:22:14.250194901 2017: pid 12833: thd-0x1782350: amrecover: send_to_tape_server: HEADER-DONE
    
    Wed Mar 08 14:22:14.250923455 2017: pid 12833: thd-0x1782350: amrecover: get amidxtaped line: STATE-SEND
    Wed Mar 08 14:22:14.250955829 2017: pid 12833: thd-0x1782350: amrecover: send_to_tape_server: STATE-READY
    
    Wed Mar 08 14:22:14.251611740 2017: pid 12833: thd-0x1782350: amrecover: security_stream_seterr(0x17e6d10, EOF)
    Wed Mar 08 14:22:14.251637071 2017: pid 12833: thd-0x1782350: amrecover: security_stream_close(0x17e6d10)
    Wed Mar 08 14:22:14.251662769 2017: pid 12833: thd-0x1782350: amrecover: send_to_tape_server: STATE-DONE
    
    Wed Mar 08 14:22:14.252106856 2017: pid 12833: thd-0x1782350: amrecover: get amidxtaped line: USE-DAR NO
    Wed Mar 08 14:22:14.252124664 2017: pid 12833: thd-0x1782350: amrecover: send_to_tape_server: USE-DAR NO
    
    Wed Mar 08 14:22:14.252145165 2017: pid 12833: thd-0x1782350: amrecover: send_to_tape_server: AVAIL-DATAPATH AMANDA
    
    Wed Mar 08 14:22:14.253390178 2017: pid 12833: thd-0x1782350: amrecover: get amidxtaped line: USE-DATAPATH AMANDA
    Wed Mar 08 14:22:14.253407657 2017: pid 12833: thd-0x1782350: amrecover: Using AMANDA data-path
    Wed Mar 08 14:22:14.253433682 2017: pid 12833: thd-0x1782350: amrecover: image is compressed
    Wed Mar 08 14:22:14.253448408 2017: pid 12833: thd-0x1782350: amrecover: Spawning "/bin/gzip /bin/gzip -dc" in pipeline
    Wed Mar 08 14:22:14.254344549 2017: pid 12833: thd-0x1782350: amrecover: send_to_tape_server: DATAPATH-OK
    
    Wed Mar 08 14:22:14.254414851 2017: pid 13695: thd-0x1782350: amrecover: Exec'ing /bin/tar with arguments:
    Wed Mar 08 14:22:14.254495024 2017: pid 13695: thd-0x1782350: amrecover:        tar
    Wed Mar 08 14:22:14.254514598 2017: pid 13695: thd-0x1782350: amrecover:        --ignore-zeros
    Wed Mar 08 14:22:14.254531309 2017: pid 13695: thd-0x1782350: amrecover:        --numeric-owner
    Wed Mar 08 14:22:14.254547597 2017: pid 13695: thd-0x1782350: amrecover:        -xpGvf
    Wed Mar 08 14:22:14.254564689 2017: pid 13695: thd-0x1782350: amrecover:        -
    Wed Mar 08 14:22:14.254581329 2017: pid 13695: thd-0x1782350: amrecover:        .
    Wed Mar 08 14:22:14.254789789 2017: pid 12833: thd-0x1782350: amrecover: get amidxtaped line: DATA-SEND
    Wed Mar 08 14:22:14.254807253 2017: pid 12833: thd-0x1782350: amrecover: send_to_tape_server: DATA-READY
    
    Wed Mar 08 14:22:20.291140247 2017: pid 12833: thd-0x1782350: amrecover: stream_read_callback: data is still flowing
    Let me know if you need the full logfile, as I'll have to do some redacting on it.

    The thing I don't understand is why this works for a small filesystem recovery , but not for a large(r) one....

Posting Permissions

  • You may not post new threads
  • You may not post replies
  • You may not post attachments
  • You may not edit your posts
  •