[OpenAFS] 'vos dump' destroys volumes?

[Matthias Gerstner]

Hello,

I'm recently experiencing trouble during my backup of OpenAFS volumes.
I perform backups using the

'vos dump -server <server> -partition <partition> -clone -id <vol>'

command. Data is dumped via pipes onto stdout for compression etc. and
is finally uploaded onto an FTP server location. This approach worked
for about a year now without much problems.

However some days ago the backup of a specific volume failed with
a bad exit code (255). My backup script thus stopped further processing.
The concerned volume went offline as a result and did only show up in
'vos listvol' as "couldn't attach volume ...".

After running a salvage on the affected volume it was brought back
online but most of the contained data was deleted due to a supposed
corruption of the directory strucuture detected during salvage.

The same thing occured again with another volume in one of the next
backup attempts. The affected volumes worked perfectly well before
trying to backup them. I'm concerned with this behaviour that a backup
attempt seemingly destroys my data.

Can anyone provide assistance with this?

Attached is the VolserLog from the time when the last of the incidents
occured. I'm currently running openafs 1.6.1 on Gentoo Linux with kernel
version 3.2.1.

Best regards,

Matthias

-- 
Matthias Gerstner, Dipl.-Wirtsch.-Inf. (FH), Senior Software Engineer
e.solutions GmbH

Am Wolfsmantel 46, 91058 Erlangen, Germany

Registered Office:
Pascalstr. 5, 85057 Ingolstadt, Germany

Phone +49-8458-3332-672, mailto:Matthias.Gerstner@esolutions.de
Fax +49-8458-3332-20672

e.solutions GmbH
Managing Directors Uwe Reder, Dr. Riclef Schmidt-Clausen
Register Court Ingolstadt HRB 5221

Fri Mar 23 00:01:04 2012 1 Volser: Clone: Cloning volume 536870993 to new volume 536889513
Fri Mar 23 00:04:32 2012 1 Volser: Delete: volume 536889513 deleted 
Fri Mar 23 00:04:33 2012 1 Volser: Clone: Cloning volume 536870999 to new volume 536889514
Fri Mar 23 00:09:41 2012 1 Volser: Delete: volume 536889514 deleted 
Fri Mar 23 00:09:41 2012 1 Volser: Clone: Cloning volume 536870996 to new volume 536889516
Fri Mar 23 00:10:57 2012 1 Volser: Delete: volume 536889516 deleted 
Fri Mar 23 00:10:57 2012 1 Volser: Clone: Cloning volume 536879790 to new volume 536889517
Fri Mar 23 00:16:04 2012 1 Volser: Delete: volume 536889517 deleted 
Fri Mar 23 00:16:04 2012 1 Volser: Clone: Cloning volume 536879793 to new volume 536889518
Fri Mar 23 00:16:06 2012 VDestroyVolumeDiskHeader: Couldn't unlink disk header, error = 2
Fri Mar 23 00:16:06 2012 VPurgeVolume: Error -1 when destroying volume 536889517 header
Fri Mar 23 00:16:06 2012 1 Volser: Delete: volume 536889517 deleted 
Fri Mar 23 00:16:09 2012 1 Volser: Delete: volume 536889518 deleted 
Fri Mar 23 00:16:09 2012 VDestroyVolumeDiskHeader: Couldn't unlink disk header, error = 2
Fri Mar 23 00:16:09 2012 VPurgeVolume: Error -1 when destroying volume 536889518 header
Fri Mar 23 00:16:09 2012 1 Volser: Delete: volume 536889518 deleted 
Fri Mar 23 00:21:20 2012 trans 69 on volume 536889518 is older than 300 seconds
Fri Mar 23 00:21:20 2012 trans 66 on volume 536889517 is older than 300 seconds
Fri Mar 23 00:21:50 2012 trans 69 on volume 536889518 is older than 330 seconds
Fri Mar 23 00:21:50 2012 trans 66 on volume 536889517 is older than 330 seconds
Fri Mar 23 00:22:20 2012 trans 69 on volume 536889518 is older than 360 seconds
Fri Mar 23 00:22:20 2012 trans 66 on volume 536889517 is older than 360 seconds
Fri Mar 23 00:22:50 2012 trans 69 on volume 536889518 is older than 390 seconds
Fri Mar 23 00:22:50 2012 trans 66 on volume 536889517 is older than 390 seconds
Fri Mar 23 00:23:20 2012 trans 69 on volume 536889518 is older than 420 seconds
Fri Mar 23 00:23:20 2012 trans 66 on volume 536889517 is older than 420 seconds
Fri Mar 23 00:23:27 2012 1 Volser: DumpVolume: Rx call failed during dump, error -1
Fri Mar 23 00:23:28 2012 1 Volser: DumpVolume: Rx call failed during dump, error -1
Fri Mar 23 00:28:50 2012 trans 69 on volume 536889518 has been idle for more than 300 seconds
Fri Mar 23 00:28:50 2012 trans 66 on volume 536889517 has been idle for more than 300 seconds
Fri Mar 23 00:29:20 2012 trans 69 on volume 536889518 has been idle for more than 330 seconds
Fri Mar 23 00:29:20 2012 trans 66 on volume 536889517 has been idle for more than 330 seconds
Fri Mar 23 00:29:50 2012 trans 69 on volume 536889518 has been idle for more than 360 seconds
Fri Mar 23 00:29:50 2012 trans 66 on volume 536889517 has been idle for more than 360 seconds
Fri Mar 23 00:30:20 2012 trans 69 on volume 536889518 has been idle for more than 390 seconds
Fri Mar 23 00:30:20 2012 trans 66 on volume 536889517 has been idle for more than 390 seconds
Fri Mar 23 00:30:50 2012 trans 69 on volume 536889518 has been idle for more than 420 seconds
Fri Mar 23 00:30:50 2012 trans 66 on volume 536889517 has been idle for more than 420 seconds
Fri Mar 23 00:31:20 2012 trans 69 on volume 536889518 has been idle for more than 450 seconds
Fri Mar 23 00:31:20 2012 trans 66 on volume 536889517 has been idle for more than 450 seconds
Fri Mar 23 00:31:50 2012 trans 69 on volume 536889518 has been idle for more than 480 seconds
Fri Mar 23 00:31:50 2012 trans 66 on volume 536889517 has been idle for more than 480 seconds
Fri Mar 23 00:32:20 2012 trans 69 on volume 536889518 has been idle for more than 510 seconds
Fri Mar 23 00:32:20 2012 trans 66 on volume 536889517 has been idle for more than 510 seconds
Fri Mar 23 00:32:50 2012 trans 69 on volume 536889518 has been idle for more than 540 seconds
Fri Mar 23 00:32:50 2012 trans 66 on volume 536889517 has been idle for more than 540 seconds
Fri Mar 23 00:33:20 2012 trans 69 on volume 536889518 has been idle for more than 570 seconds
Fri Mar 23 00:33:20 2012 trans 66 on volume 536889517 has been idle for more than 570 seconds
Fri Mar 23 00:33:50 2012 trans 69 on volume 536889518 has been idle for more than 600 seconds
Fri Mar 23 00:33:50 2012 trans 69 on volume 536889518 has timed out
Fri Mar 23 00:33:50 2012 trans 66 on volume 536889517 has been idle for more than 600 seconds
Fri Mar 23 00:33:50 2012 trans 66 on volume 536889517 has timed out