Perhaps the root of the problems I'm having, perhaps not.
I keep saying "I'm done with this" and then I go back and correlate
more server/client logs.
This is my latest finding.
While backups seem to be mostly working (even though I'm having some
amrecover issues in another thread), I have not seen anyone comment on
the insane amount of errors in amdump about "partial result":
[devel2]/var/log/amanda # grep "partial result" amdump.1 | wc -l
2468
Lines look basically like this, both for tar AND dump, and on EVERY
client:
planner: time 20.742: got partial result for host h16.biglist.com disk
/usr/local: 0 -> 130180K, 1 -> 68K, -1 -> -2K
planner: time 20.742: got partial result for host h16.biglist.com disk
/home: 0 -> 65074K, 2 -> 44K, -1 -> -2K
planner: time 20.742: got partial result for host h16.biglist.com disk
/: 0 -> 45968K, 1 -> 66K, -1 -> -2K
planner: time 20.815: got partial result for host h20.biglist.com disk
/var/qmail/bin: 0 -> -2K, 1 -> -2K, -1 -> -2K
And then on a client when it's sending the size estimate:
root@h07[/tmp/amanda/client/DailySet1]# grep "seek failed"
sendsize.20070409* | wc -l
13
And both for gtar and dump types:
dump_calc_estimates: warning - seek failed: Illegal seek
gnutar_calc_estimates: warning - seek failed: Illegal seek
And the errors in context:
(dump)
sendsize: debug 1 pid 56571 ruid 2 euid 2: rename at Mon Apr 9
03:10:02 2007
sendsize[56571]: time 0.014: waiting for any estimate child: 1 running
sendsize[56573]: time 0.014: calculating for amname /, dirname /,
spindle -1
sendsize[56573]: time 0.015: getting size via dump for / level 0
sendsize[56573]: time 0.015: calculating for device /dev/da0s1a with ufs
sendsize[56573]: time 0.016: running "/sbin/dump 0Shsf 0 1048576 -
/dev/da0s1a"
sendsize[56573]: time 0.017: running /usr/local/libexec/amanda/killpgrp
sendsize[56573]: time 0.022: DUMP: Date of this level 0 dump: Mon
Apr 9 03:10:02 2007
sendsize[56573]: time 0.023: DUMP: Date of last level 0 dump: the epoch
sendsize[56573]: time 0.024: DUMP: Dumping /dev/da0s1a (/) to
standard output
sendsize[56573]: time 0.077: DUMP: mapping (Pass I) [regular files]
sendsize[56573]: time 0.648: DUMP: mapping (Pass II) [directories]
sendsize[56573]: time 0.649: DUMP: estimated 43991 tape blocks.
sendsize[56573]: time 0.650: .....
sendsize[56573]: estimate time for / level 0: 0.633
sendsize[56573]: estimate size for / level 0: 43991 KB
sendsize[56573]: time 0.650: asking killpgrp to terminate
dump_calc_estimates: warning - seek failed: Illegal seek
--> Do we start over here??
sendsize[56573]: time 1.660: getting size via dump for / level 1
sendsize[56573]: time 1.660: calculating for device /dev/da0s1a with ufs
sendsize[56573]: time 1.660: running "/sbin/dump 1Shsf 0 1048576 -
/dev/da0s1a"
sendsize[56573]: time 1.661: running /usr/local/libexec/amanda/killpgrp
sendsize[56573]: time 1.667: DUMP: Date of this level 1 dump: Mon
Apr 9 03:10:04 2007
sendsize[56573]: time 1.668: DUMP: Date of last level 0 dump: Sat
Apr 7 04:03:16 2007
sendsize[56573]: time 1.668: DUMP: Dumping /dev/da0s1a (/) to
standard output
sendsize[56573]: time 1.710: DUMP: mapping (Pass I) [regular files]
sendsize[56573]: time 2.204: DUMP: mapping (Pass II) [directories]
sendsize[56573]: time 2.347: DUMP: estimated 76 tape blocks.
sendsize[56573]: time 2.347: .....
sendsize[56573]: estimate time for / level 1: 0.686
sendsize[56573]: estimate size for / level 1: 76 KB
sendsize[56573]: time 2.347: asking killpgrp to terminate
dump_calc_estimates: warning - seek failed: Illegal seek
sendsize[56573]: time 3.350: done with amname / dirname / spindle -1
sendsize[56571]: time 3.351: child 56573 terminated normally
sendsize[56571]: time 3.352: waiting for any estimate child: 1 running
(gtar)
sendsize[56571]: time 13.583: waiting for any estimate child: 1 running
sendsize[56623]: time 13.583: calculating for amname /var/db/pkg,
dirname /var/db/pkg, spindle -1
sendsize[56623]: time 13.583: getting size via gnutar for /var/db/pkg
level 0
sendsize[56623]: time 13.585: spawning
/usr/local/libexec/amanda/runtar in pipeline
sendsize[56623]: argument list: runtar DailySet1 /usr/local/bin/gtar
--create --
file /dev/null --directory /var/db/pkg --one-file-system
--listed-incremental
/usr/local/var/amanda/gnutar-lists/h07.biglist.com_var_db_pkg_0.new
--sparse --ignore-failed-read --totals .
sendsize[56623]: time 13.675: Total bytes written: 2816000 (2.7MiB,
117MiB/s)
sendsize[56623]: time 13.676: .....
sendsize[56623]: estimate time for /var/db/pkg level 0: 0.091
sendsize[56623]: estimate size for /var/db/pkg level 0: 2750 KB
sendsize[56623]: time 13.676: waiting for runtar "/var/db/pkg" child
sendsize[56623]: time 13.677: after runtar /var/db/pkg wait
gnutar_calc_estimates: warning - seek failed: Illegal seek
--> Again, looks like we repeat
sendsize[56623]: time 13.678: getting size via gnutar for /var/db/pkg
level 1
sendsize[56623]: time 13.679: spawning
/usr/local/libexec/amanda/runtar in pipeline
sendsize[56623]: argument list: runtar DailySet1 /usr/local/bin/gtar
--create --file /dev/null --directory /var/db/pkg --one-file-system
--listed-incremental
/usr/local/var/amanda/gnutar-lists/h07.biglist.com_var_db_pkg_1.new
--sparse --ignore-failed-read --totals .
sendsize[56623]: time 13.759: Total bytes written: 71680 (70KiB,
5.3MiB/s)
sendsize[56623]: time 13.760: .....
sendsize[56623]: estimate time for /var/db/pkg level 1: 0.080
sendsize[56623]: estimate size for /var/db/pkg level 1: 70 KB
sendsize[56623]: time 13.760: waiting for runtar "/var/db/pkg" child
sendsize[56623]: time 13.761: after runtar /var/db/pkg wait
gnutar_calc_estimates: warning - seek failed: Illegal seek
sendsize[56623]: time 13.761: getting size via gnutar for /var/db/pkg
level 2
sendsize[56623]: time 13.763: spawning
/usr/local/libexec/amanda/runtar in pipeline
sendsize[56623]: argument list: runtar DailySet1 /usr/local/bin/gtar
--create --file /dev/null --directory /var/db/pkg --one-file-system
--listed-incremental
/usr/local/var/amanda/gnutar-lists/h07.biglist.com_var_db_pkg_2.new
--sparse --ignore-failed-read --totals .
sendsize[56623]: time 13.843: Total bytes written: 71680 (70KiB,
5.3MiB/s)
sendsize[56623]: time 13.844: .....
sendsize[56623]: estimate time for /var/db/pkg level 2: 0.081
sendsize[56623]: estimate size for /var/db/pkg level 2: 70 KB
sendsize[56623]: time 13.844: waiting for runtar "/var/db/pkg" child
sendsize[56623]: time 13.845: after runtar /var/db/pkg wait
gnutar_calc_estimates: warning - seek failed: Illegal seek
sendsize[56623]: time 13.846: done with amname /var/db/pkg dirname
/var/db/pkg spindle -1
sendsize[56571]: time 13.846: child 56623 terminated normally
sendsize[56571]: time 13.847: waiting for any estimate child: 1 running
Am I correct in assuming these sendsize problems are causing the
"partial result" messages in the amdump log?
If so, I wonder if I'm really getting proper size estimates into
amanda...
Any thoughts?
Thanks,
Charles
