On Thursday 16 September 2010 15:25:07 Martin Simmons wrote:
> >>>>> On Wed, 15 Sep 2010 17:08:33 +0300, Silver Salonen said:
> >
> > On Wednesday 15 September 2010 16:49:18 Martin Simmons wrote:
> > > >>>>> On Wed, 15 Sep 2010 08:53:07 +0300, Silver Salonen said:
> > > >
> > > > On Tuesday 14 September 2010 21:54:21 Silver Salonen wrote:
> > > > > On 14.09.2010 18:48, Martin Simmons wrote:
> > > > > >>>>>> On Tue, 14 Sep 2010 15:54:11 +0300, Silver Salonen said:
> > > > > >>
> > > > > >> On Tuesday 14 September 2010 15:16:47 Martin Simmons wrote:
> > > > > >>>>>>>> On Tue, 14 Sep 2010 13:49:59 +0300, Silver Salonen said:
> > > > > >>>>
> > > > > >>>> On Tuesday 14 September 2010 10:59:09 Christian Manal wrote:
> > > > > >>>>> Am 14.09.2010 09:53, schrieb Silver Salonen:
> > > > > >>>>>> On Tuesday 14 September 2010 10:41:38 Christian Manal wrote:
> > > > > >>>>>>> Am 14.09.2010 09:30, schrieb Silver Salonen:
> > > > > >>>>>>>> On Tuesday 14 September 2010 10:13:49 Christian Manal wrote:
> > > > > >>>>>>>>> Am 14.09.2010 08:36, schrieb Silver Salonen:
> > > > > >>>>>>>>>> Hello.
> > > > > >>>>>>>>>>
> > > > > >>>>>>>>>> I use Bacula 5.0.2 on FreeBSD 8.0. I have a huge
> > > > > >>>>>>>>>> archive-type backup that has no full backup in its
> > > > > >>>>>>>>>> schedule:
> > > > > >>>>>>>>>>
> > > > > >>>>>>>>>> Schedule {
> > > > > >>>>>>>>>> Name = Archive
> > > > > >>>>>>>>>> Run = Level=Differential 1st fri at 23:05
> > > > > >>>>>>>>>> Run = Level=Incremental 2nd-5th fri at 23:05
> > > > > >>>>>>>>>> Run = Level=Incremental sat-thu at 23:05
> > > > > >>>>>>>>>> }
> > > > > >>>>>>>>>>
> > > > > >>>>>>>>>> The job builds its fileset dynamically with "/usr/bin/find
> > > > > >>>>>>>>>> /path/to/backup -type f -mtime +90d -print" - it takes a
> > > > > >>>>>>>>>> while, but does its job. From time-to-time the job just
> > > > > >>>>>>>>>> gets upgraded to full.. like today:
> > > > > >>>>>>>>>>
> > > > > >>>>>>>>>> 13-Sep 23:05 velvet-dir JobId 9135: 13-Sep 23:05
> > > > > >>>>>>>>>> velvet-dir JobId 9135: No prior or suitable Full backup
> > > > > >>>>>>>>>> found in catalog. Doing FULL backup.
> > > > > >>>>>>>>>> 13-Sep 23:05 velvet-dir JobId 9135: Start Backup JobId
> > > > > >>>>>>>>>> 9135, Job=userdata-archive.2010-09-13_23.05.01_05
> > > > > >>>>>>>>>>
> > > > > >>>>>>>>>> Any ideas why this happens?
> > > > > >>>>>>>>>>
> > > > > >>>>>>>>>> Is there a way to continue with incremental backups once
> > > > > >>>>>>>>>> such a full backup has been cancelled (eg. modifying
> > > > > >>>>>>>>>> Bacula DB manually)? It would really hurt to start from
> > > > > >>>>>>>>>> scratch with this archive.
> > > > > >>>>>>>>>>
> > > > > >>>>>>>>>
> > > > > >>>>>>>>>
> > > > > >>>>>>>>> Hi,
> > > > > >>>>>>>>>
> > > > > >>>>>>>>> did you set "Ignore FileSet Changes = yes" in your FileSet's
> > > > > >>>>>>>>> "Options"-Section? If not, the job level will be elevated
> > > > > >>>>>>>>> to full, if
> > > > > >>>>>>>>> the FileSet changes.
> > > > > >>>>>>>>>
> > > > > >>>>>>>>>
> > > > > >>>>>>>>> Regards,
> > > > > >>>>>>>>> Christian Manal
> > > > > >>>>>>>>
> > > > > >>>>>>>> Yes I did. Otherwise the job would be upgraded to full every
> > > > > >>>>>>>> time :)
> > > > > >>>>>>>>
> > > > > >>>>>>>
> > > > > >>>>>>> Well, it could have been, that the dynamically generated
> > > > > >>>>>>> FileSet only
> > > > > >>>>>>> changes now and then.
> > > > > >>>>>>
> > > > > >>>>>> The dataset is big enough to contain at least a modified file
> > > > > >>>>>> for every day :)
> > > > > >>>>>>
> > > > > >>>>>>>> This upgrade happened now after 35 days, ie the full backup
> > > > > >>>>>>>> was done 35 days ago, on 10th of August. Meanwhile only
> > > > > >>>>>>>> incrementals/differentials were done.
> > > > > >>>>>>>>
> > > > > >>>>>>>
> > > > > >>>>>>> What about your retention periods? Maybe the job or volume of
> > > > > >>>>>>> the last
> > > > > >>>>>>> full backup got pruned.
> > > > > >>>>>>
> > > > > >>>>>> Retention period of the full volume is 10 years. The client's
> > > > > >>>>>> file and job retention periods are 6 months. So I don't think
> > > > > >>>>>> configuration of any of these parameters' could have caused
> > > > > >>>>>> that.
> > > > > >>>>>>
> > > > > >>>>>> --
> > > > > >>>>>> Silver
> > > > > >>>>>>
> > > > > >>>>>
> > > > > >>>>>
> > > > > >>>>> Then I'm out of ideas. Sorry.
> > > > > >>>>>
> > > > > >>>>> Regards,
> > > > > >>>>> Christian Manal
> > > > > >>>>
> > > > > >>>> Thanks anyway. Any other ideas anyone?
> > > > > >>>
> > > > > >>> Is the Full job still shown by the list jobs command (i.e. is it
> > > > > >>> still in the
> > > > > >>> catalog at all)?
> > > > > >>
> > > > > >> Yes, with job status "A".
> > > > > >
> > > > > > Status "A" is a failure code for "Cancelled". Is that what you
> > > > > > expected?
> > > > > > Bacula will ignore that job when looking for the prior Full backup,
> > > > > > but you
> > > > > > can use delete jobid=... to delete it from the catalog.
> > > > > >
> > > > > > Is there an older one still in the list as well?
> > > > >
> > > > > Yes, the list has all the jobs since beginning of times, including
> > > > > the
> > > > > successful FULL one :)
> > > > >
> > > > > I now deleted the cancelled job from the list - let's see what
> > > > > happens
> > > > > today evening.
> > > > >
> > > > > >>> What did the last successful incremental print for the "Backup
> > > > > >>> Level" in the
> > > > > >>> log. It should give a date.
> > > > > >>
> > > > > >> The last incremental backup was not different from other
> > > > > >> incrementals.
> > > > > >>
> > > > > >> 12-Sep 23:05 velvet-dir JobId 9130: Start Backup JobId 9130,
> > > > > >> Job=userdata-archive.2010-09-12_23.05.04_00
> > > > > >> 12-Sep 23:05 velvet-dir JobId 9130: There are no more Jobs
> > > > > >> associated with Volume "userdata-archive-incr-0315". Marking it
> > > > > >> purged.
> > > > > >> 12-Sep 23:05 velvet-dir JobId 9130: All records pruned from Volume
> > > > > >> "userdata-archive-incr-0315"; marking it "Purged"
> > > > > >> 12-Sep 23:05 velvet-dir JobId 9130: Recycled volume
> > > > > >> "userdata-archive-incr-0315"
> > > > > >> 12-Sep 23:05 velvet-dir JobId 9130: Using Device "device-archive"
> > > > > >> 12-Sep 23:19 velvet-dir JobId 9130: Sending Accurate information.
> > > > > >> 12-Sep 23:21 velvet-sd JobId 9130: Recycled volume
> > > > > >> "userdata-archive-incr-0315" on device "device-archive"
> > > > > >> (/mnt/backup/bacula/), all previous data lost.
> > > > > >> 12-Sep 23:21 velvet-dir JobId 9130: Max Volume jobs exceeded.
> > > > > >> Marking Volume "userdata-archive-incr-0315" as Used.
> > > > > >> 12-Sep 23:59 velvet-sd JobId 9130: Job write elapsed time =
> > > > > >> 00:37:46, Transfer rate = 19 Bytes/second
> > > > > >
> > > > > > You chopped the part I wanted to see. Please post the whole job
> > > > > > log, down to
> > > > > > the start of the next job.
> > > > >
> > > > > This is from the e-mail Bacula server sent:
> > > > >
> > > > > 12-Sep 23:05 velvet-dir JobId 9130: Start Backup JobId 9130,
> > > > > Job=userdata-archive.2010-09-12_23.05.04_00
> > > > > 12-Sep 23:05 velvet-dir JobId 9130: There are no more Jobs associated
> > > > > with Volume "userdata-archive-incr-0315". Marking it purged.
> > > > > 12-Sep 23:05 velvet-dir JobId 9130: All records pruned from Volume
> > > > > "userdata-archive-incr-0315"; marking it "Purged"
> > > > > 12-Sep 23:05 velvet-dir JobId 9130: Recycled volume
> > > > > "userdata-archive-incr-0315"
> > > > > 12-Sep 23:05 velvet-dir JobId 9130: Using Device "device-archive"
> > > > > 12-Sep 23:19 velvet-dir JobId 9130: Sending Accurate information.
> > > > > 12-Sep 23:21 velvet-sd JobId 9130: Recycled volume
> > > > > "userdata-archive-incr-0315" on device "device-archive"
> > > > > (/mnt/backup/bacula/), all previous data lost.
> > > > > 12-Sep 23:21 velvet-dir JobId 9130: Max Volume jobs exceeded. Marking
> > > > > Volume "userdata-archive-incr-0315" as Used.
> > > > > 12-Sep 23:59 velvet-fd JobId 9130: Could not stat
> > > > > "/usr/local/repositories": ERR=No such file or directory
> > > > > 12-Sep 23:59 velvet-sd JobId 9130: Job write elapsed time = 00:37:46,
> > > > > Transfer rate = 19 Bytes/second
> > > > > 12-Sep 23:59 velvet-dir JobId 9130: Bacula velvet-dir 5.0.2
> > > > > (28Apr10):
> > > > > 12-Sep-2010 23:59:46
> > > > > Build OS: amd64-portbld-freebsd8.0 freebsd
> > > > > 8.0-RELEASE-p2
> > > > > JobId: 9130
> > > > > Job: userdata-archive.2010-09-12_23.05.04_00
> > > > > Backup Level: Incremental, since=2010-09-11 23:23:00
> > > > > Client: "velvet-fd" 5.0.2 (28Apr10)
> > > > > amd64-portbld-freebsd8.0,freebsd,8.0-RELEASE-p2
> > > > > FileSet: "userdata-archive" 2009-05-01 23:05:00
> > > > > Pool: "pool-userdata-archive-incr" (From Job
> > > > > IncPool override)
> > > > > Catalog: "MySQL" (From Client resource)
> > > > > Storage: "storage-archive" (From Job resource)
> > > > > Scheduled time: 12-Sep-2010 23:05:03
> > > > > Start time: 12-Sep-2010 23:19:20
> > > > > End time: 12-Sep-2010 23:59:46
> > > > > Elapsed time: 40 mins 26 secs
> > > > > Priority: 10
> > > > > FD Files Written: 193
> > > > > SD Files Written: 193
> > > > > FD Bytes Written: 17,283 (17.28 KB)
> > > > > SD Bytes Written: 44,068 (44.06 KB)
> > > > > Rate: 0.0 KB/s
> > > > > Software Compression: None
> > > > > VSS: no
> > > > > Encryption: no
> > > > > Accurate: yes
> > > > > Volume name(s): userdata-archive-incr-0315
> > > > > Volume Session Id: 174
> > > > > Volume Session Time: 1279692875
> > > > > Last Volume Bytes: 47,615 (47.61 KB)
> > > > > Non-fatal FD errors: 1
> > > > > SD Errors: 0
> > > > > FD termination status: OK
> > > > > SD termination status: OK
> > > > > Termination: Backup OK -- with warnings
> > > >
> > > > After deleting the cancelled full job, the next incremental job was
> > > > still upgraded to full. I then deleted the last successful incremental
> > > > job record from database too, but the job is still upgraded to full.
> > > >
> > > > Anything else to try?
> > >
> > > We need to find out why Bacula is rejecting the full backup.
> > >
> > > Please post the complete output from the incorrectly upgraded job as well.
> > >
> > > It would also be useful to see the output of
> > >
> > > llist jobid=aaa
> > > llist jobid=bbb
> > > llist jobid=ccc
> > >
> > > where:
> > >
> > > aaa is the jobid of the last good full backup.
> > > bbb is the jobid of the last good incremental backup still in the catalog
> > > ccc is the jobid of the incorrectly upgraded job.
> >
> > Here they come :)
> >
> > BTW, thanks for looking into it.
> >
> > A)
> >
> > 1000 OK: velvet-dir Version: 5.0.3 (04 August 2010)
> > Enter a period to cancel a command.
> > llist jobid=8960
> > Automatically selected Catalog: MySQL
> > Using Catalog "MySQL"
> > JobId: 8,960
> > Job: userdata-archive.2010-08-09_23.05.00_06
> > Name: userdata-archive
> > PurgedFiles: 0
> > Type: B
> > Level: F
> > ClientId: 1
> > Name: fd
> > JobStatus: T
> > SchedTime: 2010-08-09 23:05:00
> > StartTime: 2010-08-09 23:19:25
> > EndTime: 2010-08-10 22:13:35
> > RealEndTime: 2010-08-10 22:13:35
> > JobTDate: 1,281,467,615
> > VolSessionId: 4
> > VolSessionTime: 1,279,692,875
> > JobFiles: 1,086,225
> > JobErrors: 1
> > JobMissingFiles: 0
> > PoolId: 24
> > PooLname: pool-userdata-archive-full
> > PriorJobId: 0
> > FileSetId: 10
> > FileSet: userdata-archive
> >
> > B)
> >
> > 1000 OK: velvet-dir Version: 5.0.3 (04 August 2010)
> > Enter a period to cancel a command.
> > llist jobid=9110
> > Automatically selected Catalog: MySQL
> > Using Catalog "MySQL"
> > JobId: 9,110
> > Job: userdata-archive.2010-09-08_23.05.02_40
> > Name: userdata-archive
> > PurgedFiles: 0
> > Type: B
> > Level: I
> > ClientId: 1
> > Name: fd
> > JobStatus: T
> > SchedTime: 2010-09-08 23:05:02
> > StartTime: 2010-09-08 23:23:01
> > EndTime: 2010-09-09 00:12:52
> > RealEndTime: 2010-09-09 00:12:52
> > JobTDate: 1,283,980,372
> > VolSessionId: 154
> > VolSessionTime: 1,279,692,875
> > JobFiles: 4,365
> > JobErrors: 1
> > JobMissingFiles: 0
> > PoolId: 25
> > PooLname: pool-userdata-archive-incr
> > PriorJobId: 0
> > FileSetId: 10
> > FileSet: userdata-archive
> >
> > C)
> >
> > 1000 OK: velvet-dir Version: 5.0.3 (04 August 2010)
> > Enter a period to cancel a command.
> > llist jobid=9142
> > Automatically selected Catalog: MySQL
> > Using Catalog "MySQL"
> > JobId: 9,142
> > Job: userdata-archive.2010-09-15_08.50.38_19
> > Name: userdata-archive
> > PurgedFiles: 0
> > Type: B
> > Level: F
> > ClientId: 1
> > Name: fd
> > JobStatus: A
> > SchedTime: 2010-09-15 08:50:26
> > StartTime: 2010-09-15 08:50:40
> > EndTime: 2010-09-15 09:05:07
> > RealEndTime: 2010-09-15 09:05:07
> > JobTDate: 1,284,530,707
> > VolSessionId: 6
> > VolSessionTime: 1,284,447,278
> > JobFiles: 0
> > JobErrors: 1
> > JobMissingFiles: 0
> > PoolId: 24
> > PooLname: pool-userdata-archive-full
> > PriorJobId: 0
> > FileSetId: 10
> > FileSet: userdata-archive
>
> Those look normal to me, so they don't explain why job 9142 was upgraded.
>
> Does the job resource specify Max Full Interval? Bacula seems to be ignoring
> Full jobs older than 30 days / 1 month.
>
> If not, then try running with
>
> setdebug director level=100 trace=1
>
> The 50 lines in the trace file around the one that looks like
>
> have_full=... do_full=... now=... full_time=...
>
> would be useful to see.
Oh, that's just embarrasing - the job really had "Max Full Interval = 34d"
specified through JobDefs.. I set it to 0 now and the incremental job ran OK.
Sorry for such a silly mistake and thank you very much for the support, Martin.
PS. The "error" message could be a bit cleaner though - not that FULL was not
found, but rather than the FULL was not found within the specified interval or
smth.
--
Silver
------------------------------------------------------------------------------
Start uncovering the many advantages of virtual appliances
and start using them to simplify application deployment and
accelerate your shift to cloud computing.
http://p.sf.net/sfu/novell-sfdev2dev
_______________________________________________
Bacula-users mailing list
Bacula-users@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/bacula-users
