Dear Arno
Did as requested - set the max bytes to 1.5GB - ran catalog backup that is
1.8 GB. New tape used.
Seems to be reproducible slight different error maybe due to logical EOM
and physical EOM.
I have reported bug and will attach trace file
See below
Regards
Stephen Carr
############
25-Jun 07:45 elizabeth-dir JobId 58653: BeforeJob: run command
"/etc/bacula/make_catalog_backup bacula bacula"
25-Jun 08:02 elizabeth-dir JobId 58653: Start Backup JobId 58653,
Job=BackupCatalog.2008-06-25_07.45.03
25-Jun 08:02 elizabeth-dir JobId 58653: Using Device "LTO"
25-Jun 08:02 elizabeth-sd JobId 58653: Wrote label to prelabeled Volume
"Test" on device "LTO" (/dev/nst1)
25-Jun 08:02 elizabeth-sd JobId 58653: Spooling data ...
25-Jun 08:05 elizabeth-sd JobId 58653: Job write elapsed time = 00:02:56,
Transfer rate = 10.48 M bytes/second
25-Jun 08:05 elizabeth-sd JobId 58653: Committing spooled data to Volume
"Test". Despooling 1,847,863,866 bytes ...
25-Jun 08:06 elizabeth-sd JobId 58653: User defined maximum volume
capacity 1,500,000,000 exceeded on device "LTO"
(/dev/nst1).
25-Jun 08:06 elizabeth-sd JobId 58653: Re-read of last block succeeded.
25-Jun 08:06 elizabeth-sd JobId 58653: End of medium on Volume "Test"
Bytes=1,499,968,512 Blocks=23,250 at 25-Jun-2008
08:06.
25-Jun 08:07 elizabeth-sd JobId 58653: Volume "Test" previously written,
moving to end of data.
25-Jun 08:07 elizabeth-sd JobId 58653: Error: Bacula cannot write on tape
Volume "Test" because:
The number of files mismatch! Volume=2 Catalog=56
25-Jun 08:07 elizabeth-sd JobId 58653: Marking Volume "Test" in Error in
Catalog.
25-Jun 08:08 elizabeth-sd JobId 58653: Recycled volume "Test" on device
"LTO" (/dev/nst1), all previous data lost.
25-Jun 08:08 elizabeth-sd JobId 58653: New volume "Test" mounted on device
"LTO" (/dev/nst1) at 25-Jun-2008 08:08.
25-Jun 08:08 elizabeth-sd JobId 58653: Despooling elapsed time = 00:01:23,
Transfer rate = 22.26 M bytes/second
25-Jun 08:08 elizabeth-sd JobId 58653: Sending spooled attrs to the
Director. Despooling 279 bytes ...
25-Jun 08:08 elizabeth-dir JobId 58653: Bacula elizabeth-dir 2.4.0
(04Jun08): 25-Jun-2008 08:08:27
Build OS: i686-pc-linux-gnu slackware Slackware 9.1.0
JobId: 58653
Job: BackupCatalog.2008-06-25_07.45.03
Backup Level: Full
Client: "elizabeth" 2.4.0 (04Jun08)
i686-pc-linux-gnu,slackware,Slackware 9.1.0
FileSet: "Catalog" 2006-09-07 23:24:53
Pool: "Full" (From Job FullPool override)
Storage: "Ultrium" (From Pool resource)
Scheduled time: 25-Jun-2008 07:45:49
Start time: 25-Jun-2008 08:02:29
End time: 25-Jun-2008 08:08:27
Elapsed time: 5 mins 58 secs
Priority: 30
FD Files Written: 1
SD Files Written: 1
FD Bytes Written: 1,846,150,699 (1.846 GB)
SD Bytes Written: 1,846,150,810 (1.846 GB)
Rate: 5156.8 KB/s
Software Compression: None
VSS: no
Storage Encryption: no
Volume name(s): Test
Volume Session Id: 1
Volume Session Time: 1214345375
Last Volume Bytes: 347,719,680 (347.7 MB)
Non-fatal FD errors: 0
SD Errors: 0
FD termination status: OK
SD termination status: OK
Termination: Backup OK
25-Jun 08:08 elizabeth-dir JobId 58653: Begin pruning Jobs.
25-Jun 08:08 elizabeth-dir JobId 58653: No Jobs found to prune.
25-Jun 08:08 elizabeth-dir JobId 58653: Begin pruning Files.
25-Jun 08:08 elizabeth-dir JobId 58653: No Files found to prune.
25-Jun 08:08 elizabeth-dir JobId 58653: End auto prune.
25-Jun 08:08 elizabeth-dir JobId 58653: AfterJob: run command
"/etc/bacula/delete_catalog_backup"
#####################
Arno Lehmann wrote:
> Hi,
>
> 24.06.2008 16:12, Stephen Carr wrote:
>> Dear All
>>
>> Sorry for this - I hope it is a red herring last Saturday I had what I
>> thought was a tape problem and asked about rerunning a migration job.
>>
>> Tonight a tape was incorrectly recycled instead of requesting the next
>> tape to be loaded.
>>
>> See below.
>>
>> Will revert to 2.2.8 in interim.
>>
>> Enter MediaId or Volume name: LTO-D1
>> Updating Volume "LTO-D1"
>> Current retention period is: 28 days
>>
>> Can someone test this out on small capacity tape unit 300GB a long way
>> to wait for error.
>
> As we can not reproduce your exact setup this might be difficult (and
> don't talk about the time needed to test...).
>
> But you could set the maximum volume bytes to something lower and see
> for yourself. It might help if you run the DIR and SD with debug
> tracing enabled, too, so you can collect all the information for a
> detailed bug report.
>
> Arno
>
>> I usually change tapes if close to 300 GB event at 250 GB.
>>
>> I have also included info from log.
>>
>> Regards
>> Stephen Carr
>>
>> ###################################
>> Recycling in error
>> ###################################
>>
>> 24-Jun 18:30 elizabeth-dir JobId 58648: The following 1 JobIds were
>> chosen to be migrated: 58581
>> 24-Jun 18:30 elizabeth-dir JobId 58648: Migration using JobId=58581
>> Job=civengb179.2008-06-24_11.20.52
>> 24-Jun 18:30 elizabeth-dir JobId 58648: Storage "" not found, using
>> Storage "File" from MediaType "File".
>> 24-Jun 18:30 elizabeth-dir JobId 58648: Bootstrap records written to
>> /common/bacula/elizabeth-dir.restore.41.bsr
>> 24-Jun 18:30 elizabeth-dir JobId 58648:
>> 24-Jun 18:30 elizabeth-dir JobId 58648: The job will require the
>> following
>> Volume(s) Storage(s) SD Device(s)
>> ===========================================================================
>> 24-Jun 18:30 elizabeth-dir JobId 58648:
>> 24-Jun 18:30 elizabeth-dir JobId 58648: Full0951
>>
>> 24-Jun 18:30 elizabeth-dir JobId 58648:
>> 24-Jun 21:08 elizabeth-dir JobId 58648: Start Migration JobId 58648,
>> Job=Migrate-Full.2008-06-24_18.30.16
>> 24-Jun 21:08 elizabeth-dir JobId 58648: Using Device "LTO"
>> 24-Jun 21:08 elizabeth-sd JobId 58648: Ready to read from volume
>> "Full0951" on device "File" (/wd1000).
>> 24-Jun 21:08 elizabeth-sd JobId 58648: Forward spacing Volume "Full0951"
>> to file:block 0:202.
>> 24-Jun 21:42 elizabeth-sd JobId 58648: End of Volume "LTO-D1" at
>> 294:8935 on device "LTO" (/dev/nst1). Write of 64512 bytes got -1.
>> 24-Jun 21:42 elizabeth-sd JobId 58648: Re-read of last block succeeded.
>> 24-Jun 21:42 elizabeth-sd JobId 58648: End of medium on Volume "LTO-D1"
>> Bytes=273,626,357,760 Blocks=4,241,479 at 24-Jun-2008 21:42.
>> 24-Jun 21:43 elizabeth-sd JobId 58648: Recycled volume "LTO-D1" on
>> device "LTO" (/dev/nst1), all previous data lost.
>> 24-Jun 21:43 elizabeth-sd JobId 58648: New volume "LTO-D1" mounted on
>> device "LTO" (/dev/nst1) at 24-Jun-2008 21:43.
>> 24-Jun 21:43 elizabeth-sd JobId 58648: End of file 8 on device "File"
>> (/wd1000), Volume "Full0951"
>> 24-Jun 21:43 elizabeth-sd JobId 58648: End of Volume at file 8 on device
>> "File" (/wd1000), Volume "Full0951"
>> 24-Jun 21:43 elizabeth-sd JobId 58648: End of all volumes.
>> 24-Jun 21:43 elizabeth-dir JobId 58648: Bacula elizabeth-dir 2.4.0
>> (04Jun08): 24-Jun-2008 21:43:30
>> Build OS: i686-pc-linux-gnu slackware Slackware 9.1.0
>> Prev Backup JobId: 58581
>> New Backup JobId: 58649
>> Migration JobId: 58648
>> Migration Job: Migrate-Full.2008-06-24_18.30.16
>> Backup Level: Full
>> Client: elizabeth
>> FileSet: "workstation" 2006-09-07 16:00:03
>> Read Pool: "Migrate-Full" (From Job resource)
>> Read Storage: "File" (From Pool resource)
>> Write Pool: "Full" (From Job Pool's NextPool resource)
>> Write Storage: "Ultrium" (From Storage from Pool's NextPool
>> resource)
>> Start time: 24-Jun-2008 21:08:07
>> End time: 24-Jun-2008 21:43:30
>> Elapsed time: 35 mins 23 secs
>> Priority: 22
>> SD Files Written: 19,872
>> SD Bytes Written: 20,651,287,536 (20.65 GB)
>> Rate: 9727.4 KB/s
>> Volume name(s): LTO-D1
>> Volume Session Id: 158
>> Volume Session Time: 1214014949
>> Last Volume Bytes: 92,187,648 (92.18 MB)
>> SD Errors: 0
>> SD termination status: OK
>> Termination: Migration OK
>>
>> 24-Jun 21:43 elizabeth-dir JobId 58648: Begin pruning Jobs.
>> 24-Jun 21:43 elizabeth-dir JobId 58648: Pruned 1 Job for client
>> elizabeth from catalog.
>> 24-Jun 21:43 elizabeth-dir JobId 58648: Begin pruning Files.
>> 24-Jun 21:43 elizabeth-dir JobId 58648: No Files found to prune.
>> 24-Jun 21:43 elizabeth-dir JobId 58648: End auto prune.
>>
>> ##############################
>> Prior job
>> ################################
>>
>> 24-Jun 18:30 elizabeth-dir JobId 58646: The following 1 JobIds were
>> chosen to be migrated: 58580
>> 24-Jun 18:30 elizabeth-dir JobId 58646: Migration using JobId=58580
>> Job=civengb178.2008-06-24_11.20.51
>> 24-Jun 18:30 elizabeth-dir JobId 58646: Storage "" not found, using
>> Storage "File" from MediaType "File".
>> 24-Jun 18:30 elizabeth-dir JobId 58646: Bootstrap records written to
>> /common/bacula/elizabeth-dir.restore.40.bsr
>> 24-Jun 18:30 elizabeth-dir JobId 58646:
>> 24-Jun 18:30 elizabeth-dir JobId 58646: The job will require the
>> following
>> Volume(s) Storage(s) SD Device(s)
>> ===========================================================================
>> 24-Jun 18:30 elizabeth-dir JobId 58646:
>> 24-Jun 18:30 elizabeth-dir JobId 58646: Full0951
>>
>> 24-Jun 18:30 elizabeth-dir JobId 58646:
>> 24-Jun 20:41 elizabeth-dir JobId 58646: Start Migration JobId 58646,
>> Job=Migrate-Full.2008-06-24_18.30.14
>> 24-Jun 20:41 elizabeth-dir JobId 58646: Using Device "LTO"
>> 24-Jun 20:41 elizabeth-sd JobId 58646: Ready to read from volume
>> "Full0951" on device "File" (/wd1000).
>> 24-Jun 20:41 elizabeth-sd JobId 58646: Forward spacing Volume "Full0951"
>> to file:block 0:202.
>> 24-Jun 21:07 elizabeth-sd JobId 58646: End of file 8 on device "File"
>> (/wd1000), Volume "Full0951"
>> 24-Jun 21:07 elizabeth-sd JobId 58646: End of Volume at file 8 on device
>> "File" (/wd1000), Volume "Full0951"
>> 24-Jun 21:07 elizabeth-sd JobId 58646: End of all volumes.
>> 24-Jun 21:07 elizabeth-dir JobId 58646: Bacula elizabeth-dir 2.4.0
>> (04Jun08): 24-Jun-2008 21:07:55
>> Build OS: i686-pc-linux-gnu slackware Slackware 9.1.0
>> Prev Backup JobId: 58580
>> New Backup JobId: 58647
>> Migration JobId: 58646
>> Migration Job: Migrate-Full.2008-06-24_18.30.14
>> Backup Level: Full
>> Client: elizabeth
>> FileSet: "workstation" 2006-09-07 16:00:03
>> Read Pool: "Migrate-Full" (From Job resource)
>> Read Storage: "File" (From Pool resource)
>> Write Pool: "Full" (From Job Pool's NextPool resource)
>> Write Storage: "Ultrium" (From Storage from Pool's NextPool
>> resource)
>> Start time: 24-Jun-2008 20:41:47
>> End time: 24-Jun-2008 21:07:55
>> Elapsed time: 26 mins 8 secs
>> Priority: 22
>> SD Files Written: 5,046
>> SD Bytes Written: 3,630,970,128 (3.630 GB)
>> Rate: 2315.7 KB/s
>> Volume name(s): LTO-D1
>> Volume Session Id: 157
>> Volume Session Time: 1214014949
>> Last Volume Bytes: 253,051,223,040 (253.0 GB)
>> SD Errors: 0
>> SD termination status: OK
>> Termination: Migration OK
>>
>> ###################################
>> log earlier error - media?? Media replaced
>> ###################################
>> 21-Jun 11:26 elizabeth-dir JobId 58269:
>> 21-Jun 11:26 elizabeth-dir JobId 58269: The job will require the
>> following
>> 21-Jun 11:26 elizabeth-dir JobId 58269:
>> 21-Jun 11:26 elizabeth-dir JobId 58269: Full0003
>> Ultrium LTO
>> 21-Jun 11:26 elizabeth-dir JobId 58269:
>> 21-Jun 11:26 elizabeth-dir JobId 58269: Start Migration JobId 58269,
>> Job=Migrate-Full.2008-06-21_11.26.34
>> 21-Jun 11:26 elizabeth-dir JobId 58269: Using Device "LTO"
>> 21-Jun 11:26 elizabeth-sd JobId 58269: Ready to read from volume
>> "Full0003" on device "File" (/wd1000).
>> 21-Jun 11:26 elizabeth-sd JobId 58269: Volume "LTO-D1" previously
>> written, moving to end of data.
>> 21-Jun 11:46 elizabeth-sd JobId 58269: Error: Unable to position to end
>> of data on device "LTO" (/dev/nst1): ERR=dev.c:895 ioctl MTEOM error on
>> "LTO" (/dev/nst1). ERR=Input/output error.
>> 21-Jun 11:46 elizabeth-sd JobId 58269: Marking Volume "LTO-D1" in Error
>> in Catalog.
>>
>> ################################################
>> Log recycling tape
>> ################################################
>> 24-Jun 21:08 elizabeth-dir JobId 58648: Start Migration JobId 58648,
>> Job=Migrate-Full.2008-06-24_18.30.16
>> 24-Jun 21:08 elizabeth-dir JobId 58648: Using Device "LTO"
>> 24-Jun 21:08 elizabeth-sd JobId 58648: Ready to read from volume
>> "Full0951" on device "File" (/wd1000).
>> 24-Jun 21:08 elizabeth-sd JobId 58648: Forward spacing Volume "Full0951"
>> to file:block 0:202.
>> 24-Jun 21:42 elizabeth-sd JobId 58648: End of Volume "LTO-D1" at
>> 294:8935 on device "LTO" (/dev/nst1). Write of 64512 bytes got -1.
>> 24-Jun 21:42 elizabeth-sd JobId 58648: Re-read of last block succeeded.
>> 24-Jun 21:42 elizabeth-sd JobId 58648: End of medium on Volume "LTO-D1"
>> Bytes=273,626,357,760 Blocks=4,241,479 at 24-Jun-2008 21:42.
>> 24-Jun 21:43 elizabeth-sd JobId 58648: Recycled volume "LTO-D1" on
>> device "LTO" (/dev/nst1), all previous data lost.
>> 24-Jun 21:43 elizabeth-sd JobId 58648: New volume "LTO-D1" mounted on
>> device "LTO" (/dev/nst1) at 24-Jun-2008 21:43.
>> 24-Jun 21:43 elizabeth-sd JobId 58648: End of file 8 on device "File"
>> (/wd1000), Volume "Full0951"
>> 24-Jun 21:43 elizabeth-sd JobId 58648: End of Volume at file 8 on device
>> "File" (/wd1000), Volume "Full0951"
>> 24-Jun 21:43 elizabeth-sd JobId 58648: End of all volumes.
>> 24-Jun 21:43 elizabeth-dir JobId 58648: Bacula elizabeth-dir 2.4.0
>> (04Jun08): 24-Jun-2008 21:43:30
>> 24-Jun 21:43 elizabeth-dir JobId 58648: Begin pruning Jobs.
>> 24-Jun 21:43 elizabeth-dir JobId 58648: Pruned 1 Job for client
>> elizabeth from catalog.
>> 24-Jun 21:43 elizabeth-dir JobId 58648: Begin pruning Files.
>> 24-Jun 21:43 elizabeth-dir JobId 58648: No Files found to prune.
>> 24-Jun 21:43 elizabeth-dir JobId 58648: End auto prune.
>> 24-Jun 21:43 elizabeth-dir JobId 58630: Start Migration JobId 58630,
>> Job=Migrate-Full.2008-06-24_18.30.58
>> 24-Jun 21:43 elizabeth-dir JobId 58630: Using Device "LTO"
>> 24-Jun 21:43 elizabeth-sd JobId 58630: Ready to read from volume
>> "Full0951" on device "File" (/wd1000).
>> 24-Jun 21:44 elizabeth-sd JobId 58630: Volume "LTO-D1" previously
>> written, moving to end of data.
>> 24-Jun 21:44 elizabeth-sd JobId 58630: Ready to append to end of Volume
>> "LTO-D1" at file=1.
>> 24-Jun 21:44 elizabeth-sd JobId 58630: Forward spacing Volume "Full0951"
>> to file:block 0:202.
>>
>>
>
> --
> Arno Lehmann
> IT-Service Lehmann
> www.its-lehmann.de
>
> -------------------------------------------------------------------------
> Check out the new SourceForge.net Marketplace.
> It's the best place to buy or sell services for
> just about anything Open Source.
> http://sourceforge.net/services/buy/index.php
> _______________________________________________
> Bacula-users mailing list
> Bacula-users AT lists.sourceforge DOT net
> https://lists.sourceforge.net/lists/listinfo/bacula-users
>
>
--
Stephen Carr
Computing Officer
School of Civil and Environmental Engineering
The University of Adelaide
Tel +618-8303-4313
Fax +618-8303-4359
Email sgcarr AT civeng.adelaide.edu DOT au
CRICOS Provider Number 00123M
-----------------------------------------------------------
This email message is intended only for the addressee(s)and contains
information that may be confidential and/or copyright. If you are not the
intended recipient please notify the sender by reply email and immediately
delete this email. Use, disclosure or reproduction of this email by anyone
other than the intended recipient(s) is strictly prohibited. No
representation is made that this email or any attachments are free of
viruses. Virus scanning is recommended and is the responsibility of the
recipient.
-------------------------------------------------------------------------
Check out the new SourceForge.net Marketplace.
It's the best place to buy or sell services for
just about anything Open Source.
http://sourceforge.net/services/buy/index.php
_______________________________________________
Bacula-users mailing list
Bacula-users AT lists.sourceforge DOT net
https://lists.sourceforge.net/lists/listinfo/bacula-users
|
