I remove the ^M's
On 14 Feb 2006 at 17:40, Brian A. Seklecki wrote:
> ...with -d99999, here are the relevant decision making parts:
>
> Without looking at the code, I think this may be a database error
> related to:
>
> mindwipe-dir: postgresql.c:334 my_postgresql_fetch_row finishes
> returning 8128018
> mindwipe-dir: next_vol.c:62 catreq after find_next_vol ok=3D1 FW=3D0
> mindwipe-dir: next_vol.c:175 VolJobs=3D1 FirstWritten=3D0
>
> But I'll have to check.
Why do you think it's a database error?
>
> Full Debug:
>
> mindwipe-dir: next_vol.c:46 CatReq FindMedia: Id=3D2, MediaType=3DFile
> mindwipe-dir: postgresql.c:408 my_postgresql_query started
> mindwipe-dir: postgresql.c:418 my_postgresql_query starts with 'SELECT
> MediaId,VolumeName,VolJobs,VolFiles,VolBlocks,VolBytes,VolMounts,V
> olErrors,VolWrites,MaxVolBytes,VolCapacityBytes,VolRetention,VolUseDuration=
> ,MaxVolJobs,MaxVolFiles,Recycle,Slot,FirstWritten,LastWritten,
> VolStatus,InChanger,VolParts,LabelType FROM Media WHERE PoolId=3D2 AND
> MediaType=3D'File' AND VolStatus=3D'Append' ORDER BY LastWritten IS NUL
> L,LastWritten DESC,MediaId LIMIT 1'
> mindwipe-dir: postgresql.c:422 we have a result
> mindwipe-dir: postgresql.c:426 we have 23 fields
> mindwipe-dir: postgresql.c:429 we have 1 rows
> mindwipe-dir: postgresql.c:437 my_postgresql_query finishing
> mindwipe-dir: postgresql.c:301 my_postgresql_fetch_row start
> mindwipe-dir: postgresql.c:304 we have need space of 92 bytes
> mindwipe-dir: postgresql.c:320 my_postgresql_fetch_row row number '0' is
> acceptable (0..1)
> mindwipe-dir: postgresql.c:324 my_postgresql_fetch_row field '0' has
> value '7'
> mindwipe-dir: postgresql.c:324 my_postgresql_fetch_row field '1' has
> value 'CFusionWeekly0'
> mindwipe-dir: postgresql.c:418 my_postgresql_query starts with 'SELECT
> MediaId,VolumeName,VolJobs,VolFiles,VolBlocks,VolBytes,VolMounts,V
> olErrors,VolWrites,MaxVolBytes,VolCapacityBytes,VolRetention,VolUseDuration=
> ,MaxVolJobs,MaxVolFiles,Recycle,Slot,FirstWritten,LastWritten,
> VolStatus,InChanger,VolParts,LabelType FROM Media WHERE PoolId=3D2 AND
> MediaType=3D'File' AND VolStatus=3D'Append' ORDER BY LastWritten IS NUL
> L,LastWritten DESC,MediaId LIMIT 1'
> mindwipe-dir: postgresql.c:422 we have a result
> mindwipe-dir: postgresql.c:426 we have 23 fields
> mindwipe-dir: postgresql.c:429 we have 1 rows
> mindwipe-dir: postgresql.c:437 my_postgresql_query finishing
> mindwipe-dir: postgresql.c:301 my_postgresql_fetch_row start
> mindwipe-dir: postgresql.c:304 we have need space of 92 bytes
> mindwipe-dir: postgresql.c:320 my_postgresql_fetch_row row number '0' is
> acceptable (0..1)
> mindwipe-dir: postgresql.c:324 my_postgresql_fetch_row field '0' has
> value '7'
> mindwipe-dir: postgresql.c:324 my_postgresql_fetch_row field '1' has
> value 'CFusionWeekly0'
> mindwipe-dir: postgresql.c:324 my_postgresql_fetch_row field '2' has
> value '1'
> mindwipe-dir: postgresql.c:324 my_postgresql_fetch_row field '3' has
> value '0'
> mindwipe-dir: postgresql.c:324 my_postgresql_fetch_row field '4' has
> value '35'
> mindwipe-dir: postgresql.c:324 my_postgresql_fetch_row field '5' has
> value '2246868'
> mindwipe-dir: postgresql.c:324 my_postgresql_fetch_row field '6' has
> value '1'
> mindwipe-dir: postgresql.c:324 my_postgresql_fetch_row field '7' has
> value '0'
> mindwipe-dir: postgresql.c:324 my_postgresql_fetch_row field '8' has
> value '36'
> mindwipe-dir: postgresql.c:324 my_postgresql_fetch_row field '9' has
> value '0'
> mindwipe-dir: postgresql.c:324 my_postgresql_fetch_row field '10' has
> value '0'
> mindwipe-dir: postgresql.c:324 my_postgresql_fetch_row field '11' has
> value '2505600'
> mindwipe-dir: postgresql.c:324 my_postgresql_fetch_row field '12' has
> value '82800'
> mindwipe-dir: postgresql.c:324 my_postgresql_fetch_row field '13' has
> value '0'
> mindwipe-dir: postgresql.c:324 my_postgresql_fetch_row field '14' has
> value '0'
> mindwipe-dir: postgresql.c:324 my_postgresql_fetch_row field '15' has
> value '1'
> mindwipe-dir: postgresql.c:324 my_postgresql_fetch_row field '16' has
> value '0'
> mindwipe-dir: postgresql.c:324 my_postgresql_fetch_row field '17' has
> value '02/14/2006 17:06:15'
> mindwipe-dir: postgresql.c:324 my_postgresql_fetch_row field '18' has
> value '02/14/2006 17:06:20'
> mindwipe-dir: postgresql.c:324 my_postgresql_fetch_row field '19' has
> value 'Append'
> mindwipe-dir: postgresql.c:324 my_postgresql_fetch_row field '20' has
> value '1'
> mindwipe-dir: postgresql.c:324 my_postgresql_fetch_row field '21' has
> value '0'
> mindwipe-dir: postgresql.c:324 my_postgresql_fetch_row field '22' has
> value '0'
> mindwipe-dir: postgresql.c:334 my_postgresql_fetch_row finishes
> returning 8128018
> mindwipe-dir: next_vol.c:62 catreq after find_next_vol ok=3D1 FW=3D0
> mindwipe-dir: next_vol.c:175 VolJobs=3D1 FirstWritten=3D0
> mindwipe-dir: message.c:993 Enter Jmsg type=3D6
> mindwipe-dir: message.c:565 Enter dispatch_msg type=3D6 msg=3Dmindwipe-dir:
> Max configured use duration exceeded. Marking Volume "CFusionWeek
> ly0" as Used.
> mindwipe-dir: message.c:659 MAIL for following msg: mindwipe-dir: Max
> configured use duration exceeded. Marking Volume "CFusionWeekly0" a
> s Used.
> mindwipe-dir: message.c:606 CONSOLE for following msg: mindwipe-dir: Max
> configured use duration exceeded. Marking Volume "CFusionWeekly0
> " as Used.
> mindwipe-dir: message.c:699 APPEND for following msg: mindwipe-dir: Max
> configured use duration exceeded. Marking Volume "CFusionWeekly0"
> as Used.
> mindwipe-dir: sql_update.c:293 update_media: FirstWritten=3D0
> mindwipe-dir: sql_update.c:350 UPDATE Media SET
> VolJobs=3D1,VolFiles=3D0,VolBlocks=3D35,VolBytes=3D2246868,VolMounts=3D1,Vo=
> lErrors=3D0,VolWrites=3D36,M
> axVolBytes=3D0,VolStatus=3D'Used',Slot=3D0,InChanger=3D1,VolReadTime=3D0,Vo=
> lWriteTime=3D0,VolParts=3D0,LabelType=3D0,StorageId=3D0,PoolId=3D2,VolReten=
> tion=3D25
> 05600,VolUseDuration=3D82800,MaxVolJobs=3D0,MaxVolFiles=3D0 WHERE
> VolumeName=3D'CFusionWeekly0'
> mindwipe-dir: postgresql.c:408 my_postgresql_query started
> mindwipe-dir: postgresql.c:418 my_postgresql_query starts with 'UPDATE
> Media SET VolJobs=3D1,VolFiles=3D0,VolBlocks=3D35,VolBytes=3D2246868,VolMo
> unts=3D1,VolErrors=3D0,VolWrites=3D36,MaxVolBytes=3D0,VolStatus=3D'Used',Sl=
> ot=3D0,InChanger=3D1,VolReadTime=3D0,VolWriteTime=3D0,VolParts=3D0,LabelTyp=
> e=3D0,Sto
> rageId=3D0,PoolId=3D2,VolRetention=3D2505600,VolUseDuration=3D82800,MaxVolJ=
> obs=3D0,MaxVolFiles=3D0 WHERE VolumeName=3D'CFusionWeekly0''
>
>
> ~BAS
>
> On Tue, 2006-02-14 at 16:03 -0500, Brian A. Seklecki wrote:
> > Platform:
> > $ uname -a
> > FreeBSD mindwipe 5.3-RELEASE-p23 FreeBSD 5.3-RELEASE-p23 #0: Wed Oct 12=20
> >=20
> > -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)
> >=20
> >=20
> > Here's what I know so far:
> >=20
> > *) 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
> >=20
> > Description:
> >=20
> > 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.
> >=20
> > Pool {
> > Name =3D Daily
> > Volume Use Duration =3D 23h
> > Pool Type =3D Backup
> > AutoPrune =3D yes
> > Recycle Oldest Volume =3D yes
> > VolumeRetention =3D 6d # recycle in 6 days
> > Maximum Volumes =3D 6
> > Recycle =3D yes
> > }
> >=20
> > Pool {
> > Name =3D Weekly
> > Pool Type =3D Backup
> > Volume Use Duration =3D 23h
> > AutoPrune =3D yes
> > VolumeRetention =3D 29d # recycle in 29 days
> > Maximum Volumes =3D 4
> > Recycle Oldest Volume =3D yes
> > Recycle =3D yes
> > }
> >=20
> > 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: ".
> >=20
> > 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". =20
> >=20
> > Here are the logs of the first job:
> > -------------------------------------------------
> >=20
> > 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=3DBlackout-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
> >=20
> > 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.
> >=20
> > Here are the logs of the second job (an 'llist media' between jobs can
> > be found below):
> >=20
> > ---------------------------------------------------------
> >=20
> > 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=3DBlackout-LDAP.2006-02-14_15.59.01
> > 14-Feb 15:59 mindwipe-dir: Max configured use duration exceeded. Marking
> > Volume "CFusionWeekly0" as Used.
> >=20
> >=20
> > --------------------------------------
> >=20
> > 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:
> >=20
> > firstwritten: 02/14/2006 15:53:33
> > lastwritten: 02/14/2006 15:53:43
> > labeldate: 02/14/2006 15:53:33
> >=20
> >=20
> > ---------------------------------------------------------
> > --------------------------------------------------------
> >=20
> > Here is the "llist media" prior to the first job:
> >=20
> > *llist media
> > Pool: Monthly
> > No results to list.
> > Pool: Daily
> > mediaid: 1
> > volumename: CFusionDaily0
> > slot: 0
> > poolid: 1
> > mediatype: File
> > firstwritten:=20
> > lastwritten:=20
> > 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
> >=20
> > mediaid: 2
> > volumename: CFusionDaily1
> > slot: 0
> > poolid: 1
> > mediatype: File
> > firstwritten:=20
> > lastwritten:=20
> > 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
> >=20
> > Pool: Weekly
> > mediaid: 3
> > volumename: CFusionWeekly0
> > slot: 0
> > poolid: 2
> > mediatype: File
> > firstwritten:=20
> > lastwritten:=20
> > 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
> >=20
> >=20
> >=20
> > ----
> >=20
> > LList in between jobs:
> > Pool: Daily
> > mediaid: 1
> > volumename: CFusionDaily0
> > slot: 0
> > poolid: 1
> > mediatype: File
> > firstwritten:=20
> > lastwritten:=20
> > 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
> >=20
> > mediaid: 2
> > volumename: CFusionDaily1
> > slot: 0
> > poolid: 1
> > mediatype: File
> > firstwritten:=20
> > lastwritten:=20
> > 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
> >=20
> > 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
> >=20
> >=20
> >=20
> >=20
> >=20
>
>
> -------------------------------------------------------
> This SF.net email is sponsored by: Splunk Inc. Do you grep through log files
> for problems? Stop! Download the new AJAX search engine that makes
> searching your log files as easy as surfing the web. DOWNLOAD SPLUNK!
> http://sel.as-us.falkag.net/sel?cmd=lnk&kid=103432&bid=230486&dat=121642
> _______________________________________________
> Bacula-users mailing list
> Bacula-users@lists.sourceforge.net
> https://lists.sourceforge.net/lists/listinfo/bacula-users
--
Dan Langille : Software Developer looking for work
my resume: http://www.freebsddiary.org/dan_langille.php
-------------------------------------------------------
This SF.net email is sponsored by: Splunk Inc. Do you grep through log files
for problems? Stop! Download the new AJAX search engine that makes
searching your log files as easy as surfing the web. DOWNLOAD SPLUNK!
http://sel.as-us.falkag.net/sel?cmd=lnk&kid=103432&bid=230486&dat=121642
_______________________________________________
Bacula-users mailing list
Bacula-users@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/bacula-users
