Hi,

Both client and server are at 3.3.0

I now see this all the time on this particular server-client: amanda
schedules, say an incremental level 1 (a few mbs usually) for a DLE
and when the chunker seems to have all done it's job, it just stands
there doing nothing, for hours sometimes, before it completes. I have
DLEs of a few GBs that complete faster than a 50MB one...

Suffice to say, this completely disrupts the backups. The amanda runs
now take more than 2 days to complete (51 DLEs in total) :(

Any help welcomed.
Thanks,
jf

Here are a few logfiles. I can provide more info if needed.

---
amstatus:  

gustav:/raid/dagher3   1        52m dumping 52m ( 99.97%) (15:23:32)

---
amdump logfile shows:

pondering gustav:/raid/dagher3... next_level0 6 last_level 1 (not due
for a full dump, picking an incr level)
  gustav /raid/dagher3 pri 2 lev 1 nsize 54160 csize 54160
DUMP gustav ffffffff9efefbffffffffff0f /raid/dagher3 20111127201101 2
1 2011:11:24:1:11:1 54160 54160 143 378 "Skipping: a full is not
planned, so can't dump in degraded mode"
driver: send-cmd time 69151.276 to chunker1: PORT-WRITE 00-00070
/holddisk/top/20111127201101/gustav._raid_dagher3.1 gustav
ffffffff9efefbffffffffff0f /raid/dagher3 1 2011:11:24:1:11:1
9007199254740896 APPLICATION 54240 |;auth=BSDTCP;index;
driver: send-cmd time 69151.282 to dumper1: PORT-DUMP 00-00070 36699
gustav ffffffff9efefbffffffffff0f /raid/dagher3 NODEVICE 1
2011:11:24:1:11:1 amgtar "" "" "" "" BSDTCP AMANDA 127.0.0.1:36700 |"
<auth>BSDTCP</auth>\n  <record>YES</record>\n  <index>YES</index>\n
<datapath>AMANDA</datapath>\n  <backup-program>\n
<plugin>amgtar</plugin>\n    <property>\n      <name>ignore</name>\n
<value encoding=\"raw\"
raw=\"OiBEaXJlY3RvcnkgaXMgbmV3JA==\">:_Directory_is_new$</value>\n
<value encoding=\"raw\"
raw=\"OiBEaXJlY3RvcnkgaGFzIGJlZW4gcmVuYW1lZA==\">:_Directory_has_been_renamed</value>\n
<value encoding=\"raw\"
raw=\"OiBmaWxlIGNoYW5nZWQgYXMgd2UgcmVhZCBpdCQ=\">:_file_changed_as_we_read_it$</value>\n
<value encoding=\"raw\"
raw=\"OiBzb2NrZXQgaWdub3JlZCQ=\">:_socket_ignored$</value>\n
<value encoding=\"raw\"
raw=\"OiBDYW5ub3Qgc3RhdDogTm8gc3VjaCBmaWxlIG9yIGRpcmVjdG9yeSQ=\">:_Cannot_stat:_No_such_file_or_directory$</value>\n
</property>\n    <property>\n      <name>check-device</name>\n
<value>NO</value>\n    </property>\n  </backup-program>\n"
driver: state time 69151.282 free kps: 1023574 space: 3896191960
taper: idle idle-dumpers: 9 qlen tapeq: 1 runq: 16 roomq: 0 wakeup: 0
driver-idle: no-dumpers
driver: interface-state time 69151.282 if default: free 1023574
driver: hdisk-state time 69151.282 hdisk 0: free 3896191960 dumpers 3

---
chunker debug file: chunker.20111128152332.debug

/var/tmp/amanda/server/top/chunker.20111128152332.debug:Mon Nov 28
15:23:32 2011: chunker: getcmd: PORT-WRITE 00-00070
/holddisk/top/20111127201101/gustav._raid_dagher3.1 gustav
ffffffff9efefbffffffffff0f /raid/dagher3 1 2011:11:24:1:11:1
9007199254740896 APPLICATION 54240 |;auth=BSDTCP;index;
/var/tmp/amanda/server/top/chunker.20111128152332.debug:Mon Nov 28
15:23:32 2011: chunker: Building type FILE header of 32768-32768 bytes
with name='gustav' disk='/raid/dagher3' dumplevel=1 and
blocksize=32768

---
client amandad debug file: amandad.20111128152755.debug

[...]

Mon Nov 28 15:27:55 2011: amandad: sending ACK pkt:
<<<<<
>>>>>
Mon Nov 28 15:27:55 2011: amandad: tcpm_send_token: data is still
flowing
Mon Nov 28 15:27:55 2011: amandad:
security_streaminit(stream=0x235cd00, driver=0x7f1440cfe380 (BSDTCP))
Mon Nov 28 15:27:55 2011: amandad:
security_streaminit(stream=0x2364d60, driver=0x7f1440cfe380 (BSDTCP))
Mon Nov 28 15:27:55 2011: amandad:
security_streaminit(stream=0x236cdc0, driver=0x7f1440cfe380 (BSDTCP))
Mon Nov 28 15:27:55 2011: amandad: sending REP pkt:
<<<<<
CONNECT DATA 499999 MESG 499998 INDEX 499997
OPTIONS features=ffffffff9efefbffffffffff0f;
>>>>>
Mon Nov 28 15:27:55 2011: amandad: received ACK pkt:
<<<<<
>>>>>
Mon Nov 28 15:27:55 2011: amandad: opening security stream for fd 50
Mon Nov 28 15:27:55 2011: amandad: opening security stream for fd 51
Mon Nov 28 15:27:55 2011: amandad: opening security stream for fd 52
Mon Nov 28 15:27:55 2011: amandad: security_close(handle=0x23438c0,
driver=0x7f1440cfe380 (BSDTCP))
Mon Nov 28 15:27:55 2011: amandad: security_stream_close(0x2343a90)
Mon Nov 28 15:31:00 2011: amandad: tcpm_send_token: data is still
flowing

Reply via email to