Hello!
I recently (this Sunday) upgraded my Amanda server to 2.5.0p2. Clients (other
than the server itself) are 2.4.4 and 2.4.5.
First two amdumps (Monday and Tuesday evenyng) ran fine, except that I forgot
to change the tape on Tuesday and had to run amflush on Wednesday. But the
Wednesday evening dump had two DLEs fail.
The reason of first one (tsensor.raad.tartu.ee /) I understand - it's caused
by a firewall on client not handling some TCP windowing stuff very well. This
has happened from time to time, even before upgrading the Amanda server, even
though the error message was a bit different.
The second one (heerold.raad.tartu.ee /home) is something new, however.
The situation with this DLE is that it is quite big and sometimes doesn't fit on
holding disk. With previous versions of Amanda it was started to dump on
holdingdisk,
then the holdingdisk filled up, then there was a "broken pipe" message in
syslog (but
not in Amanda report), then the DLE was restarted directly to tape and got
backed up
successfully.
It seems that now, once the holdingdisk fills up, the DLE is not restarted
directly
to tape, it just fails.
I think I might set "holdingdisk no" for this DLE since it often doesn't fit
anyway,
but the behaviour of Amanda in this situation still doesn't seem quite correct
to me.
-------- Amanda report --------
Subject: TLV AMANDA MAIL REPORT FOR August 23, 2006
Date: Thu, 24 Aug 2006 03:32:58 +0300 (EEST)
From: operator AT post.raad.tartu DOT ee (System Operator)
To: amanda-admins AT post.raad.tartu DOT ee
*** THE DUMPS DID NOT FINISH PROPERLY!
These dumps were to tape PAEV33.
The next tape Amanda expects to use is: PAEV34.
FAILURE AND STRANGE DUMP SUMMARY:
tsensor.raad.tartu.ee / lev 0 FAILED [cannot read header: got 0
instead of 32768]
heerold.raad.tartu.ee /home lev 0 FAILED [data write: Broken pipe]
driver: FATAL Don't know how to send ABORT command to chunker
chunker: FATAL error [bad command after RQ-MORE-DISK: "QUIT"]
<snip>
(brought to you by Amanda version 2.5.0p2)
-------- Amanda report --------
-------- sendbackup debug --------
sendbackup: debug 1 pid 36024 ruid 1034 euid 1034: start at Thu Aug 24 01:48:29
2006
/usr/local/libexec/amanda/sendbackup: version 2.4.4p4
parsed request as: program `DUMP'
disk `/home'
device `/home'
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.11081
sendbackup: time 0.000: stream_server: waiting for connection: 0.0.0.0.11082
sendbackup: time 0.000: stream_server: waiting for connection: 0.0.0.0.11083
sendbackup: time 0.000: waiting for connect on 11081, then 11082, then 11083
sendbackup: time 0.016: stream_accept: connection from 194.126.106.100.11083
sendbackup: time 0.035: stream_accept: connection from 194.126.106.100.11084
sendbackup: time 0.061: stream_accept: connection from 194.126.106.100.11085
sendbackup: time 0.061: got all connections
sendbackup: time 0.062: dumping device '/dev/da0s1g' with 'ufs'
sendbackup: time 0.063: spawning /sbin/dump in pipeline
sendbackup: argument list: dump 0ushf 1048576 0 - /dev/da0s1g
sendbackup: time 0.065: 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.068: 93: normal(|): DUMP: WARNING: should use -L when
dumping live read-write filesystems!
sendbackup: time 0.068: 93: normal(|): DUMP: Date of this level 0 dump: Thu
Aug 24 01:48:29 2006
sendbackup: time 0.069: 93: normal(|): DUMP: Date of last level 0 dump: the
epoch
sendbackup: time 0.069: 93: normal(|): DUMP: Dumping /dev/da0s1g (/home) to
standard output
sendbackup: time 0.767: 93: normal(|): DUMP: mapping (Pass I) [regular
files]
sendbackup: time 2.676: 93: normal(|): DUMP: mapping (Pass II) [directories]
sendbackup: time 2.677: 93: normal(|): DUMP: estimated 17437291 tape blocks.
sendbackup: time 2.725: 93: normal(|): DUMP: dumping (Pass III)
[directories]
sendbackup: time 26.967: 93: normal(|): DUMP: dumping (Pass IV) [regular
files]
sendbackup: time 302.311: 93: normal(|): DUMP: 5.25% done, finished in 1:30
at Thu Aug 24 03:23:45 2006
sendbackup: time 602.284: 93: normal(|): DUMP: 11.48% done, finished in
1:17 at Thu Aug 24 03:15:36 2006
sendbackup: time 902.281: 93: normal(|): DUMP: 16.86% done, finished in
1:13 at Thu Aug 24 03:17:28 2006
sendbackup: time 1202.285: 93: normal(|): DUMP: 22.56% done, finished in
1:08 at Thu Aug 24 03:17:10 2006
sendbackup: time 1502.290: 93: normal(|): DUMP: 28.54% done, finished in
1:02 at Thu Aug 24 03:16:07 2006
sendbackup: time 1802.283: 93: normal(|): DUMP: 34.17% done, finished in
0:57 at Thu Aug 24 03:16:20 2006
sendbackup: time 2102.284: 93: normal(|): DUMP: 39.05% done, finished in
0:54 at Thu Aug 24 03:18:09 2006
sendbackup: time 2402.293: 93: normal(|): DUMP: 44.47% done, finished in
0:49 at Thu Aug 24 03:18:28 2006
sendbackup: time 2702.282: 93: normal(|): DUMP: 49.93% done, finished in
0:45 at Thu Aug 24 03:18:39 2006
sendbackup: time 3002.282: 93: normal(|): DUMP: 55.30% done, finished in
0:40 at Thu Aug 24 03:18:57 2006
sendbackup: time 3302.282: 93: normal(|): DUMP: 59.90% done, finished in
0:36 at Thu Aug 24 03:20:21 2006
sendbackup: time 3602.284: 93: normal(|): DUMP: 63.92% done, finished in
0:33 at Thu Aug 24 03:22:23 2006
sendbackup: time 3902.281: 93: normal(|): DUMP: 68.38% done, finished in
0:30 at Thu Aug 24 03:23:35 2006
sendbackup: time 4202.287: 93: normal(|): DUMP: 72.81% done, finished in
0:26 at Thu Aug 24 03:24:40 2006
sendbackup: time 4502.281: 93: normal(|): DUMP: 76.80% done, finished in
0:22 at Thu Aug 24 03:26:11 2006
sendbackup: time 4802.378: 93: normal(|): DUMP: 80.26% done, finished in
0:19 at Thu Aug 24 03:28:12 2006
sendbackup: time 5102.311: 93: normal(|): DUMP: 84.16% done, finished in
0:15 at Thu Aug 24 03:29:31 2006
sendbackup: time 5402.289: 93: normal(|): DUMP: 87.76% done, finished in
0:12 at Thu Aug 24 03:31:05 2006
sendbackup: time 5702.281: 93: normal(|): DUMP: 91.87% done, finished in
0:08 at Thu Aug 24 03:31:56 2006
sendbackup: time 6002.280: 93: normal(|): DUMP: 96.28% done, finished in
0:03 at Thu Aug 24 03:32:23 2006
sendbackup: time 6268.139: index tee cannot write [Broken pipe]
sendbackup: time 6268.139: pid 36026 finish time Thu Aug 24 03:32:57 2006
sendbackup: time 6268.139: 117: strange(?): sendbackup: index tee cannot write
[Broken pipe]
sendbackup: time 6268.140: 93: normal(|): DUMP: Broken pipe
-------- sendbackup debug --------
--
Toomas Aas
|
