Bacula-users

[Bacula-users] Exchange plugin always truncating logs (when it should not)

2012-05-04 12:33:09
Subject: [Bacula-users] Exchange plugin always truncating logs (when it should not)
From: Guido Falsi <mad AT madpilot DOT net>
To: bacula-users AT lists.sourceforge DOT net
Date: Fri, 4 May 2012 18:11:26 +0200
Hi!

I've been using bacula to backup an exchange 2003 server for some time with
success. You could say I'm an happy user :)

Lately I noticed bacula started truncating logs on EVERY backup, also
incrementals and differentials, when it should not.

I'm not sure when this happened. I'm inclined to thing it started when
I upgraded to 5.2.6 But I don't have logs handy till them. I can try to
reover them from some backup perhaps.

The machine is a Windows 2003 R2 server, 32 bit. I used the installer
from the project page on sourceforge to install bacula.

If needed I can try installing a previous version on this client and see
if this makes the problem disappear. Is such a scenario(older client)
supported?

The job description is unmodified since february 2011, and I'm sure it
was not truncating logs back then.

here's the job definition (defaults too):

JobDefs {
        Name = "DefaultJob"
        Type = Backup
        Level = Full
        Accurate = yes
        Messages = Standard
        Pool = Default
        Priority = 10
        SpoolData = no
        Spool Attributes = yes
        Write Bootstrap = "/var/db/bacula/Bootstraps/%c_%n"
        Max Start Delay = 20 h
        Enabled = yes
}

Job {
        Name = "nifi10MonthlyMain"
        Jobdefs = "DefaultJob"
        Schedule = "MonthlyCycleMain"
        Storage = "Storageworks-1"
        Client = "ntfi10-fd"
        FileSet = "ntfi10 Set"
        # Exchange plugin not tested with accurate backups. Don't
        # use the option.
        Accurate = no
        Client Run Before Job = "PreBCK.bat before"
        Client Run After Job = "PreBCK.bat after"
}

FileSet {
        Name = "ntfi10 Set"
        Enable VSS = yes
        Include {
                Options {
                        Signature = SHA1
                }
                Plugin = "exchange:/@EXCHANGE/Microsoft Information
Store"
                File = "E:/Exchsrvr/NTFI10.log"
                File = "E:/Exchsrvr/Old-logs"
                File = "D:/Save_DB_Marcatempo"
                File = "D:/Software"
                File = "D:/tmp_BO"
                File = "E:/Documenti"
                File = "E:/backup"
        }
}

The accurate and Enable VSS line have always been like that. So I don't
think they're problematic.

I'm quite sure that up to last year this configuration DID work as
expected.

Here are the messages from an Incremental:

03-May 23:51 uxifi04-dir JobId 26741: Start Backup JobId 26741, 
Job=nifi10MonthlyMain.2012-05-03_22.30.01_42
03-May 23:51 uxifi04-dir JobId 26741: Using Device "Ultrium-1"
03-May 23:51 ntfi10-fd JobId 26741: shell command: run ClientRunBeforeJob 
"PreBCK.bat before"
03-May 23:51 ntfi10-fd JobId 26741: ClientRunBeforeJob: 
03-May 23:51 ntfi10-fd JobId 26741: ClientRunBeforeJob: C:\WINDOWS\system32>REM 
$VGFi: PreBCK.bat,v 1.2 2010/01/19 15:40:24 gfalsi Exp $ 
03-May 23:51 ntfi10-fd JobId 26741: ClientRunBeforeJob: 
03-May 23:51 ntfi10-fd JobId 26741: ClientRunBeforeJob: C:\WINDOWS\system32>if 
"before" == "before" goto create 
03-May 23:51 ntfi10-fd JobId 26741: ClientRunBeforeJob: 
03-May 23:51 ntfi10-fd JobId 26741: ClientRunBeforeJob: 
C:\WINDOWS\system32>C:\windows\system32\ntbackup.exe backup systemstate /J 
"NTFI10 SystemState" /F "E:\backup\ntfi10-systemstate.bkf" /R:yes /L:n /SNAP:on 
03-May 23:55 ntfi10-fd JobId 26741: ClientRunBeforeJob: 
03-May 23:55 ntfi10-fd JobId 26741: ClientRunBeforeJob: 
C:\WINDOWS\system32>goto :scend 
03-May 23:55 ntfi10-fd JobId 26741: ClientRunBeforeJob: 
03-May 23:55 ntfi10-fd JobId 26741: ClientRunBeforeJob: 
C:\WINDOWS\system32>exit 0 
03-May 23:55 uxifi04-sd JobId 26741: Spooling data ...
03-May 23:55 ntfi10-fd JobId 26741: Generate VSS snapshots. Driver="Win32 VSS", 
Drive(s)="ED"
03-May 23:58 ntfi10-fd JobId 26741: Preparing Exchange Backup for NTFI10
03-May 23:58 ntfi10-fd JobId 26741: Truncated database logs for Storage Group 
First Storage Group
03-May 23:58 ntfi10-fd JobId 26741: Truncated database logs for Storage Group 
Second Storage Group
03-May 23:58 ntfi10-fd JobId 26741: Truncated database logs for Storage Group 
Third Storage Group
03-May 23:58 ntfi10-fd JobId 26741: VSS Writer (BackupComplete): "System 
Writer", State: 0x1 (VSS_WS_STABLE)
03-May 23:58 ntfi10-fd JobId 26741: VSS Writer (BackupComplete): "Microsoft 
Exchange Writer", State: 0x1 (VSS_WS_STABLE)
03-May 23:58 ntfi10-fd JobId 26741: VSS Writer (BackupComplete): "IIS Metabase 
Writer", State: 0x1 (VSS_WS_STABLE)
03-May 23:58 ntfi10-fd JobId 26741: VSS Writer (BackupComplete): "MSDEWriter", 
State: 0x1 (VSS_WS_STABLE)
03-May 23:58 ntfi10-fd JobId 26741: VSS Writer (BackupComplete): "BITS Writer", 
State: 0x1 (VSS_WS_STABLE)
03-May 23:58 ntfi10-fd JobId 26741: VSS Writer (BackupComplete): "Event Log 
Writer", State: 0x1 (VSS_WS_STABLE)
03-May 23:58 ntfi10-fd JobId 26741: VSS Writer (BackupComplete): "Registry 
Writer", State: 0x1 (VSS_WS_STABLE)
03-May 23:58 ntfi10-fd JobId 26741: VSS Writer (BackupComplete): "Removable 
Storage Manager", State: 0x1 (VSS_WS_STABLE)
03-May 23:58 ntfi10-fd JobId 26741: VSS Writer (BackupComplete): "COM+ REGDB 
Writer", State: 0x1 (VSS_WS_STABLE)
03-May 23:58 ntfi10-fd JobId 26741: VSS Writer (BackupComplete): "WMI Writer", 
State: 0x1 (VSS_WS_STABLE)
03-May 23:58 uxifi04-sd JobId 26741: Job write elapsed time = 00:03:18, 
Transfer rate = 8.689 M Bytes/second
03-May 23:58 ntfi10-fd JobId 26741: shell command: run ClientAfterJob 
"PreBCK.bat after"
03-May 23:58 uxifi04-sd JobId 26741: Committing spooled data to Volume 
"MT0498L4". Despooling 1,722,106,742 bytes ...
03-May 23:58 ntfi10-fd JobId 26741: ClientAfterJob: 
03-May 23:58 ntfi10-fd JobId 26741: ClientAfterJob: C:\WINDOWS\system32>REM 
$VGFi: PreBCK.bat,v 1.2 2010/01/19 15:40:24 gfalsi Exp $ 
03-May 23:58 ntfi10-fd JobId 26741: ClientAfterJob: 
03-May 23:58 ntfi10-fd JobId 26741: ClientAfterJob: C:\WINDOWS\system32>if 
"after" == "before" goto create 
03-May 23:58 ntfi10-fd JobId 26741: ClientAfterJob: 
03-May 23:58 ntfi10-fd JobId 26741: ClientAfterJob: C:\WINDOWS\system32>if 
"after" == "after" goto delete 
03-May 23:58 ntfi10-fd JobId 26741: ClientAfterJob: 
03-May 23:58 ntfi10-fd JobId 26741: ClientAfterJob: C:\WINDOWS\system32>del /F 
/Q E:\backup\ntfi10-systemstate.bkf 
03-May 23:58 ntfi10-fd JobId 26741: ClientAfterJob: 
03-May 23:58 ntfi10-fd JobId 26741: ClientAfterJob: C:\WINDOWS\system32>goto 
:scend 
03-May 23:58 ntfi10-fd JobId 26741: ClientAfterJob: 
03-May 23:58 ntfi10-fd JobId 26741: ClientAfterJob: C:\WINDOWS\system32>exit 0 
04-May 00:00 uxifi04-sd JobId 26741: Despooling elapsed time = 00:01:10, 
Transfer rate = 24.60 M Bytes/second
04-May 00:00 uxifi04-sd JobId 26741: Sending spooled attrs to the Director. 
Despooling 203,879 bytes ...
04-May 00:00 uxifi04-dir JobId 26741: Bacula uxifi04-dir 5.2.6 (21Feb12):
  Build OS:               amd64-portbld-freebsd9.0 freebsd 9.0-STABLE
  JobId:                  26741
  Job:                    nifi10MonthlyMain.2012-05-03_22.30.01_42
  Backup Level:           Incremental, since=2012-05-02 23:57:17
  Client:                 "ntfi10-fd" 5.2.6 (21Feb12) Microsoft Windows Home 
ServerStandard Edition Service Pack 2 (build 3790),Cross-compile,Win32
  FileSet:                "ntfi10 Set" 2011-02-23 22:30:00
  Pool:                   "MainInc" (From Run IncPool override)
  Catalog:                "MyCatalog" (From Client resource)
  Storage:                "Storageworks-1" (From Pool resource)
  Scheduled time:         03-May-2012 22:30:01
  Start time:             03-May-2012 23:55:34
  End time:               04-May-2012 00:00:17
  Elapsed time:           4 mins 43 secs
  Priority:               10
  FD Files Written:       591
  SD Files Written:       591
  FD Bytes Written:       1,720,367,350 (1.720 GB)
  SD Bytes Written:       1,720,489,484 (1.720 GB)
  Rate:                   6079.0 KB/s
  Software Compression:   None
  VSS:                    yes
  Encryption:             no
  Accurate:               no
  Volume name(s):         MT0498L4
  Volume Session Id:      29
  Volume Session Time:    1335960421
  Last Volume Bytes:      1,237,800,775,680 (1.237 TB)
  Non-fatal FD errors:    0
  SD Errors:              0
  FD termination status:  OK
  SD termination status:  OK
  Termination:            Backup OK

04-May 00:00 uxifi04-dir JobId 26741: Begin pruning Jobs older than 6 months .
04-May 00:00 uxifi04-dir JobId 26741: Pruned 1 Job for client ntfi10-fd from 
catalog.
04-May 00:00 uxifi04-dir JobId 26741: Begin pruning Files.
04-May 00:00 uxifi04-dir JobId 26741: No Files found to prune.
04-May 00:00 uxifi04-dir JobId 26741: End auto prune.


As you can see the plugin is truncating logs even if this is an
incremental backup.

Any suggestions? I think I've already looked at all the obvious things.

If more information is needed I can dig it out.

Thanks in advance for any help.

-- 
Guido Falsi <mad AT madpilot DOT net>

------------------------------------------------------------------------------
Live Security Virtual Conference
Exclusive live event will cover all the ways today's security and 
threat landscape has changed and how IT managers can respond. Discussions 
will include endpoint security, mobile security and the latest in malware 
threats. http://www.accelacomm.com/jaw/sfrnl04242012/114/50122263/
_______________________________________________
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>