Amanda-Users

Re: False alarm in e-mail report

2006-08-25 12:21:38
Subject: Re: False alarm in e-mail report
From: Jean-Louis Martineau <martineau AT zmanda DOT com>
To: Toomas Aas <toomas.aas AT raad.tartu DOT ee>
Date: Fri, 25 Aug 2006 12:14:50 -0400
Toomas,

I looks like the first attempt to dump tsensor.raad.tartu.ee:/usr failed but the seconds attempt succeeded. Could you send me the amdump.?? and log.<datestamp> file so that I can look at them and be sure of what I said.

You sent the sendbackup.*.debug file for the successful dump, you should have one for the failed dump?
The amandad.*.debug might tell something about the failed dump.
Did you have a problem with tsensor.raad.tartu.ee during that night, look at system log.

Jean-Louis

Toomas Aas wrote:
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>