Platform: $ uname -a FreeBSD mindwipe 5.3-RELEASE-p23 FreeBSD 5.3-RELEASE-p23 #0: Wed Oct 12
-bash-2.05b$ pkg_info |grep -i bacula
bacula-client-1.38.5_1 The network backup solution (client)
bacula-server-1.38.5_1 The network backup solution (server)
Here's what I know so far:
*) This bug is not related to manual manipulation of the system clock (I
can simulate it with and NTP sync)
*) It does not matter if the two jobs in question start from the
scheduler or by bconsole manually
Description:
I create a Daily and a Weekly pool for GFS, both with "23h" "Max Use
Duration"'s to ensure the tapes are only used once/week.
Pool {
Name = Daily
Volume Use Duration = 23h
Pool Type = Backup
AutoPrune = yes
Recycle Oldest Volume = yes
VolumeRetention = 6d # recycle in 6 days
Maximum Volumes = 6
Recycle = yes
}
Pool {
Name = Weekly
Pool Type = Backup
Volume Use Duration = 23h
AutoPrune = yes
VolumeRetention = 29d # recycle in 29 days
Maximum Volumes = 4
Recycle Oldest Volume = yes
Recycle = yes
}
In theory, once the volume in the pool is elected for use in a Job, as
many other qualifying jobs should also be able to write to it until it's
full or more than 23 hours since "firstwritten: ".
An llist of the "pool" and "media" show the appropriate
"voluseduration:" of 82,800 seconds. When I run the first job,
Promotion sends the data to CFusionWeekly0 per the auto-upgrade logic.
When I run the second job 15 seconds later, for some reason the previous
tape/volume is flagged as having "Exceeded Volume Use Duration".
Here are the logs of the first job:
-------------------------------------------------
14-Feb 15:53 mindwipe-dir: No prior Full backup Job record found.
14-Feb 15:53 mindwipe-dir: No prior or suitable Full backup found. Doing
FULL backup.
14-Feb 15:53 mindwipe-dir: Start Backup JobId 1,
Job=Blackout-CFusionDefaults.2006-02-14_15.53.31
14-Feb 15:53 mindwipe-sd: Wrote label to prelabeled Volume
"CFusionWeekly0" on device "FileStorage" (/usr/dump/bacula)
14-Feb 15:53 mindwipe-dir: Bacula 1.38.5 (18Jan06): 14-Feb-2006 15:53:44
[snip]
FileSet: "CFDefaults" 2006-02-14 15:53:33
Pool: "Weekly"
Storage: "FileStorage"
Scheduled time: 14-Feb-2006 15:53:20
Start time: 14-Feb-2006 15:53:33
End time: 14-Feb-2006 15:53:44
Priority: 10
FD Files Written: 722
SD Files Written: 722
FD Bytes Written: 14,749,540
SD Bytes Written: 14,826,848
[snip]
Volume name(s): CFusionWeekly0
Volume Session Id: 1
Volume Session Time: 1139949980
[snip]
Termination: Backup OK
14-Feb 15:53 mindwipe-dir: Begin pruning Jobs.
14-Feb 15:53 mindwipe-dir: No Jobs found to prune.
14-Feb 15:53 mindwipe-dir: Begin pruning Files.
14-Feb 15:53 mindwipe-dir: No Files found to prune.
14-Feb 15:53 mindwipe-dir: End auto prune.
Here are the logs of the second job (an 'llist media' between jobs can
be found below):
---------------------------------------------------------
14-Feb 15:59 mindwipe-dir: No prior Full backup Job record found.
14-Feb 15:59 mindwipe-dir: No prior or suitable Full backup found. Doing
FULL backup.
14-Feb 15:59 mindwipe-dir: Start Backup JobId 2,
Job=Blackout-LDAP.2006-02-14_15.59.01
14-Feb 15:59 mindwipe-dir: Max configured use duration exceeded. Marking
Volume "CFusionWeekly0" as Used.
--------------------------------------
Clearly the Director is confused because the Mark Used event should not
occur until 15-Feb 14:53.33 per the following llist output exerpt from
below:
firstwritten: 02/14/2006 15:53:33
lastwritten: 02/14/2006 15:53:43
labeldate: 02/14/2006 15:53:33
---------------------------------------------------------
--------------------------------------------------------
Here is the "llist media" prior to the first job:
*llist media
Pool: Monthly
No results to list.
Pool: Daily
mediaid: 1
volumename: CFusionDaily0
slot: 0
poolid: 1
mediatype: File
firstwritten:
lastwritten:
labeldate: 02/14/2006 15:46:46
voljobs: 0
volfiles: 0
volblocks: 0
volmounts: 0
volbytes: 1
volerrors: 0
volwrites: 0
volcapacitybytes: 0
volstatus: Append
recycle: 1
volretention: 518,400
voluseduration: 82,800
maxvoljobs: 0
maxvolfiles: 0
maxvolbytes: 0
inchanger: 1
endfile: 0
endblock: 0
volparts: 0
labeltype: 0
storageid: 1
mediaid: 2
volumename: CFusionDaily1
slot: 0
poolid: 1
mediatype: File
firstwritten:
lastwritten:
labeldate: 02/14/2006 15:47:03
voljobs: 0
volfiles: 0
volblocks: 0
volmounts: 0
volbytes: 1
volerrors: 0
volwrites: 0
volcapacitybytes: 0
volstatus: Append
recycle: 1
volretention: 518,400
voluseduration: 82,800
maxvoljobs: 0
maxvolfiles: 0
maxvolbytes: 0
inchanger: 1
endfile: 0
endblock: 0
volparts: 0
labeltype: 0
storageid: 1
Pool: Weekly
mediaid: 3
volumename: CFusionWeekly0
slot: 0
poolid: 2
mediatype: File
firstwritten:
lastwritten:
labeldate: 02/14/2006 15:47:15
voljobs: 0
volfiles: 0
volblocks: 0
volmounts: 0
volbytes: 1
volerrors: 0
volwrites: 0
volcapacitybytes: 0
volstatus: Append
recycle: 1
volretention: 2,505,600
voluseduration: 82,800
maxvoljobs: 0
maxvolfiles: 0
maxvolbytes: 0
inchanger: 1
endfile: 0
endblock: 0
volparts: 0
labeltype: 0
storageid: 1
----
LList in between jobs:
Pool: Daily
mediaid: 1
volumename: CFusionDaily0
slot: 0
poolid: 1
mediatype: File
firstwritten:
lastwritten:
labeldate: 02/14/2006 15:46:46
voljobs: 0
volfiles: 0
volblocks: 0
volmounts: 0
volbytes: 1
volerrors: 0
volwrites: 0
volcapacitybytes: 0
volstatus: Append
recycle: 1
volretention: 518,400
voluseduration: 82,800
maxvoljobs: 0
maxvolfiles: 0
maxvolbytes: 0
inchanger: 1
endfile: 0
endblock: 0
volparts: 0
labeltype: 0
storageid: 1
mediaid: 2
volumename: CFusionDaily1
slot: 0
poolid: 1
mediatype: File
firstwritten:
lastwritten:
labeldate: 02/14/2006 15:47:03
voljobs: 0
volfiles: 0
volblocks: 0
volmounts: 0
volbytes: 1
volerrors: 0
volwrites: 0
volcapacitybytes: 0
volstatus: Append
recycle: 1
volretention: 518,400
voluseduration: 82,800
maxvoljobs: 0
maxvolfiles: 0
maxvolbytes: 0
inchanger: 1
endfile: 0
endblock: 0
volparts: 0
labeltype: 0
storageid: 1
Pool: Weekly
mediaid: 3
volumename: CFusionWeekly0
slot: 0
poolid: 2
mediatype: File
firstwritten: 02/14/2006 15:53:33
lastwritten: 02/14/2006 15:53:43
labeldate: 02/14/2006 15:53:33
voljobs: 1
volfiles: 0
volblocks: 231
volmounts: 1
volbytes: 14,861,739
volerrors: 0
volwrites: 232
volcapacitybytes: 0
volstatus: Append
recycle: 1
volretention: 2,505,600
voluseduration: 82,800
maxvoljobs: 0
maxvolfiles: 0
maxvolbytes: 0
inchanger: 1
endfile: 0
endblock: 14,861,941
volparts: 0
labeltype: 0
storageid: 1
smime.p7s
Description: S/MIME cryptographic signature
