I've made some changes few days ago, please, can you test the lastest svn ? (you can update only the FD) and report the debug output ?
Thanks Le Wednesday 24 September 2008 19:11:40 Ulrich Leodolter, vous avez écrit : > Hello, > > On Wed, 2008-09-24 at 17:56 +0200, Kern Sibbald wrote: > > On Wednesday 24 September 2008 16:19:29 Ulrich Leodolter wrote: > > > Hello, > > > > > > ok, i've started bacula-fd in debug mode > > > > > > leodolter:~# nohup /opt/bacula/sbin/bacula-fd -f -d 200 -u root -g > > > bacula \ -c /opt/bacula/etc/bacula-fd.conf >& /tmp/bacula-fd.log > > > > > > then i've started 2 consecutive incremental backups, and again looked > > > at /usr/bin/wget, (i can send u 350MB debug file if u like) > > > > > > leodolter:~# fgrep '/usr/bin/wget' /tmp/bacula-fd.log > > > leodolter-fd: htable.c:288-3680 Insert hp->next=0 hp->hash=0x59616a69 > > > hp->key=/usr/bin/wget leodolter-fd: htable.c:294-3680 Leave insert > > > index=25223 num_items=50014 key=/usr/bin/wget leodolter-fd: > > > backup.c:1210-3680 No strip for /usr/bin/wget > > > leodolter-fd: accurate.c:182-3680 /usr/bin/wget st_mtime differs > > > leodolter-fd: backup.c:307-3680 FT_REG saving: /usr/bin/wget > > > leodolter-fd: backup.c:402-3680 bfiled: sending /usr/bin/wget to stored > > > leodolter-fd: backup.c:1210-3680 No strip for /usr/bin/wget > > > leodolter-fd: bfile.c:835-3680 open file /usr/bin/wget > > > leodolter-fd: htable.c:288-3681 Insert hp->next=0 hp->hash=0x59616a69 > > > hp->key=/usr/bin/wget leodolter-fd: htable.c:294-3681 Leave insert > > > index=25223 num_items=50014 key=/usr/bin/wget leodolter-fd: > > > backup.c:1210-3681 No strip for /usr/bin/wget > > > leodolter-fd: accurate.c:182-3681 /usr/bin/wget st_mtime differs > > > leodolter-fd: backup.c:307-3681 FT_REG saving: /usr/bin/wget > > > leodolter-fd: backup.c:402-3681 bfiled: sending /usr/bin/wget to stored > > > leodolter-fd: backup.c:1210-3681 No strip for /usr/bin/wget > > > leodolter-fd: bfile.c:835-3681 open file /usr/bin/wget > > > > > > as u see , st_mtime is the reason. > > > but i am very sure that st_mtime did not change between incremental > > > backups! verified that st_time did not change using a simple perl > > > script called it before and after incremental jobs. > > > > When I look at the above, it looks perfectly normal to me. I see that > > st_mtime is different from the last backup, but that you are running two > > simultaneous jobs that seem to have the same FileSet, so they both want > > to save the same file. This is normal. If you want the second job to > > take into account what the first job backs up, you must ensure that it > > starts after the first job has finished. > > I have started the second Job after the first finished, look at Start > and End time below, there are 2 minutes between. Look also at > the number of Files written, this looks very strange to me! > i am sure my system does not touch or modify more than 20000 files in 2 > minutes. /usr/bin/wget i just an example. > > again: when i look at the file names backed up, i looks like accurate > incremental backups are only compared against last full. > > Build OS: i686-pc-linux-gnu redhat Enterprise release > JobId: 3680 > Job: Backup-leodolter.2008-09-24_15.49.11 > Backup Level: Incremental, since=2008-09-24 02:05:06 > Client: "leodolter-fd" 2.5.3 (16Sep08) > i686-pc-linux-gnu,debian,lenny/sid FileSet: > "LinuxLocalPartitions" 2008-05-23 14:56:44 Pool: > "DiskBackup" (From Job resource) > Catalog: "MyCatalog" (From Client resource) > Storage: "File" (From Job resource) > Scheduled time: 24-Sep-2008 15:48:58 > Start time: 24-Sep-2008 15:49:03 > End time: 24-Sep-2008 15:51:32 > Elapsed time: 2 mins 29 secs > Priority: 10 > FD Files Written: 22,297 > SD Files Written: 22,297 > FD Bytes Written: 249,462,630 (249.4 MB) > SD Bytes Written: 252,590,613 (252.5 MB) > Rate: 1674.2 KB/s > Software Compression: 63.2 % > VSS: no > Encryption: no > Accurate: yes > Volume name(s): Backup-0158 > Volume Session Id: 178 > Volume Session Time: 1221573719 > Last Volume Bytes: 2,297,116,205 (2.297 GB) > Non-fatal FD errors: 0 > SD Errors: 0 > FD termination status: OK > SD termination status: OK > Termination: Backup OK > > Build OS: i686-pc-linux-gnu redhat Enterprise release > JobId: 3681 > Job: Backup-leodolter.2008-09-24_15.53.12 > Backup Level: Incremental, since=2008-09-24 15:49:03 > Client: "leodolter-fd" 2.5.3 (16Sep08) > i686-pc-linux-gnu,debian,lenny/sid FileSet: > "LinuxLocalPartitions" 2008-05-23 14:56:44 Pool: > "DiskBackup" (From Job resource) > Catalog: "MyCatalog" (From Client resource) > Storage: "File" (From Job resource) > Scheduled time: 24-Sep-2008 15:53:32 > Start time: 24-Sep-2008 15:53:43 > End time: 24-Sep-2008 15:56:18 > Elapsed time: 2 mins 35 secs > Priority: 10 > FD Files Written: 22,299 > SD Files Written: 22,299 > FD Bytes Written: 249,462,803 (249.4 MB) > SD Bytes Written: 252,591,047 (252.5 MB) > Rate: 1609.4 KB/s > Software Compression: 63.2 % > VSS: no > Encryption: no > Accurate: yes > Volume name(s): Backup-0158 > Volume Session Id: 179 > Volume Session Time: 1221573719 > Last Volume Bytes: 2,550,602,312 (2.550 GB) > Non-fatal FD errors: 0 > SD Errors: 0 > FD termination status: OK > SD termination status: OK > Termination: Backup OK > > > If you really think that st_mtime has not changed since the last backup, > > then please find the backup record in the catalog associated with the > > previous backup job, and list it as well as the backup record from one of > > the two jobs above. > > There a 2 minutes between End time of Job 3680 > and Start time of Job 3681 (see above) > > I don't think, i am sure st_time of /usr/bin/wget did not change. > I used system call lstat to read st_mtime before i started Job 3680 > and after Job 3681 finished, it was exactly the same. > > Bacula reports different st_mtime, but stores the same st_mtime. > Look at the sql query result, u can see that only the 11'th column > st_atime in LStat changed, which is totally correct, but st_mtime and > st_ctime are the same. > (hopefully your email reader does not break lines) > > mysql> select File.JobId, File.FileId, > Filename.Name,Path.Path,File.LStat,File.MD5 from File join Filename using > (FilenameId) > join Path using (PathId) where File.JobId in (3680,3681) and > Filename.Name = 'wget'; > +-------+----------+------+-----------+------------------------------------ >------------------------+-----------------------------+ > > | JobId | FileId | Name | Path | LStat > | | MD5 | > > +-------+----------+------+-----------+------------------------------------ >------------------------+-----------------------------+ > > | 3680 | 79476174 | wget | /usr/bin/ | P4A HECd IHt B A A A 3PU BAA HI > | BI2kMY BIxGDt BI11Hr A A E | FyVUN2j34bKjITbKF5khOovbiGs | 3681 | > | 79498472 | wget | /usr/bin/ | P4A HECd IHt B A A A 3PU BAA HI BI2kWI > | BIxGDt BI11Hr A A E | FyVUN2j34bKjITbKF5khOovbiGs | > > +-------+----------+------+-----------+------------------------------------ >------------------------+-----------------------------+ 2 rows in set (0.22 > sec) > > > I may be missing something here, but this looks normal to me. I cannot > > rule out a bug with st_mtime with the new code, but I would like to see > > more information before asking Eric to look into it. > > > > Regards, > > > > Kern > > Thanks > Ulrich > > > > so please tell me which st_mtime are compared? > > > (maybe there is a hash code bug in accurrate.c, just thinking > > > because i dont understand) > > > > > > [EMAIL PROTECTED]:~$ bin/ul_bacula_lstat.pl /usr/bin/wget > > > dev = 65024 P4A > > > ino = 1851549 HECd > > > mode = 33261 IHt > > > nlink = 1 B > > > uid = 0 A > > > gid = 0 A > > > rdev = 0 A > > > size = 226260 3PU > > > atime = 1222265400 BI2ko4 > > > mtime = 1220829421 BIxGDt > > > ctime = 1222070763 BI11Hr > > > blksize = 4096 BAA > > > blocks = 456 HI > > > sha1 = FyVUN2j34bKjITbKF5khOovbiGs > > > > > > > > > mysql> select File.JobId, Filename.Name,Path.Path,File.LStat,File.MD5 > > > from File join Filename using (FilenameId) > > > join Path using (PathId) where File.JobId in > > > (3574,3605,3637,3669,3680,3681) and Filename.Name = 'wget'; > > > +-------+------+-----------+------------------------------------------- > > >---- -------------+-----------------------------+ > > > > > > | JobId | Name | Path | LStat > > > | > > > | | MD5 | > > > > > > +-------+------+-----------+------------------------------------------- > > >---- -------------+-----------------------------+ > > > > > > | 3574 | wget | /usr/bin/ | P4A HEEh IHt B A A A 3PU BAA HI BIz28l > > > | BIaVNu BIfhPi A A E | 8dz2rHajxE25WMWnQ2U6DUja/MI | 3637 | wget | > > > | /usr/bin/ | P4A HECd IHt B A A A 3PU BAA HI BI2CXZ BIxGDt BI11Hr A A > > > | E | FyVUN2j34bKjITbKF5khOovbiGs | 3669 | wget | /usr/bin/ | P4A HECd > > > | IHt B A A A 3PU BAA HI BI2DL7 BIxGDt BI11Hr A A E | > > > | FyVUN2j34bKjITbKF5khOovbiGs | 3680 | wget | /usr/bin/ | P4A HECd IHt > > > | B A A A 3PU BAA HI BI2kMY BIxGDt BI11Hr A A E | > > > | FyVUN2j34bKjITbKF5khOovbiGs | 3681 | wget | /usr/bin/ | P4A HECd IHt > > > | B A A A 3PU BAA HI BI2kWI BIxGDt BI11Hr A A E | > > > | FyVUN2j34bKjITbKF5khOovbiGs | > > > > > > +-------+------+-----------+------------------------------------------- > > >---- -------------+-----------------------------+ > > > > > > > > > Please have a closer look at this > > > Ulrich > > > > > > On Wed, 2008-09-24 at 14:01 +0200, Eric Bollengier wrote: > > > > Hello, > > > > > > > > On Wednesday 24 September 2008 13:34:53 Kern Sibbald wrote: > > > > > Hello, > > > > > > > > > > On Wednesday 24 September 2008 11:52:41 Ulrich Leodolter wrote: > > > > > > Hi, > > > > > > > > > > > > I looks like Accurate Incremental backups work not like expected. > > > > > > > > > > > > I am using current bacula trunk, last update 2008-09-16. > > > > > > No config changes since last update. > > > > > > > > > > > > Below is a Job list where i tried to track down the problem. > > > > > > On Monday Sep 22 i did a system update (apt-get), so 20794 Files > > > > > > are ok for Job 3637. But i did not make major changes on Sep 23, > > > > > > so 21725 Files for Job 3669 are not expected! > > > > > > > > > > > > > > > > > > JobId JobName Status Level Client Pool StartTime EndTime Duration > > > > > > Files Bytes 3574 Backup-leodolter OK F leodolter-fd DiskBackup > > > > > > 08-Sep-21 02:05 08-Sep-21 02:26 00:21:45 178,917 4.5 GB 3605 > > > > > > Backup-leodolter OK I leodolter-fd DiskBackup 08-Sep-22 02:05 > > > > > > 08-Sep-22 02:06 00:01:27 202 13.3 MB 3637 Backup-leodolter OK > > > > > > I leodolter-fd DiskBackup 08-Sep-23 02:05 08-Sep-23 02:07 > > > > > > 00:02:34 20,794 187.6 MB 3669 Backup-leodolter OK I leodolter-fd > > > > > > DiskBackup 08-Sep-24 02:05 08-Sep-24 02:07 00:02:42 21,725 192.6 > > > > > > MB > > > > > > > > > > > > > > > > > > Now i looked at some special file /usr/bin/wget (see mysql select > > > > > > below) As far as i can see only st_atime (11'th field in LStat) > > > > > > changed from 23 Sep (JobId 3637) to 24 Sep (JobId 3669). > > > > > > > > > > > > Until now i thought st_atime is not used for Accurate backups. > > > > > > > > > > To the best of my knowledge, st_atime is not used by Bacula to make > > > > > any decision whether or not to backup the file. The tests are > > > > > strictly against st_mtime and st_ctime (depending on how you > > > > > configure Bacula). > > > > > > > > > > It sounds to me like you have a problem of an anti-virus program > > > > > that is "touching" some files or some other change to your system > > > > > happened. Running verify InitCatalog, then later Catalog can verify > > > > > this ... > > > > > > > > > > > For me i looks like Accurate Incremental backups are always made > > > > > > against last Full while ignoring previous Accurate Incremental > > > > > > jobs (maybe i am completely wrong) > > > > > > > > > > I haven't taken a careful look at all the details you presented > > > > > above, but Accurate works very much like existing backups -- that > > > > > is it looks at st_mtime and st_ctime (if I am not mistaken), and if > > > > > the file needs to be backed up for the "normal" backup reasons, it > > > > > will be. What Accurate does is in *addition* to the "normal" > > > > > rules, it will check to see if a file has been deleted or has been > > > > > added with an old date, and in those cases, it ensures that files > > > > > that are deleted are so marked, and any file that is missed by the > > > > > normal backup will also be backed up. > > > > > > > > > > I'll let Eric confirm this. > > > > > > > > I confirm :) > > > > > > > > Ulrich, you can try to run the the FD at debuglevel 200, and you will > > > > see why the file has been backuped. > > > > > > > > Bye > > > > > > > > > If it is not working like I described above, then please let me > > > > > know and we can look at it in more details. > > > > > > > > > > Best regards, > > > > > > > > > > Kern > > > > > > > > > > > mysql> select File.JobId, > > > > > > Filename.Name,Path.Path,File.LStat,File.MD5 from File join > > > > > > Filename using (FilenameId) > > > > > > join Path using (PathId) > > > > > > where File.JobId in (3574,3605,3637,3669) and Filename.Name = > > > > > > 'wget'; > > > > > > > > > > > > +-------+------+-----------+------------------------------------- > > > > > >---- ---- -- -------------+-----------------------------+ > > > > > > > > > > > > | JobId | Name | Path | LStat > > > > > > | > > > > > > | | MD5 | > > > > > > > > > > > > +-------+------+-----------+------------------------------------- > > > > > >---- ---- -- -------------+-----------------------------+ > > > > > > > > > > > > | 3574 | wget | /usr/bin/ | P4A HEEh IHt B A A A 3PU BAA HI > > > > > > | BIz28l BIaVNu BIfhPi A A E | 8dz2rHajxE25WMWnQ2U6DUja/MI | 3637 > > > > > > | | wget | /usr/bin/ | P4A HECd IHt B A A A 3PU BAA HI BI2CXZ > > > > > > | BIxGDt BI11Hr A A E > > > > > > | > > > > > > | FyVUN2j34bKjITbKF5khOovbiGs | 3669 | wget | /usr/bin/ | P4A > > > > > > | HECd IHt B A A A 3PU BAA HI BI2DL7 BIxGDt BI11Hr A A E | > > > > > > | FyVUN2j34bKjITbKF5khOovbiGs | > > > > > > > > > > > > +-------+------+-----------+------------------------------------- > > > > > >---- ---- -- -------------+-----------------------------+ 3 rows > > > > > > in set (0.00 sec) > > > > > > > > > > > > > > > > > > Please have a look at this > > > > > > Thanks ------------------------------------------------------------------------- This SF.Net email is sponsored by the Moblin Your Move Developer's challenge Build the coolest Linux based applications with Moblin SDK & win great prizes Grand prize is a trip for two to an Open Source event anywhere in the world http://moblin-contest.org/redirect.php?banner_id=100&url=/ _______________________________________________ Bacula-devel mailing list [email protected] https://lists.sourceforge.net/lists/listinfo/bacula-devel
