Bacula-users

Re: [Bacula-users] backup upgraded to FULL for no apparent reason

2010-09-15 10:11:29
Subject: Re: [Bacula-users] backup upgraded to FULL for no apparent reason
From: Silver Salonen <silver AT ultrasoft DOT ee>
To: bacula-users AT lists.sourceforge DOT net
Date: Wed, 15 Sep 2010 17:08:33 +0300
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

--
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 AT lists.sourceforge DOT net
https://lists.sourceforge.net/lists/listinfo/bacula-users

<Prev in Thread] Current Thread [Next in Thread>