Amanda-Users

more of the dreaded 'missing size line from sendbackup'

2008-01-17 14:44:36
Subject: more of the dreaded 'missing size line from sendbackup'
From: Jean-Francois Malouin <Jean-Francois.Malouin AT bic.mni.mcgill DOT ca>
To: AMANDA users <amanda-users AT amanda DOT org>
Date: Thu, 17 Jan 2008 14:33:58 -0500
Hello again,

Yet another case of the driver reporting 'missing size line from
sendbackup' just before the DLE (~1TB) was entirely in the holddisk...

Here's what the server (2.5.2p1) logs show: 

log:

FAIL dumper yorick /data/nih/nih1 20080116 0 [missing size line from sendbackup]
  sendbackup: start [yorick:/data/nih/nih1 level 0]
  sendbackup: info BACKUP=/usr/freeware/bin/tar
  sendbackup: info RECOVER_CMD=/usr/freeware/bin/tar -xpGf - ...
  sendbackup: info end
  ? dumper: strange [missing size line from sendbackup]
PARTIAL chunker yorick /data/nih/nih1 20080116 0 [sec 49050.184 kb 933151530 
kps 19024.4]

amdump:

driver: state time 50745.505 free kps: 1003626 space: 979020896 taper: idle 
idle-dumpers: 11 qlen tapeq: 0 run q: 0 roomq: 0 wakeup: 0 driver-idle: 
no-dumpers
driver: interface-state time 50745.505 if default: free 1002226 if local: free 
1000 if le0: free 400
driver: hdisk-state time 50745.505 hdisk 0: free 979020896 dumpers 1
driver: result time 50745.522 from dumper1: FAILED 01-00002 "[missing size line 
from sendbackup]"
driver: send-cmd time 50745.522 to chunker1: FAILED 01-00002
driver: state time 50745.522 free kps: 1003626 space: 979020896 
taper: idle idle-dumpers: 11 qlen tapeq: 0 runq: 0 roomq: 0 wakeup: 0 
driver-idle: no-dumpers
driver: interface-state time 50745.522 if default: free 1002226 if local: free 
1000 if le0: free 400
driver: hdisk-state time 50745.522 hdisk 0: free 979020896 dumpers 1
driver: result time 50745.522 from chunker1: PARTIAL 01-00002 933151530 "[sec 
49050.184 kb 933151530 kps 19024.4]"
driver: finished-cmd time 50745.522 chunker1 chunked yorick:/data/nih/nih1

On the client (2.5.2p1), the amandad/sendbackup/runtar debug files:

amandad.20080116223817.debug:

amandad: time 49049.651: security_stream_seterr(1003ca70, write error to :
Resource temporarily unavailable)
amandad: time 49049.663: sending NAK pkt:
<<<<<
ERROR write error on stream 499999: write error to : Resource temporarily
unavailable
>>>>>

sendbackup.20080116223817.debug:

sendbackup-gnutar: time 724.655: /opt/amanda/av24-2/libexec/runtar: pid 7955181
sendbackup: time 724.656: started backup
sendbackup: time 49049.606: index tee cannot write [Broken pipe]
sendbackup: time 49049.616: pid 7963340 finish time Thu Jan 17 12:15:46 2008


runtar.20080116225021.debug:

runtar: debug 1 pid 7955181 ruid 666 euid 0: start at Wed Jan 16 22:50:21 2008
runtar: time 0.001: version 2.5.2p1
/usr/freeware/bin/tar version: tar (GNU tar) 1.13.25

config: left2
runtar: debug 1 pid 7955181 ruid 0 euid 0: rename at Wed Jan 16 22:50:21 2008
running: /usr/freeware/bin/tar: 'gtar' '--create' '--file' '-' '--directory'
'/data/nih/nih1' '--one-file-system' '--listed-incremental'
'/opt/amanda-av24-2/var/amanda/left2/gnutar-lists/yorick_data_nih_nih1_0.new'
'--sparse' '--ignore-failed-read' '--totals' '.' 
runtar: time 0.017: pid 7955181 finish time Wed Jan 16 22:50:21 2008


Looks like another goose chase to me...
Any ideas on how to debug and track this issue?

regards,
jf
-- 
<° ><

<Prev in Thread] Current Thread [Next in Thread>