Greetings;
A fair share of this box didn't get backed up last night, with a
relatively odd log.20060410etc ending stanza:
FATAL chunker error [bad command after RQ-MORE-DISK: "QUIT"]
INFO taper tape Dailys-17 kb 6425920 fm 31 [OK]
FAIL dumper coyote /tmp 20060410004501 1 [data write: Broken pipe]
sendbackup: start [coyote:/tmp level 1]
sendbackup: info BACKUP=/usr/local/bin/tar
sendbackup: info RECOVER_CMD=/usr/bin/gzip -dc |/usr/local/bin/tar -f... -
sendbackup: info COMPRESS_SUFFIX=.gz
sendbackup: info end
| gtar: ./.esd/socket: socket ignored
The (v)tape wasn't full.
In /tmp/amanda-dbg, from the last sendbackup file:
sendbackup: debug 1 pid 1145 ruid 33 euid 33: start at Mon Apr 10 02:31:57 2006
sendbackup: version 2.5.1b1-20060407
parsed request as: program `GNUTAR'
disk `/tmp'
device `/tmp'
level 1
since 2006:4:9:6:3:44
options `|;auth=BSD;compress-best;index;'
sendbackup: time 0.000: spawning /usr/bin/gzip in pipeline
sendbackup: argument list: /usr/bin/gzip --best
sendbackup-gnutar: time 0.001: pid 1147: /usr/bin/gzip --best
sendbackup-gnutar: time 0.019: doing level 1 dump as listed-incremental from
/usr/local/var/amanda/gnutar-lists/coyote_tmp_0 to
/usr/local/var/amanda/gnutar-lists/coyote_tmp_1.new
sendbackup-gnutar: time 0.396: doing level 1 dump from date: 2020-04-28
4:44:04 GMT
sendbackup: time 0.403: started index creator: "/usr/local/bin/tar -tf -
2>/dev/null | sed -e 's/^\.//'"
sendbackup: time 0.403: spawning /usr/local/libexec/runtar in pipeline
sendbackup: argument list: gtar --create --file - --directory /tmp
--one-file-system --listed-incremental
/usr/local/var/amanda/gnutar-lists/coyote_tmp_1.new --sparse
--ignore-failed-read --totals .
sendbackup-gnutar: time 0.405: /usr/local/libexec/runtar: pid 1153
sendbackup: time 0.405: started backup
sendbackup: time 0.795: 52: normal(|): gtar: ./.esd/socket: socket ignored
sendbackup: time 1.424: 117: strange(?):
sendbackup: time 1.424: 117: strange(?): gzip: stdout: Broken pipe
sendbackup: time 1.425: 117: strange(?): sendbackup: index tee cannot write
[Broken pipe]
sendbackup: time 1.425: index tee cannot write [Broken pipe]
sendbackup: time 1.425: pid 1149 finish time Mon Apr 10 02:31:58 2006
sendbackup: time 1.425: 46: size(|): Total bytes written: 1085440 (1.1MiB,
?/s)
sendbackup: time 1.426: 117: strange(?): gtar: -: Wrote only 4096 of 10240 bytes
sendbackup: time 1.442: 117: strange(?): gtar: Error is not recoverable:
exiting now
sendbackup: time 1.442: 117: strange(?): sed: Couldn't flush stdout: Broken pipe
sendbackup: time 1.443: error [compress returned 1, /usr/local/bin/tar returned
2]
sendbackup: time 1.443: pid 1145 finish time Mon Apr 10 02:31:58 2006
=================
This is from the latest 2.5.1b1-20060407 snapshot.
Now looking at the sendbackup.debug files in the listing order,
about the 6th one down contains this:
sendbackup: debug 1 pid 819 ruid 33 euid 33: start at Mon Apr 10 02:22:15 2006
sendbackup: version 2.5.1b1-20060407
parsed request as: program `DUMP'
disk `/home'
device `/home'
level 0
since 1970:1:1:0:0:0
options `|;auth=BSD;srvcomp-best;index;'
sendbackup: time 0.002: dumping device '/dev/hda6' with 'ext3'
sendbackup: time 0.003: 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.004: spawning /sbin/dump in pipeline
sendbackup: argument list: dump 0usf 1048576 - /dev/hda6
sendbackup: time 0.004: started backup
sendbackup: time 0.197: 86: normal(|): DUMP: Date of this level 0 dump: Mon
Apr 10 02:22:15 2006
sendbackup: time 0.198: 86: normal(|): DUMP: Dumping /dev/hda6 (/home) to
standard output
sendbackup: time 2.268: 86: normal(|): DUMP: Label: none
sendbackup: time 2.269: 86: normal(|): DUMP: Writing 10 Kilobyte records
sendbackup: time 2.270: 86: normal(|): DUMP: mapping (Pass I) [regular
files]
sendbackup: time 5.667: 86: normal(|): DUMP: mapping (Pass II) [directories]
sendbackup: time 5.667: 86: normal(|): DUMP: estimated 833278 blocks.
sendbackup: time 5.669: 86: normal(|): DUMP: Volume 1 started with block 1
at: Mon Apr 10 02:22:20 2006
sendbackup: time 5.675: 86: normal(|): DUMP: dumping (Pass III)
[directories]
sendbackup: time 14.143: 86: normal(|): DUMP: dumping (Pass IV) [regular
files]
sendbackup: time 281.612: 86: normal(|): DUMP: Volume 1 completed at: Mon
Apr 10 02:26:56 2006
sendbackup: time 281.692: index created successfully
sendbackup: time 281.706: 86: normal(|): DUMP: Volume 1 832930 blocks
(813.41MB)
sendbackup: time 281.706: 86: normal(|): DUMP: Volume 1 took 0:04:36
sendbackup: time 281.707: 86: normal(|): DUMP: Volume 1 transfer rate: 3017
kB/s
sendbackup: time 281.707: 55: size(|): DUMP: 832930 blocks (813.41MB)
sendbackup: time 281.707: 86: normal(|): DUMP: finished in 276 seconds,
throughput 3017 kBytes/sec
sendbackup: time 281.708: 86: normal(|): DUMP: Date of this level 0 dump:
Mon Apr 10 02:22:15 2006
sendbackup: time 281.708: 86: normal(|): DUMP: Date this dump completed:
Mon Apr 10 02:26:56 2006
sendbackup: time 281.709: 86: normal(|): DUMP: Average transfer rate: 3017
kB/s
sendbackup: time 281.709: 86: normal(|): DUMP: DUMP IS DONE
sendbackup: time 281.709: parsed backup messages
sendbackup: time 281.710: pid 819 finish time Mon Apr 10 02:26:56 2006
=========================
But I don't use DUMP!
So it appears 2.5.1b1-20060407 has developed alzheimers or something!
I'm going back to 2.5.0.
--
Cheers, Gene
People having trouble with vz bouncing email to me should add the word
'online' between the 'verizon', and the dot which bypasses vz's
stupid bounce rules. I do use spamassassin too. :-)
Yahoo.com and AOL/TW attorneys please note, additions to the above
message by Gene Heskett are:
Copyright 2006 by Maurice Eugene Heskett, all rights reserved.
|
