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:
[[email protected] 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:
[[email protected] 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 ?? ()
[[email protected] 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....