>>>>> On Wed, 28 Feb 2007 13:41:25 +0100, Thomas Franz said: > > Hello, > > I am running bacula for a lot of month, without any problems. > But yesterday I've got this message: > ............ > 27-Feb 11:05 dssbkup-sd: Volume "A00040" previously written, moving to end of > data. > 27-Feb 11:06 dssbkup-sd: Backup.2007-02-27_11.05.00 Error: I cannot write on > Volume "A00040" because: > The number of files mismatch! Volume=456 Catalog=457 > 27-Feb 11:06 dssbkup-sd: Marking Volume "A00040" in Error in Catalog. > ................... > > OS: FreeBSD 6.1 > Bacula: 1.38.9 > TAPE : LTO-3 (IBM Ultrium-TD3) > Library: Exabyte > > It was the first run after a system restart. ( But this was not the first > time > bacula runs after a restart) . > > I did a "bls -c bacula-sd.conf -j -V A00040 /dev/nsa3 : > ------------------------------------------------------------------------ > bls: butil.c:269 Using device: "/dev/nsa3" for reading. > 27-Feb 20:05 bls: 3301 Issuing autochanger "loaded drive 0" command. > 27-Feb 20:05 bls: 3302 Autochanger "loaded drive 0", result is Slot 3. > 27-Feb 20:05 bls: Ready to read from volume "A00040" on device > "LTO-3" (/dev/nsa3). > bls: acquire.c:200 jcr->dcr=0x80a8818 > Volume Record: File:blk=0:1 SessId=1 SessTime=1172134677 JobId=1 DataLen=163 > End Job Session Record: File:blk=58:15321 SessId=1 SessTime=1172134677 > JobId=741 > Date=22-Feb-2007 12:36:13 Level=I Type=B Files=163 Bytes=118,812,601,974 > Errors=0 Status=T > Begin Job Session Record: File:blk=59:1 SessId=2 SessTime=1172134677 JobId=742 > Job=BackupCatalog.2007-02-22_11.10.00 Date=22-Feb-2007 12:36:27 Level=F > Type=B > End Job Session Record: File:blk=59:167 SessId=2 SessTime=1172134677 JobId=742 > Date=22-Feb-2007 12:36:27 Level=F Type=B Files=1 Bytes=10,742,762 Errors=0 > Status=T > Begin Job Session Record: File:blk=60:1 SessId=1 SessTime=1172158974 JobId=743 > Job=Backup.2007-02-23_11.05.00 Date=23-Feb-2007 11:05:57 Level=I Type=B > End Job Session Record: File:blk=184:15075 SessId=1 SessTime=1172158974 > JobId=743 > Date=23-Feb-2007 13:12:25 Level=I Type=B Files=170 Bytes=124,871,924,365 > Errors=0 Status=T > Begin Job Session Record: File:blk=185:1 SessId=2 SessTime=1172158974 > JobId=744 > Job=BackupCatalog.2007-02-23_11.10.00 Date=23-Feb-2007 13:12:41 Level=F > Type=B > End Job Session Record: File:blk=185:167 SessId=2 SessTime=1172158974 > JobId=744 > Date=23-Feb-2007 13:12:42 Level=F Type=B Files=1 Bytes=10,758,705 Errors=0 > Status=T > Begin Job Session Record: File:blk=186:1 SessId=3 SessTime=1172158974 > JobId=745 > Job=BackupCatalog.2007-02-24_11.10.00 Date=24-Feb-2007 11:10:12 Level=F > Type=B > End Job Session Record: File:blk=186:167 SessId=3 SessTime=1172158974 > JobId=745 > Date=24-Feb-2007 11:10:13 Level=F Type=B Files=1 Bytes=10,759,041 Errors=0 > Status=T > Begin Job Session Record: File:blk=187:1 SessId=4 SessTime=1172158974 > JobId=746 > Job=Backup.2007-02-24_15.05.00 Date=24-Feb-2007 15:05:08 Level=I Type=B > End Job Session Record: File:blk=373:4820 SessId=4 SessTime=1172158974 > JobId=746 > Date=24-Feb-2007 18:21:53 Level=I Type=B Files=227 Bytes=186,160,933,600 > Errors=0 Status=T > Begin Job Session Record: File:blk=374:1 SessId=5 SessTime=1172158974 > JobId=747 > Job=BackupCatalog.2007-02-25_11.10.00 Date=25-Feb-2007 11:10:11 Level=F > Type=B > End Job Session Record: File:blk=374:168 SessId=5 SessTime=1172158974 > JobId=747 > Date=25-Feb-2007 11:10:12 Level=F Type=B Files=1 Bytes=10,781,378 Errors=0 > Status=T > Begin Job Session Record: File:blk=375:1 SessId=6 SessTime=1172158974 > JobId=748 > Job=Backup.2007-02-25_15.05.00 Date=25-Feb-2007 15:05:07 Level=I Type=B > End Job Session Record: File:blk=424:13848 SessId=6 SessTime=1172158974 > JobId=748 > Date=25-Feb-2007 15:55:11 Level=I Type=B Files=103 Bytes=49,853,197,033 > Errors=0 Status=T > Begin Job Session Record: File:blk=425:1 SessId=7 SessTime=1172158974 > JobId=749 > Job=Backup.2007-02-26_11.05.00 Date=26-Feb-2007 11:05:07 Level=I Type=B > End Job Session Record: File:blk=455:12387 SessId=7 SessTime=1172158974 > JobId=749 > Date=26-Feb-2007 11:36:23 Level=I Type=B Files=86 Bytes=30,774,345,961 > Errors=0 Status=T > Begin Job Session Record: File:blk=456:1 SessId=8 SessTime=1172158974 > JobId=750 > Job=BackupCatalog.2007-02-26_11.10.00 Date=26-Feb-2007 11:36:39 Level=F > Type=B > End Job Session Record: File:blk=456:168 SessId=8 SessTime=1172158974 > JobId=750 > Date=26-Feb-2007 11:36:40 Level=F Type=B Files=1 Bytes=10,798,086 Errors=0 > Status=T > 27-Feb 22:41 bls: bls Error: block.c:945 Read error at file:blk 457:0 on > device "LTO-3" (/dev/nsa3). ERR=Operation not permi > tted. > 27-Feb 22:41 bls: End of Volume at file 457 on device "LTO-3" (/dev/nsa3), > Volume "A00040" > 27-Feb 22:41 bls: End of all volumes. > ------------------------------------------------------------------ > > Job 750 was the last backup at this time ( it was the backup of the Catalog > itself) . I could restore this file and it seems to be OK.
Since you got a read error at the end, it looks like something is wrong with the data on the tape. A few possibilities I can think of: 1) The EOT model in Bacula now doesn't match the EOT model in Bacula when the tape was written. 2) The EOT model in the drive doesn't match the EOT model in Bacula (or didn't match when the tape was written). 3) The EOT model in the drive is not supported by the drive correctly. 4) The EOM handling is not working and the tape is 100% full. > And I did this btape-run: > ------------------------------------------- > Tape block granularity is 1024 bytes. > btape: butil.c:272 Using device: "/dev/nsa3" for writing. > 28-Feb 09:43 btape: 3301 Issuing autochanger "loaded drive 0" command. > 28-Feb 09:43 btape: 3302 Autochanger "loaded drive 0", result is Slot 3. > 28-Feb 09:43 btape: 3301 Issuing autochanger "loaded drive 0" command. > 28-Feb 09:43 btape: 3302 Autochanger "loaded drive 0", result is Slot 3. > btape: btape.c:338 open device "LTO-3" (/dev/nsa3): OK > *rewind > btape: btape.c:438 Rewound "LTO-3" (/dev/nsa3) > *status > Bacula status: file=0 block=0 > Device status: file=0 block=0 > btape: btape.c:1759 Device status: 1. ERR= > *eod > btape: btape.c:490 Moved to end of medium. > *status > Bacula status: file=456 block=0 > Device status: file=456 block=0 > btape: btape.c:1759 Device status: 1. ERR= > *quit > Orphaned buffer: 16 bytes allocated at line 276 of btape reserve.c > ------------------------------------------------ > > The content of the catalog for this volume : see attachment It looks like the catalog value matches what bls prints, except for the final read error. The btape eod doesn't match, which again indicates an EOT/EOM problem. Have you run the btape tests with you current settings? __Martin ------------------------------------------------------------------------- Take Surveys. Earn Cash. Influence the Future of IT Join SourceForge.net's Techsay panel and you'll get the chance to share your opinions on IT & business topics through brief surveys-and earn cash http://www.techsay.com/default.php?page=join.php&p=sourceforge&CID=DEVDEV _______________________________________________ Bacula-users mailing list Bacula-users@lists.sourceforge.net https://lists.sourceforge.net/lists/listinfo/bacula-users
