Bacula-users

[Bacula-users] Wrong behavior of Incremental backup

2013-12-09 07:00:49
Subject: [Bacula-users] Wrong behavior of Incremental backup
From: "it AT kipspb DOT ru" <it AT kipspb DOT ru>
To: bacula-users AT lists.sourceforge DOT net
Date: Mon, 09 Dec 2013 15:38:33 +0400
Hello.
There are problems with size of some incremental backups in our installation.

We use bacula version 5.2.13-17.el6 from yum repository epel-bacula

on the platform Scientific Linux release 6.3 (Carbon).

There is 2 jobs for FileSet "FNAS automatix":

1. job for Base backup
Job {
Name = "j-base FNAS automatix"

Enabled = Yes
Type = Backup
Level = Base
Client = fnas-alpha-fd
Schedule = OnceBase
Storage = St-automatix
Pool = Full-Pool
Messages = Standard
FileSet = "FNAS automatix"
Full Backup Pool = Full-Pool
Priority = 10
}

2. job for Full, Differential and Incremental backup
Job {
Name = "j-dedup FNAS automatix"
Base = "j-base FNAS automatix", "j-dedup FNAS automatix"
Type = Backup
Accurate = yes
Client = fnas-alpha-fd
Schedule = WeeklyCycle
Storage = St-automatix
Pool = Default
Messages = Standard
FileSet = "FNAS automatix"
Full Backup Pool = Full-Pool
Incremental Backup Pool = Inc-Pool
Differential Backup Pool = Diff-Pool
Write Bootstrap = "/sd/bootstrap/%c.bsr"
Priority = 10
}

The base job 
(jobid 3638) was completed on 2013-10-11 17:11:38 with status "T".
Number of files and size of backup were as expected.
+-------+------------------------+---------------------+------+-------+-----------+-----------------+-----------+
| JobId | Name                   | StartTime           | Type | Level | JobFiles  | JobBytes        | JobStatus |
+-------+------------------------+---------------------+------+-------+-----------+-----------------+-----------+
| 3,638 | j-base FNAS automatix  | 2013-10-11 17:11:38 | B    | B     |    74,355 |  90,107,063,338 | T         |
| 3,652 | j-dedup FNAS automatix | 2013-10-11 23:05:18 | B    | F     |    74,357 |          34,155 | T         |
| 4,177 | j-dedup FNAS automatix | 2013-10-20 23:05:17 | B    | D     |       208 |      61,633,045 | T         |
| 4,591 | j-dedup FNAS automatix | 2013-10-27 23:06:07 | B    | D     |       215 |      63,088,695 | T         |
| 5,002 | j-dedup FNAS automatix | 2013-11-03 23:05:22 | B    | F     |    74,494 |     202,110,011 | T         |
| 5,400 | j-dedup FNAS automatix | 2013-11-10 23:05:16 | B    | D     |       231 |      96,181,157 | T         |
| 5,787 | j-dedup FNAS automatix | 2013-11-17 23:05:19 | B    | D     |       378 |     160,150,479 | T         |
| 6,185 | j-dedup FNAS automatix | 2013-11-24 23:05:25 | B    | D     |       691 |     189,529,241 | T         |
| 6,238 | j-dedup FNAS automatix | 2013-11-25 23:05:05 | B    | I     |        23 |      21,385,822 | T         |
| 6,295 | j-dedup FNAS automatix | 2013-11-26 23:05:19 | B    | I     |        32 |       8,855,122 | T         |
| 6,351 | j-dedup FNAS automatix | 2013-11-27 23:05:05 | B    | I     |        34 |       5,999,039 | T         |
| 6,408 | j-dedup FNAS automatix | 2013-11-28 23:05:15 | B    | I     |        18 |       9,265,824 | T         |
| 6,465 | j-dedup FNAS automatix | 2013-11-29 23:05:05 | B    | I     |        57 |       4,840,316 | T         |
| 6,522 | j-dedup FNAS automatix | 2013-11-30 23:05:17 | B    | I     |       377 |       9,345,024 | T         |
| 6,578 | j-dedup FNAS automatix | 2013-12-01 23:05:47 | B    | F     |    74,953 |     355,315,009 | T         |
| 6,699 | j-dedup FNAS automatix | 2013-12-03 23:05:19 | B    | I     |    74,438 |  90,017,638,926 | T         |
+-------+------------------------+---------------------+------+-------+-----------+-----------------+-----------+

Next was completed Full backup (job 3652, 2013-10-11 23:05:18).
Number of files and size of backup were as expected, i.e. number of files is almost the same as number of files in previous Base backup
and size was very small. The log of this jobs contains "Using BaseJobId(s): 3638"

After that
there were completed several backups of types Full, Differential and Incremental (jobs numbers from 4177 to 6578)
And again the number of files and size of backups were as expected (please, see table above)
including last Full backup (job_6578_log.txt in attachment), which size tell us that Base backup was taken into account.
The log of this jobs contains "Using BaseJobId(s): 3638"

The next job 6999 (Incremental backup) was unexpectedly large, its size was almost as size of the first Base backup.

We can not find out why.

We have checked CreateTime of FileSet - it wasn't changed:
mysql> SELECT * FROM FileSet WHERE FileSet = "FNAS automatix";
+-----------+----------------+------------------------+---------------------+
| FileSetId | FileSet        | MD5                    | CreateTime          |
+-----------+----------------+------------------------+---------------------+
|        21 | FNAS automatix | /+9Wn8hmM7Z58Fo5D++/oA | 2013-07-04 23:05:00 |
+-----------+----------------+------------------------+---------------------+

We have checked change and modification time (ctime, mtime) of files included in this Incremental backup.
They were not changed.
And log of this job (job_6699_log.txt) doesn't contain words about upgrading Incremental backup to Full.

According to question of FAQ "Incremental backups are not working" we attached:
- The bacula configuration directory, including bacula-dir.conf (bacula_config.tgz)
- The output from list jobs covering the period where we are having the problem (list_jobs.txt).
- The Job report output from the prior Full save (job_6578_log.txt)
- An llist jobid=3638 where 3638 is JobId of Base backup (list_jobid_3638.txt)
- An llist jobid=nnn where nnn is the JobId of the prior Full save (list_jobid_6578.txt)
- The Job report output from the save that is doing the wrong thing (job_6699_log.txt).
- An llist jobid=nnn where nnn is the JobId of the job that was not correct (list_jobid_6699.txt).
- An explanation of what job went wrong and why you think it did.

And the same issue took place last week with another FileSet.
Please, tell us if you need details of this second issue and we will send them ASAP.

Please, explain us what is wrong with our Bacula
and what we should change in our configuration to solve this problem.

Thank you in advance,
Vladimir Scherbo

Attachment: llist_jobid_6699.txt
Description: Text document

Attachment: bacula_conf.tgz
Description: application/compressed-tar

Attachment: list_jobs.txt
Description: Text document

Attachment: llist_jobid_3638.txt
Description: Text document

Attachment: llist_jobid_6578.txt
Description: Text document

Attachment: job_6578_log.txt
Description: Text document

Attachment: job_6699_log.txt
Description: Text document

------------------------------------------------------------------------------
Sponsored by Intel(R) XDK 
Develop, test and display web and hybrid apps with a single code base.
Download it for free now!
http://pubads.g.doubleclick.net/gampad/clk?id=111408631&iu=/4140/ostg.clktrk
_______________________________________________
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>