Amanda-Users

False alarm in e-mail report

2006-08-25 03:59:33
Subject: False alarm in e-mail report
From: Toomas Aas <toomas.aas AT raad.tartu DOT ee>
To: amanda-users AT amanda DOT org
Date: Fri, 25 Aug 2006 10:49:09 +0300
Hello!

Here's another weirdness in Amanda report.
Amanda server is 2.5.0p2 running on FreeBSD 5.4
The client with error is 2.4.5 running on FreeBSD 6.0.

The DLE that is reported as FAILED in "FAILURE AND STRANGE
DUMP SUMMARY" is later reported as having been backed up
in "DUMP SUMMARY" section. I tried to restore some files
from this DLE using amrecover and the files were restored
successfully, so indeed the backup was successful.

-------- Amanda report --------

These dumps were to tape PAEV34.
The next tape Amanda expects to use is: PAEV35.

FAILURE AND STRANGE DUMP SUMMARY:
  tsensor.raad.tartu.ee  /usr  lev 0  FAILED [cannot read header: got 0 instead 
of 32768]
  tsensor.raad.tartu.ee  /usr  lev 0  FAILED [data timeout]


STATISTICS:
                          Total       Full      Incr.
                        --------   --------   --------
Estimate Time (hrs:min)    0:04
Run Time (hrs:min)         6:06
Dump Time (hrs:min)        9:30       9:30       0:00
Output Size (meg)       36460.6    36460.6        0.0
Original Size (meg)     36460.6    36460.6        0.0
Avg Compressed Size (%)     --         --         --
Filesystems Dumped           16         16          0
Avg Dump Rate (k/s)      1092.5     1092.5        --

Tape Time (hrs:min)        4:33       4:33       0:00
Tape Size (meg)         36461.3    36461.3        0.0
Tape Used (%)              68.8       68.8        0.0
Filesystems Taped            16         16          0

Chunks Taped                  0          0          0
Avg Tp Write Rate (k/s)  2276.2     2276.2        --

USAGE BY TAPE:
  Label        Time      Size      %    Nb    Nc
  PAEV34       4:33 37336416k   68.8    16     0


FAILED AND STRANGE DUMP DETAILS:

/--  tsensor.raad.tartu.ee /usr lev 0 FAILED [data timeout]
? dumper: strange [missing size line from sendbackup]
\--------


NOTES:
  taper: tape PAEV34 kb 37336416 fm 16 [OK]


DUMP SUMMARY:
                                        DUMPER STATS                 TAPER STATS
HOSTNAME     DISK        L  ORIG-kB   OUT-kB  COMP%  MMM:SS    KB/s MMM:SS    
KB/s
-------------------------- ---------------------------------------- 
--------------
<14 DLEs snipped>
tsensor.raad /usr        0  2001740  2001792    --   159:56   208.6   7:57  
4199.5
<1 DLE snipped>

(brought to you by Amanda version 2.5.0p2)

-------- Amanda report --------

-------- sendbackup debug --------

sendbackup: debug 1 pid 91161 ruid 1002 euid 1002: start at Thu Aug 24 22:47:46 
2006
/usr/local/libexec/amanda/sendbackup: version 2.4.5
  parsed request as: program `DUMP'
                     disk `/usr'
                     device `/usr'
                     level 0
                     since 1970:1:1:0:0:0
                     options `|;auth=BSD;index;'
sendbackup: try_socksize: send buffer size is 65536
sendbackup: time 0.000: stream_server: waiting for connection: 0.0.0.0.11086
sendbackup: time 0.001: stream_server: waiting for connection: 0.0.0.0.11087
sendbackup: time 0.001: stream_server: waiting for connection: 0.0.0.0.11088
sendbackup: time 0.001: waiting for connect on 11086, then 11087, then 11088
sendbackup: time 0.097: stream_accept: connection from 194.126.106.100.58443
sendbackup: time 0.193: stream_accept: connection from 194.126.106.100.64231
sendbackup: time 0.293: stream_accept: connection from 194.126.106.100.59027
sendbackup: time 0.293: got all connections
sendbackup: time 0.295: dumping device '/dev/mirror/gm0s1f' with 'ufs'
sendbackup: time 0.296: spawning /sbin/dump in pipeline
sendbackup: argument list: dump 0ushf 1048576 0 - /dev/mirror/gm0s1f
sendbackup: time 0.304: started index creator: "/sbin/restore -tvf - 2>&1 | sed 
-e '
s/^leaf[        ]*[0-9]*[       ]*\.//
t
/^dir[  ]/ {
s/^dir[         ]*[0-9]*[       ]*\.//
s%$%/%
t
}
d
'"
sendbackup: time 0.391:  93:  normal(|):   DUMP: WARNING: should use -L when 
dumping live read-write filesystems!
sendbackup: time 0.398:  93:  normal(|):   DUMP: Date of this level 0 dump: Thu 
Aug 24 22:47:46 2006
sendbackup: time 0.400:  93:  normal(|):   DUMP: Date of last level 0 dump: the 
epoch
sendbackup: time 0.402:  93:  normal(|):   DUMP: Dumping /dev/mirror/gm0s1f 
(/usr) to standard output
sendbackup: time 0.444:  93:  normal(|):   DUMP: mapping (Pass I) [regular 
files]
sendbackup: time 3.624:  93:  normal(|):   DUMP: mapping (Pass II) [directories]
sendbackup: time 3.627:  93:  normal(|):   DUMP: estimated 1844657 tape blocks.
sendbackup: time 3.642:  93:  normal(|):   DUMP: dumping (Pass III) 
[directories]
sendbackup: time 303.594:  93:  normal(|):   DUMP: 3.75% done, finished in 2:08 
at Fri Aug 25 01:01:01 2006
sendbackup: time 432.252:  93:  normal(|):   DUMP: dumping (Pass IV) [regular 
files]
sendbackup: time 603.606:  93:  normal(|):   DUMP: 6.78% done, finished in 2:17 
at Fri Aug 25 01:15:21 2006
sendbackup: time 903.661:  93:  normal(|):   DUMP: 10.14% done, finished in 
2:12 at Fri Aug 25 01:15:45 2006
sendbackup: time 1203.679:  93:  normal(|):   DUMP: 13.57% done, finished in 
2:07 at Fri Aug 25 01:15:09 2006
sendbackup: time 1503.720:  93:  normal(|):   DUMP: 17.21% done, finished in 
2:00 at Fri Aug 25 01:13:08 2006
sendbackup: time 1803.751:  93:  normal(|):   DUMP: 20.74% done, finished in 
1:54 at Fri Aug 25 01:12:29 2006
sendbackup: time 2103.569:  93:  normal(|):   DUMP: 24.11% done, finished in 
1:50 at Fri Aug 25 01:12:59 2006
sendbackup: time 2403.765:  93:  normal(|):   DUMP: 27.88% done, finished in 
1:43 at Fri Aug 25 01:11:18 2006
sendbackup: time 2703.722:  93:  normal(|):   DUMP: 31.46% done, finished in 
1:38 at Fri Aug 25 01:10:52 2006
sendbackup: time 3003.586:  93:  normal(|):   DUMP: 34.89% done, finished in 
1:33 at Fri Aug 25 01:11:09 2006
sendbackup: time 3303.767:  93:  normal(|):   DUMP: 38.45% done, finished in 
1:28 at Fri Aug 25 01:10:52 2006
sendbackup: time 3603.809:  93:  normal(|):   DUMP: 41.78% done, finished in 
1:23 at Fri Aug 25 01:11:26 2006
sendbackup: time 3903.615:  93:  normal(|):   DUMP: 45.24% done, finished in 
1:18 at Fri Aug 25 01:11:30 2006
sendbackup: time 4203.572:  93:  normal(|):   DUMP: 48.89% done, finished in 
1:13 at Fri Aug 25 01:11:00 2006
sendbackup: time 4503.673:  93:  normal(|):   DUMP: 52.58% done, finished in 
1:07 at Fri Aug 25 01:10:27 2006
sendbackup: time 4803.796:  93:  normal(|):   DUMP: 55.96% done, finished in 
1:02 at Fri Aug 25 01:10:47 2006
sendbackup: time 5103.705:  93:  normal(|):   DUMP: 58.76% done, finished in 
0:59 at Fri Aug 25 01:12:29 2006
sendbackup: time 5403.724:  93:  normal(|):   DUMP: 61.41% done, finished in 
0:56 at Fri Aug 25 01:14:23 2006
sendbackup: time 5703.741:  93:  normal(|):   DUMP: 64.18% done, finished in 
0:53 at Fri Aug 25 01:15:50 2006
sendbackup: time 6003.744:  93:  normal(|):   DUMP: 66.97% done, finished in 
0:49 at Fri Aug 25 01:17:08 2006
sendbackup: time 6303.702:  93:  normal(|):   DUMP: 70.34% done, finished in 
0:44 at Fri Aug 25 01:17:06 2006
sendbackup: time 6603.632:  93:  normal(|):   DUMP: 73.79% done, finished in 
0:39 at Fri Aug 25 01:16:54 2006
sendbackup: time 6903.571:  93:  normal(|):   DUMP: 77.15% done, finished in 
0:34 at Fri Aug 25 01:16:54 2006
sendbackup: time 7203.815:  93:  normal(|):   DUMP: 81.06% done, finished in 
0:28 at Fri Aug 25 01:15:52 2006
sendbackup: time 7503.714:  93:  normal(|):   DUMP: 84.83% done, finished in 
0:22 at Fri Aug 25 01:15:11 2006
sendbackup: time 7803.814:  93:  normal(|):   DUMP: 88.39% done, finished in 
0:17 at Fri Aug 25 01:14:54 2006
sendbackup: time 8103.767:  93:  normal(|):   DUMP: 91.94% done, finished in 
0:11 at Fri Aug 25 01:14:39 2006
sendbackup: time 8403.622:  93:  normal(|):   DUMP: 95.42% done, finished in 
0:06 at Fri Aug 25 01:14:32 2006
sendbackup: time 8703.966:  93:  normal(|):   DUMP: 98.93% done, finished in 
0:01 at Fri Aug 25 01:14:24 2006
sendbackup: time 9003.604:  93:  normal(|):   DUMP: 99.99% done, finished soon
sendbackup: time 9303.677:  93:  normal(|):   DUMP: 99.99% done, finished soon
sendbackup: time 9595.528:  49:    size(|):   DUMP: DUMP: 2001748 tape blocks
sendbackup: time 9595.531:  93:  normal(|):   DUMP: finished in 9591 seconds, 
throughput 208 KBytes/sec
sendbackup: time 9595.534:  93:  normal(|):   DUMP: level 0 dump on Thu Aug 24 
22:47:46 2006
sendbackup: time 9595.572:  93:  normal(|):   DUMP: DUMP IS DONE
sendbackup: time 9595.574: index created successfully
sendbackup: time 9595.576: pid 91161 finish time Fri Aug 25 01:27:42 2006

-------- sendbackup debug --------

<Prev in Thread] Current Thread [Next in Thread>