[Box Backup] Restart after connection error

Magnus Homann boxbackup@boxbackup.org
Tue, 12 Aug 2008 18:02:18 +0200


I havenät seen thsi before, but canät guarantee it hasn't happened either.

After a reboot bbstored and bbackupd starts. It then seems to fail at 
some point and bbackupd starts all over again. Here's a part of the 
daemon.log, I'm not sure if it is the interesting bit.

------------
Aug 12 17:36:31 crux bbackupd[6999]: Send 
ListDirectory(0x1261,0xffffffff,0xc,true)
Aug 12 17:36:32 crux bbstored[7063]: Receive 
ListDirectory(0x1261,0xffffffff,0xc,true)
Aug 12 17:36:32 crux bbstored[7063]: Receive 
ListDirectory(0x1261,0xffffffff,0xc,true)
Aug 12 17:36:32 crux bbstored[7063]: Send Success(0x1261)
Aug 12 17:36:32 crux bbstored[7063]: Send Success(0x1261)
Aug 12 17:36:32 crux bbstored[7063]: Sending stream, size 5114
Aug 12 17:36:32 crux bbackupd[6999]: Receive Success(0x1261)
Aug 12 17:36:32 crux bbackupd[6999]: Receiving stream, size 5114
Aug 12 17:36:32 crux bbackupd[6999]: Send 
GetBlockIndexByName(0x1261,"HomannElektronik.4DD")
Aug 12 17:36:32 crux bbstored[7063]: Receive 
GetBlockIndexByName(0x1261,OPAQUE)
Aug 12 17:36:32 crux bbstored[7063]: Receive 
GetBlockIndexByName(0x1261,OPAQUE)
Aug 12 17:36:32 crux bbstored[7063]: Send Success(0xb8d5)
Aug 12 17:36:32 crux bbstored[7063]: Send Success(0xb8d5)
Aug 12 17:36:32 crux bbstored[7063]: Sending stream, size 67676
Aug 12 17:36:32 crux bbackupd[6999]: Receive Success(0xb8d5)
Aug 12 17:36:32 crux bbackupd[6999]: Receiving stream, size 67676
Aug 12 17:36:58 crux bbackupd[6999]: Send 
StoreFile(0x1261,0x453db4edea540,0xb62406a6d501546b,0xb8d5,"HomannElektronik.4DD")
Aug 12 17:36:58 crux bbstored[7063]: Receive 
StoreFile(0x1261,0x453db4edea540,0xb62406a6d501546b,0xb8d5,OPAQUE)
Aug 12 17:36:58 crux bbstored[7063]: Receive 
StoreFile(0x1261,0x453db4edea540,0xb62406a6d501546b,0xb8d5,OPAQUE)
Aug 12 17:36:58 crux bbackupd[6999]: Sending stream, size uncertain
Aug 12 17:36:58 crux bbstored[7063]: Receiving stream, size uncertain
Aug 12 17:37:01 crux bbstored[7063]: Connection statistics for 
BACKUP-1000: IN=1571476 OUT=2381999 TOTAL=3953475
Aug 12 17:37:01 crux bbackupd[6999]: Send 
SetClientStoreMarker(0x454450b020140)
Aug 12 17:37:01 crux bbackupd[6999]: Exception caught (Connection 
TLSReadFailed (Probably a network issue between client and server.) 
7/34), reset state and waiting to retry...
Aug 12 17:37:01 crux bbstored[7063]: in server child, exception RaidFile 
OSError (Error when accessing an underlying file. Check file permissions 
allow files to be read and written in the configured raid directories.) 
(2/8) -- terminating child
Aug 12 17:46:45 crux bbackupd[6999]: File statistics: total file size 
uploaded 8454144, bytes already on server 3095049, encoded size 1497953
Aug 12 17:46:45 crux bbackupd[6999]: Beginning scan of local files
Aug 12 17:46:45 crux bbackupd[6999]: Opening connection to server 
localhost...
Aug 12 17:46:45 crux bbstored[6623]: Incoming connection from 127.0.0.1 
port 59286 (handling in child 7110)

------------

Repeats in about 5 min cycles.

I tried setting KeepAliveTime, no change. Tried googling a bit but don't 
know what to look for. I seem to remember these kind of errors from the 
list...

All files appears to have the correct owner and permissions.

Any debugging hints?

-- 
Magnus Homann