Bacula-users
[Top] [All Lists]
<prev [Date] next>
[Advanced]
 <prev [Thread] next>

Re: [Bacula-users] Duplicate Bacula Log Lines

2015-08-14 09:13:27
Subject: Re: [Bacula-users] Duplicate Bacula Log Lines
From: Radosław Korzeniewski <radoslaw AT korzeniewski DOT net>
To: Wanderlei Huttel <wanderleihuttel AT gmail DOT com>, bacula-users <bacula-users AT lists.sourceforge DOT net>
Date: Fri, 14 Aug 2015 15:11:28 +0200

Hello.

If you have two Directors for the same FD then you will have duplicate job logs from this FD. There was a bug in messages handling runtime which caused this. I had the same issue at one of my customer. I do not know if it was fixed. The customer was migrating from Bacula Community into Bacula Enterprise and has two Dir for a short time.

Best regards

14 sie 2015 3:02 PM "Wanderlei Huttel" <wanderleihuttel AT gmail DOT com> napisał(a):
Hi Radoslaw

I have 2 directors, but the duplication log lines just happen on machines like servers that stay 24 hours power on
Users machine that are turned off  every day this doesn't happen

Best Regards
Wanderlei

2015-08-14 9:29 GMT-03:00 Radosław Korzeniewski <radoslaw AT korzeniewski DOT net>:
Hello,

I see a duplication of logs only for messages generated from Bacula File Daemon. So please check you Bacula FD configuration, especially if you have more then one Bacula Director defined.

best regards

2015-07-31 19:03 GMT+02:00 Wanderlei Huttel <wanderleihuttel AT gmail DOT com>:
I've been noticed a few days ago that bacula is duplicating a lot of lines in the log.

What should this happening?

Below my logs.


Thanks Wanderlei

30-Jul 21:30 bacula-dir JobId 1276: Start Backup JobId 1276, Job=Backup_Servidor_Firewall.2015-07-30_21.30.00_16
30-Jul 21:30 bacula-dir JobId 1276: Using Device "DiscoLocal1" to write.
30-Jul 21:31 srv_firewall-fd JobId 1276: DIR and FD clocks differ by 108 seconds, FD automatically compensating.
30-Jul 21:31 srv_firewall-fd JobId 1276: DIR and FD clocks differ by 108 seconds, FD automatically compensating.
30-Jul 21:31 srv_firewall-fd JobId 1276: shell command: run ClientBeforeJob "/usr/local/bin/backup_mysql_bacula.sh"
30-Jul 21:31 srv_firewall-fd JobId 1276: shell command: run ClientBeforeJob "/usr/local/bin/backup_mysql_bacula.sh"
30-Jul 21:31 srv_firewall-fd JobId 1276: ClientBeforeJob: Backing up information_schema... Done.
30-Jul 21:31 srv_firewall-fd JobId 1276: ClientBeforeJob: Backing up information_schema... Done.
30-Jul 21:31 srv_firewall-fd JobId 1276: ClientBeforeJob: Backing up cacti... Done.
30-Jul 21:31 srv_firewall-fd JobId 1276: ClientBeforeJob: Backing up cacti... Done.
30-Jul 21:31 srv_firewall-fd JobId 1276: ClientBeforeJob: Backing up curriculum... Done.
30-Jul 21:31 srv_firewall-fd JobId 1276: ClientBeforeJob: Backing up curriculum... Done.
30-Jul 21:31 srv_firewall-fd JobId 1276: ClientBeforeJob: Backing up db_admin... Done.
30-Jul 21:31 srv_firewall-fd JobId 1276: ClientBeforeJob: Backing up db_admin... Done.
30-Jul 21:31 srv_firewall-fd JobId 1276: ClientBeforeJob: Backing up db_qmail... Done.
30-Jul 21:31 srv_firewall-fd JobId 1276: ClientBeforeJob: Backing up db_qmail... Done.
30-Jul 21:31 srv_firewall-fd JobId 1276: ClientBeforeJob: Backing up iptables... Done.
30-Jul 21:31 srv_firewall-fd JobId 1276: ClientBeforeJob: Backing up iptables... Done.
30-Jul 21:31 srv_firewall-fd JobId 1276: ClientBeforeJob: Backing up msnproxy... Done.
30-Jul 21:31 srv_firewall-fd JobId 1276: ClientBeforeJob: Backing up msnproxy... Done.
30-Jul 21:31 srv_firewall-fd JobId 1276: ClientBeforeJob: Backing up mysql... Done.
30-Jul 21:31 srv_firewall-fd JobId 1276: ClientBeforeJob: Backing up mysql... Done.
30-Jul 21:31 srv_firewall-fd JobId 1276: ClientBeforeJob: Backing up squid... Done.
30-Jul 21:31 srv_firewall-fd JobId 1276: ClientBeforeJob: Backing up squid... Done.
30-Jul 21:31 srv_firewall-fd JobId 1276: ClientBeforeJob: Backing up squid_log... Done.
30-Jul 21:31 srv_firewall-fd JobId 1276: ClientBeforeJob: Backing up squid_log... Done.
30-Jul 21:31 srv_firewall-fd JobId 1276: ClientBeforeJob: Backing up squidaccess... Done.
30-Jul 21:31 srv_firewall-fd JobId 1276: ClientBeforeJob: Backing up squidaccess... Done.
30-Jul 21:31 srv_firewall-fd JobId 1276: ClientBeforeJob: Backing up website... Done.
30-Jul 21:31 srv_firewall-fd JobId 1276: ClientBeforeJob: Backing up website... Done.
30-Jul 21:30 bacula-sd JobId 1276: Elapsed time=00:00:11, Transfer rate=706.4 K Bytes/second
30-Jul 21:30 bacula-sd JobId 1276: Sending spooled attrs to the Director. Despooling 24,355 bytes ...
30-Jul 21:30 bacula-dir JobId 1276: Bacula bacula-dir 7.0.5 (28Jul14):
  Build OS:               x86_64-unknown-linux-gnu debian 7.8
  JobId:                  1276
  Job:                    Backup_Servidor_Firewall.2015-07-30_21.30.00_16
  Backup Level:           Differential, since=2015-07-24 22:00:06
  Client:                 "srv_firewall-fd" 7.0.5 (28Jul14) i686-pc-linux-gnu,debian,5.0
  FileSet:                "FileSet_SRV_Firewall" 2015-07-03 22:00:00
  Pool:                   "Diaria" (From Run Pool override)
  Catalog:                "MyCatalog" (From Client resource)
  Storage:                "StorageLocal1" (From Pool resource)
  Scheduled time:         30-Jul-2015 21:30:00
  Start time:             30-Jul-2015 21:30:06
  End time:               30-Jul-2015 21:30:17
  Elapsed time:           11 secs
  Priority:               10
  FD Files Written:       80
  SD Files Written:       80
  FD Bytes Written:       7,761,487 (7.761 MB)
  SD Bytes Written:       7,770,554 (7.770 MB)
  Rate:                   705.6 KB/s
  Software Compression:   3.5% 1.0:1
  VSS:                    no
  Encryption:             no
  Accurate:               no
  Volume name(s):         Volume-Diario-0001
  Volume Session Id:      5
  Volume Session Time:    1438286880
  Last Volume Bytes:      1,800,774,445 (1.800 GB)
  Non-fatal FD errors:    0
  SD Errors:              0
  FD termination status:  OK
  SD termination status:  OK
  Termination:            Backup OK

30-Jul 21:30 bacula-dir JobId 1276: Begin pruning Jobs older than 1 year .
30-Jul 21:30 bacula-dir JobId 1276: No Jobs found to prune.
30-Jul 21:30 bacula-dir JobId 1276: Begin pruning Files.
30-Jul 21:30 bacula-dir JobId 1276: No Files found to prune.
30-Jul 21:30 bacula-dir JobId 1276: End auto prune.

##################################################################################################################################


30-Jul 21:30 bacula-dir JobId 1277: Start Backup JobId 1277, Job=Backup_Servidor_Intranet.2015-07-30_21.30.00_17
30-Jul 21:30 bacula-dir JobId 1277: Using Device "DiscoLocal1" to write.
30-Jul 21:31 backup-fd JobId 1277: DIR and FD clocks differ by 108 seconds, FD automatically compensating.
30-Jul 21:31 backup-fd JobId 1277: DIR and FD clocks differ by 108 seconds, FD automatically compensating.
30-Jul 21:31 backup-fd JobId 1277: shell command: run ClientBeforeJob "/usr/local/bin/backup_mysql_bacula.sh"
30-Jul 21:31 backup-fd JobId 1277: shell command: run ClientBeforeJob "/usr/local/bin/backup_mysql_bacula.sh"
30-Jul 21:31 backup-fd JobId 1277: ClientBeforeJob: Backing up information_schema... Done.
30-Jul 21:31 backup-fd JobId 1277: ClientBeforeJob: Backing up information_schema... Done.
30-Jul 21:31 backup-fd JobId 1277: ClientBeforeJob: Backing up bacula... Done.
30-Jul 21:31 backup-fd JobId 1277: ClientBeforeJob: Backing up bacula... Done.
30-Jul 21:31 backup-fd JobId 1277: ClientBeforeJob: Backing up intranet... Done.
30-Jul 21:31 backup-fd JobId 1277: ClientBeforeJob: Backing up intranet... Done.
30-Jul 21:31 backup-fd JobId 1277: ClientBeforeJob: Backing up mysql... -- Warning: Skipping the data of table mysql.event. Specify the --events option explicitly.
30-Jul 21:31 backup-fd JobId 1277: ClientBeforeJob: Backing up mysql... -- Warning: Skipping the data of table mysql.event. Specify the --events option explicitly.
30-Jul 21:31 backup-fd JobId 1277: ClientBeforeJob: Done.
30-Jul 21:31 backup-fd JobId 1277: ClientBeforeJob: Done.
30-Jul 21:31 backup-fd JobId 1277: ClientBeforeJob: Backing up performance_schema... Done.
30-Jul 21:31 backup-fd JobId 1277: ClientBeforeJob: Backing up performance_schema... Done.
30-Jul 21:30 bacula-sd JobId 1277: Elapsed time=00:00:13, Transfer rate=1.904 M Bytes/second
30-Jul 21:30 bacula-sd JobId 1277: Sending spooled attrs to the Director. Despooling 129,841 bytes ...
30-Jul 21:30 bacula-dir JobId 1277: Bacula bacula-dir 7.0.5 (28Jul14):
  Build OS:               x86_64-unknown-linux-gnu debian 7.8
  JobId:                  1277
  Job:                    Backup_Servidor_Intranet.2015-07-30_21.30.00_17
  Backup Level:           Differential, since=2015-07-24 22:00:09
  Client:                 "srv_intranet-fd" 7.0.5 (28Jul14) x86_64-unknown-linux-gnu,debian,7.8
  FileSet:                "FileSet_SRV_Intranet" 2015-07-03 22:00:00
  Pool:                   "Diaria" (From Run Pool override)
  Catalog:                "MyCatalog" (From Client resource)
  Storage:                "StorageLocal1" (From Pool resource)
  Scheduled time:         30-Jul-2015 21:30:00
  Start time:             30-Jul-2015 21:30:09
  End time:               30-Jul-2015 21:30:23
  Elapsed time:           14 secs
  Priority:               10
  FD Files Written:       344
  SD Files Written:       344
  FD Bytes Written:       24,690,808 (24.69 MB)
  SD Bytes Written:       24,754,597 (24.75 MB)
  Rate:                   1763.6 KB/s
  Software Compression:   13.4% 1.2:1
  VSS:                    no
  Encryption:             no
  Accurate:               no
  Volume name(s):         Volume-Diario-0001
  Volume Session Id:      7
  Volume Session Time:    1438286880
  Last Volume Bytes:      1,800,786,462 (1.800 GB)
  Non-fatal FD errors:    0
  SD Errors:              0
  FD termination status:  OK
  SD termination status:  OK
  Termination:            Backup OK

30-Jul 21:30 bacula-dir JobId 1277: Begin pruning Jobs older than 1 year .
30-Jul 21:30 bacula-dir JobId 1277: No Jobs found to prune.
30-Jul 21:30 bacula-dir JobId 1277: Begin pruning Files.
30-Jul 21:30 bacula-dir JobId 1277: No Files found to prune.
30-Jul 21:30 bacula-dir JobId 1277: End auto prune.

##################################################################################################################################

30-Jul 21:30 bacula-dir JobId 1275: Start Backup JobId 1275, Job=Backup_Servidor_R2D2.2015-07-30_21.30.00_15
30-Jul 21:30 bacula-dir JobId 1275: Using Device "DiscoLocal1" to write.
30-Jul 21:30 srv_r2d2-fd JobId 1275: Generate VSS snapshots. Driver="Win64 VSS", Drive(s)="CJK"
30-Jul 21:30 srv_r2d2-fd JobId 1275: Generate VSS snapshots. Driver="Win64 VSS", Drive(s)="CJK"
30-Jul 21:32 srv_r2d2-fd JobId 1275: VSS Writer (BackupComplete): "Task Scheduler Writer", State: 0x1 (VSS_WS_STABLE)
30-Jul 21:32 srv_r2d2-fd JobId 1275: VSS Writer (BackupComplete): "Task Scheduler Writer", State: 0x1 (VSS_WS_STABLE)
30-Jul 21:32 srv_r2d2-fd JobId 1275: VSS Writer (BackupComplete): "VSS Metadata Store Writer", State: 0x1 (VSS_WS_STABLE)
30-Jul 21:32 srv_r2d2-fd JobId 1275: VSS Writer (BackupComplete): "VSS Metadata Store Writer", State: 0x1 (VSS_WS_STABLE)
30-Jul 21:32 srv_r2d2-fd JobId 1275: VSS Writer (BackupComplete): "Performance Counters Writer", State: 0x1 (VSS_WS_STABLE)
30-Jul 21:32 srv_r2d2-fd JobId 1275: VSS Writer (BackupComplete): "Performance Counters Writer", State: 0x1 (VSS_WS_STABLE)
30-Jul 21:32 srv_r2d2-fd JobId 1275: VSS Writer (BackupComplete): "System Writer", State: 0x1 (VSS_WS_STABLE)
30-Jul 21:32 srv_r2d2-fd JobId 1275: VSS Writer (BackupComplete): "System Writer", State: 0x1 (VSS_WS_STABLE)
30-Jul 21:32 srv_r2d2-fd JobId 1275: VSS Writer (BackupComplete): "ASR Writer", State: 0x1 (VSS_WS_STABLE)
30-Jul 21:32 srv_r2d2-fd JobId 1275: VSS Writer (BackupComplete): "ASR Writer", State: 0x1 (VSS_WS_STABLE)
30-Jul 21:32 srv_r2d2-fd JobId 1275: VSS Writer (BackupComplete): "WIDWriter", State: 0x1 (VSS_WS_STABLE)
30-Jul 21:32 srv_r2d2-fd JobId 1275: VSS Writer (BackupComplete): "WIDWriter", State: 0x1 (VSS_WS_STABLE)
30-Jul 21:32 srv_r2d2-fd JobId 1275: VSS Writer (BackupComplete): "FSRM Writer", State: 0x1 (VSS_WS_STABLE)
30-Jul 21:32 srv_r2d2-fd JobId 1275: VSS Writer (BackupComplete): "FSRM Writer", State: 0x1 (VSS_WS_STABLE)
30-Jul 21:32 srv_r2d2-fd JobId 1275: VSS Writer (BackupComplete): "Shadow Copy Optimization Writer", State: 0x1 (VSS_WS_STABLE)
30-Jul 21:32 srv_r2d2-fd JobId 1275: VSS Writer (BackupComplete): "Shadow Copy Optimization Writer", State: 0x1 (VSS_WS_STABLE)
30-Jul 21:32 srv_r2d2-fd JobId 1275: VSS Writer (BackupComplete): "Registry Writer", State: 0x1 (VSS_WS_STABLE)
30-Jul 21:32 srv_r2d2-fd JobId 1275: VSS Writer (BackupComplete): "Registry Writer", State: 0x1 (VSS_WS_STABLE)
30-Jul 21:32 srv_r2d2-fd JobId 1275: VSS Writer (BackupComplete): "IIS Config Writer", State: 0x1 (VSS_WS_STABLE)
30-Jul 21:32 srv_r2d2-fd JobId 1275: VSS Writer (BackupComplete): "IIS Config Writer", State: 0x1 (VSS_WS_STABLE)
30-Jul 21:32 srv_r2d2-fd JobId 1275: VSS Writer (BackupComplete): "BITS Writer", State: 0x1 (VSS_WS_STABLE)
30-Jul 21:32 srv_r2d2-fd JobId 1275: VSS Writer (BackupComplete): "BITS Writer", State: 0x1 (VSS_WS_STABLE)
30-Jul 21:32 srv_r2d2-fd JobId 1275: VSS Writer (BackupComplete): "WMI Writer", State: 0x1 (VSS_WS_STABLE)
30-Jul 21:32 srv_r2d2-fd JobId 1275: VSS Writer (BackupComplete): "WMI Writer", State: 0x1 (VSS_WS_STABLE)
30-Jul 21:32 srv_r2d2-fd JobId 1275: VSS Writer (BackupComplete): "IIS Metabase Writer", State: 0x1 (VSS_WS_STABLE)
30-Jul 21:32 srv_r2d2-fd JobId 1275: VSS Writer (BackupComplete): "IIS Metabase Writer", State: 0x1 (VSS_WS_STABLE)
30-Jul 21:32 srv_r2d2-fd JobId 1275: VSS Writer (BackupComplete): "TermServLicensing", State: 0x1 (VSS_WS_STABLE)
30-Jul 21:32 srv_r2d2-fd JobId 1275: VSS Writer (BackupComplete): "TermServLicensing", State: 0x1 (VSS_WS_STABLE)
30-Jul 21:32 srv_r2d2-fd JobId 1275: VSS Writer (BackupComplete): "COM+ REGDB Writer", State: 0x1 (VSS_WS_STABLE)
30-Jul 21:32 srv_r2d2-fd JobId 1275: VSS Writer (BackupComplete): "COM+ REGDB Writer", State: 0x1 (VSS_WS_STABLE)
30-Jul 21:32 bacula-sd JobId 1275: Elapsed time=00:02:29, Transfer rate=962.8 K Bytes/second
30-Jul 21:32 bacula-sd JobId 1275: Sending spooled attrs to the Director. Despooling 353,308 bytes ...
30-Jul 21:32 bacula-dir JobId 1275: Bacula bacula-dir 7.0.5 (28Jul14):
  Build OS:               x86_64-unknown-linux-gnu debian 7.8
  JobId:                  1275
  Job:                    Backup_Servidor_R2D2.2015-07-30_21.30.00_15
  Backup Level:           Differential, since=2015-07-24 22:00:01
  Client:                 "srv_r2d2-fd" 5.2.10 (28Jun12) Microsoft Standard Edition (build 9200), 64-bit,Cross-compile,Win64
  FileSet:                "FileSet_SRV_R2D2" 2015-07-24 22:00:00
  Pool:                   "Diaria" (From Run Pool override)
  Catalog:                "MyCatalog" (From Client resource)
  Storage:                "StorageLocal1" (From Pool resource)
  Scheduled time:         30-Jul-2015 21:30:00
  Start time:             30-Jul-2015 21:30:04
  End time:               30-Jul-2015 21:32:34
  Elapsed time:           2 mins 30 secs
  Priority:               10
  FD Files Written:       915
  SD Files Written:       915
  FD Bytes Written:       143,253,552 (143.2 MB)
  SD Bytes Written:       143,466,612 (143.4 MB)
  Rate:                   955.0 KB/s
  Software Compression:   25.8% 1.3:1
  VSS:                    yes
  Encryption:             no
  Accurate:               no
  Volume name(s):         Volume-Diario-0001
  Volume Session Id:      4
  Volume Session Time:    1438286880
  Last Volume Bytes:      1,944,395,330 (1.944 GB)
  Non-fatal FD errors:    0
  SD Errors:              0
  FD termination status:  OK
  SD termination status:  OK
  Termination:            Backup OK

30-Jul 21:32 bacula-dir JobId 1275: Begin pruning Jobs older than 1 year .
30-Jul 21:32 bacula-dir JobId 1275: No Jobs found to prune.
30-Jul 21:32 bacula-dir JobId 1275: Begin pruning Files.
30-Jul 21:32 bacula-dir JobId 1275: No Files found to prune.
30-Jul 21:32 bacula-dir JobId 1275: End auto prune.


------------------------------------------------------------------------------

_______________________________________________
Bacula-users mailing list
Bacula-users AT lists.sourceforge DOT net
https://lists.sourceforge.net/lists/listinfo/bacula-users




--
Radosław Korzeniewski
radoslaw AT korzeniewski DOT net

------------------------------------------------------------------------------

_______________________________________________
Bacula-users mailing list
Bacula-users AT lists.sourceforge DOT net
https://lists.sourceforge.net/lists/listinfo/bacula-users
[More with this subject...]
<Prev in Thread] Current Thread [Next in Thread>
Previous by Date:  Re: [Bacula-users] Out of virtual tapes, Ana Emília M. Arruda
Next by Date:  Re: [Bacula-users] Bacula version 7.2.0 released, Alex Domoradov
Previous by Thread:  Re: [Bacula-users] Duplicate Bacula Log Lines, Radosław Korzeniewski
Next by Thread:  [Bacula-users] Baculum 7.2.0 new features and binary packages for CentOS 7 and Fedora 22, Marcin Haba
Indexes:  [Date] [Thread] [Top] [All Lists]