Jean-Louis Martineau wrote:
> Tom Robinson wrote:
>> DUMPER
>> STATS TAPER STATS HOSTNAME
>> DISK L ORIG-KB OUT-KB COMP% MMM:SS KB/s
>> MMM:SS KB/s
>> ------------------------------------
>> ------------------------------------------ ---------------
>> host /disk 1 2031690 4063380 200.0
>> 36:34 1852.3 6:27 10487.2
>>
>>
>> Note the ORIG-KB blows out to twice the size! COMP% is 200.0...
>>
> ORIG-KB is the size reported by the dump program, it report a number of
> blocks, but all dump doesn't have the same blocksize.
> Can you post the sendsize.*.debug and sendbackup.*.debug files from the
> client and answer the following questions?
> amanda version on the client?
> Os of the client?
> Filesystem?
> dump program?
> dump version?
>
>
Client:
amanda: 2.4.4p3
OS: CentOS 4.7
filesystem: ext3
dump prog-ver: dump-0.4b39 (2 disks)
dump prog-ver: tar-1.14 (1 disk)
For ease of debugging full names are restored:
DUMPER STATS
TAPER STATS
HOSTNAME DISK L ORIG-KB OUT-KB COMP% MMM:SS KB/s
MMM:SS KB/s
------------------------------------ ------------------------------------------
---------------
rook /dev/mapper/vg-root 1 2031690 4063380 200.0 36:34 1852.3
6:27 10487.2
rook /dev/sda1 0 2010 4020 200.0 0:06 634.9
0:01 3247.0
rook /etc 0 11200 2900 25.9 0:21 137.6
0:01 4732.5
DLE:
rook /etc comp-root-tar
rook /dev/sda1 nocomp-root
rook /dev/mapper/vg-root nocomp-root
-----------------
sendsize: debug 1 pid 2434 ruid 33 euid 33: start at Wed Jan 21 21:45:28 2009
sendsize: version 2.4.4p3
sendsize[2436]: time 0.101: calculating for amname '/etc', dirname '/etc',
spindle -1
sendsize[2436]: time 0.101: getting size via gnutar for /etc level 0
sendsize[2434]: time 0.101: waiting for any estimate child: 1 running
sendsize[2436]: time 0.119: spawning /usr/lib/amanda/runtar in pipeline
sendsize[2436]: argument list: /bin/tar --create --file /dev/null --directory
/etc --one-file-system --listed-incremental
/var/lib/amanda/gnutar-lists/rook_etc_0.new --sparse --ignore-failed-read
--totals .
sendsize[2436]: time 5.762: Total bytes written: 11468800 (11MiB, 2.2MiB/s)
sendsize[2436]: time 5.762: .....
sendsize[2436]: estimate time for /etc level 0: 5.643
sendsize[2436]: estimate size for /etc level 0: 11200 KB
sendsize[2436]: time 5.762: waiting for /bin/tar "/etc" child
sendsize[2436]: time 5.763: after /bin/tar "/etc" wait
sendsize[2436]: time 5.763: getting size via gnutar for /etc level 1
sendsize[2436]: time 5.803: spawning /usr/lib/amanda/runtar in pipeline
sendsize[2436]: argument list: /bin/tar --create --file /dev/null --directory
/etc --one-file-system --listed-incremental
/var/lib/amanda/gnutar-lists/rook_etc_1.new --sparse --ignore-failed-read
--totals .
sendsize[2436]: time 5.828: Total bytes written: 296960 (290KiB, ?/s)
sendsize[2436]: time 5.829: .....
sendsize[2436]: estimate time for /etc level 1: 0.025
sendsize[2436]: estimate size for /etc level 1: 290 KB
sendsize[2436]: time 5.829: waiting for /bin/tar "/etc" child
sendsize[2436]: time 5.829: after /bin/tar "/etc" wait
sendsize[2436]: time 5.829: done with amname '/etc', dirname '/etc', spindle -1
sendsize[2434]: time 5.830: child 2436 terminated normally
sendsize[2440]: time 5.830: calculating for amname '/dev/sda1', dirname
'/boot', spindle -1
sendsize[2440]: time 5.830: getting size via dump for /dev/sda1 level 0
sendsize[2440]: time 5.831: calculating for device '/dev/sda1' with 'ext3'
sendsize[2440]: time 5.831: running "/sbin/dump 0Ssf 1048576 - /dev/sda1"
sendsize[2440]: time 5.832: running /usr/lib/amanda/killpgrp
sendsize[2434]: time 5.832: waiting for any estimate child: 1 running
sendsize[2440]: time 7.831: 4077568
sendsize[2440]: time 7.832: .....
sendsize[2440]: estimate time for /dev/sda1 level 0: 2.001
sendsize[2440]: estimate size for /dev/sda1 level 0: 3982 KB
sendsize[2440]: time 7.832: asking killpgrp to terminate
sendsize[2440]: time 8.835: getting size via dump for /dev/sda1 level 1
sendsize[2440]: time 8.836: calculating for device '/dev/sda1' with 'ext3'
sendsize[2440]: time 8.836: running "/sbin/dump 1Ssf 1048576 - /dev/sda1"
sendsize[2440]: time 8.839: running /usr/lib/amanda/killpgrp
sendsize[2440]: time 8.888: 21504
sendsize[2440]: time 8.889: .....
sendsize[2440]: estimate time for /dev/sda1 level 1: 0.053
sendsize[2440]: estimate size for /dev/sda1 level 1: 21 KB
sendsize[2440]: time 8.889: asking killpgrp to terminate
sendsize[2440]: time 9.896: done with amname '/dev/sda1', dirname '/boot',
spindle -1
sendsize[2434]: time 9.896: child 2440 terminated normally
sendsize[2445]: time 9.897: calculating for amname '/dev/mapper/vg-root',
dirname '/', spindle -1
sendsize[2445]: time 9.897: getting size via dump for /dev/mapper/vg-root level 0
sendsize[2445]: time 9.898: calculating for device '/dev/mapper/vg-root' with
'ext3'
sendsize[2445]: time 9.898: running "/sbin/dump 0Ssf 1048576 -
/dev/mapper/vg-root"
sendsize[2445]: time 9.901: running /usr/lib/amanda/killpgrp
sendsize[2434]: time 9.904: waiting for any estimate child: 1 running
sendsize[2445]: time 866.903: 154051642368
sendsize[2445]: time 867.357: .....
sendsize[2445]: estimate time for /dev/mapper/vg-root level 0: 857.459
sendsize[2445]: estimate size for /dev/mapper/vg-root level 0: 150441057 KB
sendsize[2445]: time 867.357: asking killpgrp to terminate
sendsize[2445]: time 868.364: getting size via dump for /dev/mapper/vg-root
level 1
sendsize[2445]: time 868.649: calculating for device '/dev/mapper/vg-root' with
'ext3'
sendsize[2445]: time 868.649: running "/sbin/dump 1Ssf 1048576 -
/dev/mapper/vg-root"
sendsize[2445]: time 868.650: running /usr/lib/amanda/killpgrp
sendsize[2445]: time 1420.013: 4162008064
sendsize[2445]: time 1420.026: .....
sendsize[2445]: estimate time for /dev/mapper/vg-root level 1: 551.376
sendsize[2445]: estimate size for /dev/mapper/vg-root level 1: 4064461 KB
sendsize[2445]: time 1420.026: asking killpgrp to terminate
sendsize[2445]: time 1421.030: done with amname '/dev/mapper/vg-root', dirname
'/', spindle -1
sendsize[2434]: time 1421.031: child 2445 terminated normally
sendsize: time 1421.031: pid 2434 finish time Wed Jan 21 22:09:09 2009
-----------------
sendbackup: debug 1 pid 2598 ruid 33 euid 33: start at Wed Jan 21 22:09:25 2009
/usr/lib/amanda/sendbackup: version 2.4.4p3
parsed request as: program `GNUTAR'
disk `/etc'
device `/etc'
level 0
since 1970:1:1:0:0:0
options `|;auth=BSD;compress-fast;index;'
sendbackup: try_socksize: send buffer size is 65536
sendbackup: time 0.000: stream_server: waiting for connection: 0.0.0.0.34496
sendbackup: time 0.000: stream_server: waiting for connection: 0.0.0.0.34497
sendbackup: time 0.000: stream_server: waiting for connection: 0.0.0.0.34498
sendbackup: time 0.000: waiting for connect on 34496, then 34497, then 34498
sendbackup: time 0.006: stream_accept: connection from 192.168.0.31.11002
sendbackup: time 0.011: stream_accept: connection from 192.168.0.31.11002
sendbackup: time 0.017: stream_accept: connection from 192.168.0.31.11002
sendbackup: time 0.017: got all connections
sendbackup: time 0.017: spawning /bin/gzip in pipeline
sendbackup: argument list: /bin/gzip --fast
sendbackup-gnutar: time 0.018: pid 2600: /bin/gzip --fast
sendbackup-gnutar: time 0.037: doing level 0 dump as listed-incremental to
/var/lib/amanda/gnutar-lists/rook_etc_0.new
sendbackup-gnutar: time 0.219: doing level 0 dump from date: 1970-01-01
0:00:00 GMT
sendbackup: time 0.222: started index creator: "/bin/tar -tf - 2>/dev/null |
sed -e 's/^\.//'"
sendbackup: time 0.223: spawning /usr/lib/amanda/runtar in pipeline
sendbackup: argument list: gtar --create --file - --directory /etc
--one-file-system --listed-incremental
/var/lib/amanda/gnutar-lists/rook_etc_0.new --sparse --ignore-failed-read
--totals .
sendbackup-gnutar: time 0.223: /usr/lib/amanda/runtar: pid 2603
sendbackup: time 21.026: index created successfully
sendbackup: time 21.086: 53: size(|): Total bytes written: 11468800 (11MiB,
560KiB/s)
sendbackup: time 21.088: pid 2598 finish time Wed Jan 21 22:09:46 2009
-----------------
sendbackup: debug 1 pid 2607 ruid 33 euid 33: start at Wed Jan 21 22:09:46 2009
/usr/lib/amanda/sendbackup: version 2.4.4p3
parsed request as: program `DUMP'
disk `/dev/sda1'
device `/dev/sda1'
level 0
since 1970:1:1:0:0:0
options `|;auth=BSD;index;'
sendbackup: try_socksize: send buffer size is 65536
sendbackup: time 0.001: stream_server: waiting for connection: 0.0.0.0.34499
sendbackup: time 0.001: stream_server: waiting for connection: 0.0.0.0.34500
sendbackup: time 0.001: stream_server: waiting for connection: 0.0.0.0.34501
sendbackup: time 0.001: waiting for connect on 34499, then 34500, then 34501
sendbackup: time 0.006: stream_accept: connection from 192.168.0.31.11002
sendbackup: time 0.011: stream_accept: connection from 192.168.0.31.11002
sendbackup: time 0.016: stream_accept: connection from 192.168.0.31.11002
sendbackup: time 0.016: got all connections
sendbackup: time 0.017: dumping device '/dev/sda1' with 'ext3'
sendbackup: time 0.022: 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.023: spawning /sbin/dump in pipeline
sendbackup: argument list: dump 0usf 1048576 - /dev/sda1
sendbackup: time 0.086: 93: normal(|): DUMP: Date of this level 0 dump: Wed
Jan 21 22:09:46 2009
sendbackup: time 0.087: 93: normal(|): DUMP: Dumping /dev/sda1 (/boot) to
standard output
sendbackup: time 0.527: 93: normal(|): DUMP: Label: /boot
sendbackup: time 0.528: 93: normal(|): DUMP: Writing 10 Kilobyte records
sendbackup: time 0.528: 93: normal(|): DUMP: mapping (Pass I) [regular
files]
sendbackup: time 3.889: 93: normal(|): DUMP: mapping (Pass II) [directories]
sendbackup: time 3.890: 93: normal(|): DUMP: estimated 3982 blocks.
sendbackup: time 3.892: 93: normal(|): DUMP: Volume 1 started with block 1
at: Wed Jan 21 22:09:50 2009
sendbackup: time 3.893: 93: normal(|): DUMP: dumping (Pass III)
[directories]
sendbackup: time 4.067: 93: normal(|): DUMP: dumping (Pass IV) [regular
files]
sendbackup: time 6.343: 93: normal(|): DUMP: Volume 1 completed at: Wed Jan
21 22:09:53 2009
sendbackup: time 6.344: 93: normal(|): DUMP: Volume 1 4020 blocks (3.93MB)
sendbackup: time 6.344: 93: normal(|): DUMP: Volume 1 took 0:00:03
sendbackup: time 6.345: index created successfully
sendbackup: time 6.344: 93: normal(|): DUMP: Volume 1 transfer rate: 1340
kB/s
sendbackup: time 6.346: 62: size(|): DUMP: 4020 blocks (3.93MB)
sendbackup: time 6.346: 93: normal(|): DUMP: finished in 2 seconds,
throughput 2010 kBytes/sec
sendbackup: time 6.346: 93: normal(|): DUMP: Date of this level 0 dump: Wed
Jan 21 22:09:46 2009
sendbackup: time 6.347: 93: normal(|): DUMP: Date this dump completed: Wed
Jan 21 22:09:53 2009
sendbackup: time 6.347: 93: normal(|): DUMP: Average transfer rate: 1340
kB/s
sendbackup: time 6.347: 93: normal(|): DUMP: DUMP IS DONE
sendbackup: time 6.347: pid 2607 finish time Wed Jan 21 22:09:53 2009
-----------------
sendbackup: debug 1 pid 2622 ruid 33 euid 33: start at Wed Jan 21 22:10:05 2009
/usr/lib/amanda/sendbackup: version 2.4.4p3
parsed request as: program `DUMP'
disk `/dev/mapper/vg-root'
device `/dev/mapper/vg-root'
level 1
since 2009:1:16:11:6:1
options `|;auth=BSD;index;'
sendbackup: try_socksize: send buffer size is 65536
sendbackup: time 0.001: stream_server: waiting for connection: 0.0.0.0.34502
sendbackup: time 0.001: stream_server: waiting for connection: 0.0.0.0.34503
sendbackup: time 0.001: stream_server: waiting for connection: 0.0.0.0.34504
sendbackup: time 0.001: waiting for connect on 34502, then 34503, then 34504
sendbackup: time 0.006: stream_accept: connection from 192.168.0.31.11002
sendbackup: time 0.011: stream_accept: connection from 192.168.0.31.11002
sendbackup: time 0.016: stream_accept: connection from 192.168.0.31.11002
sendbackup: time 0.016: got all connections
sendbackup: time 0.017: dumping device '/dev/mapper/vg-root' with 'ext3'
sendbackup: time 0.024: 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.024: spawning /sbin/dump in pipeline
sendbackup: argument list: dump 1usf 1048576 - /dev/mapper/vg-root
sendbackup: time 0.028: 93: normal(|): DUMP: Date of this level 1 dump: Wed
Jan 21 22:10:05 2009
sendbackup: time 0.028: 93: normal(|): DUMP: Date of last level 0 dump: Fri
Jan 16 22:06:22 2009
sendbackup: time 0.028: 93: normal(|): DUMP: Dumping /dev/mapper/vg-root
(/) to standard output
sendbackup: time 0.539: 93: normal(|): DUMP: Label: none
sendbackup: time 0.540: 93: normal(|): DUMP: Writing 10 Kilobyte records
sendbackup: time 0.540: 93: normal(|): DUMP: mapping (Pass I) [regular
files]
sendbackup: time 733.790: 93: normal(|): DUMP: mapping (Pass II)
[directories]
sendbackup: time 1319.118: 93: normal(|): DUMP: estimated 4064500 blocks.
sendbackup: time 1319.152: 93: normal(|): DUMP: Volume 1 started with block
1 at: Wed Jan 21 22:32:04 2009
sendbackup: time 1319.395: 93: normal(|): DUMP: dumping (Pass III)
[directories]
sendbackup: time 1343.315: 93: normal(|): DUMP: dumping (Pass IV) [regular
files]
sendbackup: time 1618.756: 93: normal(|): DUMP: 34.14% done at 4625 kB/s,
finished in 0:09
sendbackup: time 1918.649: 93: normal(|): DUMP: 67.31% done at 4559 kB/s,
finished in 0:04
sendbackup: time 2193.149: 93: normal(|): DUMP: Volume 1 completed at: Wed
Jan 21 22:46:38 2009
sendbackup: time 2193.228: 93: normal(|): DUMP: Volume 1 4063380 blocks
(3968.14MB)
sendbackup: time 2193.228: 93: normal(|): DUMP: Volume 1 took 0:14:34
sendbackup: time 2193.229: 93: normal(|): DUMP: Volume 1 transfer rate:
4649 kB/s
sendbackup: time 2193.240: index created successfully
sendbackup: time 2193.407: 62: size(|): DUMP: 4063380 blocks (3968.14MB)
sendbackup: time 2193.408: 93: normal(|): DUMP: finished in 874 seconds,
throughput 4649 kBytes/sec
sendbackup: time 2193.408: 93: normal(|): DUMP: Date of this level 1 dump:
Wed Jan 21 22:10:05 2009
sendbackup: time 2193.409: 93: normal(|): DUMP: Date this dump completed:
Wed Jan 21 22:46:38 2009
sendbackup: time 2193.409: 93: normal(|): DUMP: Average transfer rate: 4649
kB/s
sendbackup: time 2193.409: 93: normal(|): DUMP: DUMP IS DONE
sendbackup: time 2193.409: pid 2622 finish time Wed Jan 21 22:46:38 2009
-----------------
|
