Taper debug file:
Mon Apr 10 15:21:13.388038789 2017: pid 16607: thd-0x1dcae00: taper: pid 16607
ruid 9000 euid 9000 version 3.4: start at Mon Apr 10 15:21:13 2017
Mon Apr 10 15:21:13.388111083 2017: pid 16607: thd-0x1dcae00: taper: Arguments:
NMHPVPR --storage NMHPVPR --log-filename
/var/lib/amanda/NMHPVPR/state/log/log.20170410152105.0
Mon Apr 10 15:21:13.388421435 2017: pid 16607: thd-0x1dcae00: taper: reading
config file /etc/amanda/NMHPVPR/amanda.conf
Mon Apr 10 15:21:13.389776453 2017: pid 16607: thd-0x1dcae00: taper: pid 16607
ruid 9000 euid 9000 version 3.4: rename at Mon Apr 10 15:21:13 2017
Mon Apr 10 15:21:13.397097849 2017: pid 16607: thd-0x1dcae00: taper:
Amanda::Taper::Scan::traditional stage 1: search for oldest reusable volume
Mon Apr 10 15:21:13.397251012 2017: pid 16607: thd-0x1dcae00: taper:
Amanda::Taper::Scan::traditional oldest reusable volume is 'NMHPVPR0002'
Mon Apr 10 15:21:13.397341803 2017: pid 16607: thd-0x1dcae00: taper:
Amanda::Taper::Scan::traditional changer is not fast-searchable; skipping to
stage 2
Mon Apr 10 15:21:13.397421969 2017: pid 16607: thd-0x1dcae00: taper:
Amanda::Taper::Scan::traditional stage 2: scan for any reusable volume
Mon Apr 10 15:21:13.401516306 2017: pid 16607: thd-0x1dcae00: taper: Device is
in variable block size
Mon Apr 10 15:21:18.258290267 2017: pid 16607: thd-0x1dcae00: taper: Slot 1
with label NMHPVPR0002 is usable
Mon Apr 10 15:21:18.258422019 2017: pid 16607: thd-0x1dcae00: taper:
Amanda::Taper::Scan::traditional result: 'NMHPVPR0002' on tape:/dev/nst0 slot
1, mode 2
Mon Apr 10 15:21:18.260327601 2017: pid 16607: thd-0x1dcae00: taper:
Amanda::Taper::Scribe preparing to write, part size 0, using no cache (PEOM
will be fatal) (splitter) (no LEOM)
Mon Apr 10 15:21:18.260781324 2017: pid 16607: thd-0x1dcae00: taper: Starting
<Xfer@0x3386bd0 (<XferSourceHolding@0x3387010> ->
<XferDestTaperSplitter@0x3388010>)>
Mon Apr 10 15:21:18.260819175 2017: pid 16607: thd-0x1dcae00: taper: Final
linkage: <XferSourceHolding@0x3387010> -(MEM_RING)->
<XferDestTaperSplitter@0x3388010>
Mon Apr 10 15:21:18.261417598 2017: pid 16607: thd-0x1dcae00: taper: header
native_crc: 48f5f7aa:3983360
Mon Apr 10 15:21:18.261445517 2017: pid 16607: thd-0x1dcae00: taper: header
client_crc: 48f5f7aa:3983360
Mon Apr 10 15:21:18.261456690 2017: pid 16607: thd-0x1dcae00: taper: header
server_crc: 823a1732:1282787
Mon Apr 10 15:21:18.261557266 2017: pid 16607: thd-0x1dcae00: taper:
start_recovery called
Mon Apr 10 15:21:18.274176799 2017: pid 16607: thd-0x1dcae00: taper: Building
type TAPESTART header of 262144-262144 bytes with name='NMHPVPR0002' disk=''
dumplevel=0 and blocksize=262144
Mon Apr 10 15:21:30.273418789 2017: pid 16607: thd-0x338a800: taper: Building
type SPLIT_FILE header of 262144-262144 bytes with name='fileserver2'
disk='/Hope_IT' dumplevel=1 and blocksize=262144
/usr/bin/perl amflush stack trace:
#0 0x00007f478b5a9ecc in waitpid () from /lib64/libpthread.so.0
#1 0x00007f478c5c2c1f in Perl_wait4pid () from /usr/lib64/perl5/CORE/libperl.so
#2 0x00007f478c630e86 in Perl_pp_wait () from /usr/lib64/perl5/CORE/libperl.so
#3 0x00007f478c5deba6 in Perl_runops_standard () from
/usr/lib64/perl5/CORE/libperl.so
#4 0x00007f478c57b9a5 in perl_run () from /usr/lib64/perl5/CORE/libperl.so
#5 0x0000000000400d99 in main ()
/usr/libexec/amanda/driver stack trace:
#0 0x00007fed83286de0 in __poll_nocancel () from /lib64/libc.so.6
#1 0x00007fed837c104c in g_main_context_iterate.isra.24 () from
/lib64/libglib-2.0.so.0
#2 0x00007fed837c116c in g_main_context_iteration () from
/lib64/libglib-2.0.so.0
#3 0x00007fed83ae6aed in event_loop_wait () from
/usr/lib64/amanda/libamanda-3.4.so
#4 0x0000000000404da8 in main ()
/usr/bin/perl taper stack trace:
#0 0x00007fcbe7187dfd in poll () from /lib64/libc.so.6
#1 0x00007fcbe5a5904c in g_main_context_iterate.isra.24 () from
/lib64/libglib-2.0.so.0
#2 0x00007fcbe5a5916c in g_main_context_iteration () from
/lib64/libglib-2.0.so.0
#3 0x00007fcbe65dcb45 in event_loop_wait () from
/usr/lib64/amanda/libamanda-3.4.so
#4 0x00007fcbdfc698b0 in _wrap_run_c () from
/usr/local/share/perl5/auto/Amanda/MainLoop/libMainLoop.so
#5 0x00007fcbe84a742f in Perl_pp_entersub () from
/usr/lib64/perl5/CORE/libperl.so
#6 0x00007fcbe849fba6 in Perl_runops_standard () from
/usr/lib64/perl5/CORE/libperl.so
#7 0x00007fcbe843c9a5 in perl_run () from /usr/lib64/perl5/CORE/libperl.so
#8 0x0000000000400d99 in main ()
-Sandro
From: Jean-Louis Martineau [mailto:[email protected]]
Sent: Tuesday, April 11, 2017 8:37 AM
To: Ochressandro Rettinger <[email protected]>; Nathan Stratton Treadway
<[email protected]>; [email protected]
Subject: Re: amflush
It looks like the taper process is hang.
Can you post the taper debug file?
Can you get a gdb stacktrace of all threads?
Jean-Louis
On 11/04/17 10:12 AM, Ochressandro Rettinger wrote:
> In fact, I am now sure that it's not doing anything. I ran amstatus this
> morning and it looks exactly the same as it did yesterday afternoon.
>
> If I can't get amflush to work, is there a way to clear out the stuff that
> needs flushing in a way that won't mess Amanda up? I need to be able to run
> backups tonight.
>
> -Sandro
>
>
> -----Original Message-----
> From: [email protected]<mailto:[email protected]>
> [mailto:[email protected]] On Behalf Of Ochressandro Rettinger
> Sent: Monday, April 10, 2017 4:31 PM
> To: Nathan Stratton Treadway <[email protected]<mailto:[email protected]>>;
> [email protected]<mailto:[email protected]>
> Subject: Re: amflush
>
>
> I'm not sure it's doing anything.
>
> [amandabackup@archivist NMHPVPR]$ amstatus NMHPVPR
> Using: /var/lib/amanda/NMHPVPR/state/log/amdump
> From Mon Apr 10 15:21:05 MDT 2017
>
> fileserver2:/Hope_IT 20170408010017 1 1252k flushing (0k done (0.00%))
> (15:21:10)
> fileserver2:/Hope_Secure 20170408010017 1 2006k wait for flushing
> fileserver2:/Hope_Shared 20170408010017 1 876k wait for flushing
> fileserver2:/Hope_Students 20170408010017 0 17825086k wait for flushing
> fileserver2:/slash 20170408010017 0 1192436k wait for flushing
> pr-db2:/slash 20170408010017 0 179616325k wait for flushing
> pr-db2test:/slash 20170408010017 0 11823469k wait for flushing
>
> SUMMARY dle real estimated
> size size
> ---------------- ---- --------- ---------
> disk : 0
> estimated : 0 0k
> flush : 7 210461452k
> dump failed : 0 0k ( 0.00%)
> wait for dumping: 0 0k ( 0.00%)
> dumping to tape : 0 0k 0k ( 0.00%) ( 0.00%)
> dumping : 0 0k 0k ( 0.00%) ( 0.00%)
> dumped : 0 0k 0k ( 0.00%) ( 0.00%)
> wait for writing
> wait to flush : 6 210460199k 210460199k (100.00%) ( 0.00%)
> writing to tape : 1 1252k 1252k (100.00%) ( 0.00%)
> dumping to tape
> failed to tape
> taped
>
> 10 dumpers idle : no-dumpers
> NMHPVPR qlen: 6
> 0: flushing (fileserver2:/Hope_IT)
>
> network free kps: 80000
> holding space : 2097152k (100.00%)
> 0 dumpers busy : 0:00:17 (100.00%) no-dumpers: 0:00:12 ( 70.32%)
> not-idle: 0:00:05 ( 29.68%)
>
>
> -Sandro
>
> ________________________________________
> From: Nathan Stratton Treadway <[email protected]<mailto:[email protected]>>
> Sent: Monday, April 10, 2017 4:26 PM
> To: [email protected]<mailto:[email protected]>
> Cc: Ochressandro Rettinger
> Subject: Re: amflush
>
> On Mon, Apr 10, 2017 at 21:56:40 +0000, Ochressandro Rettinger wrote:
>> Is there a way to check to see how far along amflush is?
> the "amstatus" command.
>
> Nathan
>
> ----------------------------------------------------------------------------
> Nathan Stratton Treadway - [email protected]<mailto:[email protected]> -
> Mid-Atlantic region
> Ray Ontko & Co. - Software consulting services - http://www.ontko.com/
> GPG Key: http://www.ontko.com/~nathanst/gpg_key.txt ID: 1023D/ECFB6239
> Key fingerprint = 6AD8 485E 20B9 5C71 231C 0C32 15F3 ADCD ECFB 6239
>
>
Disclaimer
This message is the property of CARBONITE, INC.<http://www.carbonite.com> and
may contain confidential or privileged information.
If this message has been delivered to you by mistake, then do not copy or
deliver this message to anyone. Instead, destroy it and notify me by reply
e-mail.
