-----Original Message-----
From: Karyn Stump
Sent: Monday, April 30, 2012 10:43 AM
To: 'Martin Simmons'
Subject: RE: [Bacula-users] Finding (and killing) Phanton job IDs
-----Original Message-----
From: Martin Simmons [mailto:martin AT lispworks DOT com]
Sent: Monday, April 30, 2012 7:24 AM
To: bacula-users AT lists.sourceforge DOT net
Subject: Re: [Bacula-users] Finding (and killing) Phanton job IDs
>>>>> On Fri, 27 Apr 2012 18:13:42 -0700, Karyn Stump said:
>
> We have a working bacula (5.0.3) instance with a MySQL backend. A few
> weeks ago we had a power outage that caused the server to shut down
> and restart abruptly. The jobs are running successfully but now there
> is a complete set of phantom jobs running in parallel that fail.
>
> Bconsole only shows the successful JobIds. If I do a status of a
> client only the successful job IDs show up. The failed job IDs
> increment just as one would expect if they were valid jobs. An example
> of the successful job IDs are 730, 731, 732. An example of the
> phantom/failing job IDs are 900, 901, 902. As you can see they are not
> in the same sequence. The successful job IDs follow the previously
> successful job IDs (prior to the crash).
Where exactly are these phantom jobids listed? Can you post some
output?
__Martin
The jobIDs show up in the Bacula generated emails relating the job
status. The Bacula Director is running on CentOS and the catalog backup
is doing the same thing (one fails, one is successful). Here is a
sample, one each for the same client/fileset:
30-Apr 05:05 back-dir JobId 967: Start Backup JobId 967,
Job=MM_Exchange.2012-04-30_05.05.00_02
30-Apr 05:05 back-sd JobId 967: Error: dev.c:120 Unable to stat device
/var/backups: ERR=No such file or directory 30-Apr 05:05 back-sd JobId
967: Warning:
Device "FileStorage" requested by DIR could not be opened or does
not exist.
30-Apr 05:05 back-sd JobId 967: Error: dev.c:120 Unable to stat device
/var/backups: ERR=No such file or directory 30-Apr 05:05 back-sd JobId
967: Warning:
Device "FileStorage" requested by DIR could not be opened or does
not exist.
30-Apr 05:05 back-sd JobId 967: Error: dev.c:120 Unable to stat device
/var/backups: ERR=No such file or directory 30-Apr 05:05 back-sd JobId
967: Warning:
Device "FileStorage" requested by DIR could not be opened or does
not exist.
30-Apr 05:05 back-sd JobId 967: Fatal error: Device reservation failed
for JobId=967: Jmsg Job=MM_Exchange.2012-04-30_05.05.00_02 type=5
level=1335787502 back-sd JobId 967: Warning:
Device "FileStorage" requested by DIR could not be opened or does
not exist.
30-Apr 05:05 back-dir JobId 967: Fatal error:
Storage daemon didn't accept Device "FileStorage" because:
3924 Device "FileStorage" not in SD Device resources.
30-Apr 05:05 back-dir JobId 967: Error: Bacula back-dir 5.0.3 (04Aug10):
30-Apr-2012 05:05:02
Build OS: x86_64-pc-linux-gnu gentoo
JobId: 967
Job: MM_Exchange.2012-04-30_05.05.00_02
Backup Level: Full
Client: "mm-fd" 5.0.3 (04Aug10)
Linux,Cross-compile,Win32
FileSet: "NTBackup" 2011-06-21 12:02:07
Pool: "ex-full-backup" (From Job FullPool override)
Catalog: "MyCatalog" (From Client resource)
Storage: "back-sd" (From Job resource)
Scheduled time: 30-Apr-2012 05:05:00
Start time: 30-Apr-2012 05:05:02
End time: 30-Apr-2012 05:05:02
Elapsed time: 0 secs
Priority: 10
FD Files Written: 0
SD Files Written: 0
FD Bytes Written: 0 (0 B)
SD Bytes Written: 0 (0 B)
Rate: 0.0 KB/s
Software Compression: None
VSS: no
Encryption: no
Accurate: no
Volume name(s):
Volume Session Id: 61
Volume Session Time: 1334731875
Last Volume Bytes: 0 (0 B)
Non-fatal FD errors: 0
SD Errors: 0
FD termination status:
SD termination status:
Termination: *** Backup Error ***
------------------------------------------------------------------------
--------
30-Apr 05:05 back-dir JobId 838: Start Backup JobId 838,
Job=MM_Exchange.2012-04-30_05.05.00_59
30-Apr 05:05 back-dir JobId 838: There are no more Jobs associated with
Volume "ex-full-0078". Marking it purged.
30-Apr 05:05 back-dir JobId 838: All records pruned from Volume
"ex-full-0078"; marking it "Purged"
30-Apr 05:05 back-dir JobId 838: Recycled volume "ex-full-0078"
30-Apr 05:05 back-dir JobId 838: Using Device "FileStorage"
30-Apr 05:07 back-sd JobId 838: Recycled volume "ex-full-0078" on device
"FileStorage" (/var/backups), all previous data lost.
30-Apr 05:07 back-dir JobId 838: Max Volume jobs=1 exceeded. Marking
Volume "ex-full-0078" as Used.
30-Apr 05:07 mm-fd JobId 838: Generate VSS snapshots. Driver="VSS Win
2003", Drive(s)="C"
30-Apr 06:22 mm-fd JobId 838: VSS Writer (BackupComplete): "System
Writer", State: 0x1 (VSS_WS_STABLE) 30-Apr 06:22 back-sd JobId 838: Job
write elapsed time = 01:15:29, Transfer rate = 21.20 M Bytes/second
30-Apr 06:22 mm-fd JobId 838: VSS Writer (BackupComplete): "MSDEWriter",
State: 0x1 (VSS_WS_STABLE) 30-Apr 06:22 mm-fd JobId 838: VSS Writer
(BackupComplete): "Microsoft Exchange Writer", State: 0x1
(VSS_WS_STABLE) 30-Apr 06:22 mm-fd JobId 838: VSS Writer
(BackupComplete): "Event Log Writer", State: 0x1 (VSS_WS_STABLE) 30-Apr
06:22 mm-fd JobId 838: VSS Writer (BackupComplete): "Registry Writer",
State: 0x1 (VSS_WS_STABLE) 30-Apr 06:22 mm-fd JobId 838: VSS Writer
(BackupComplete): "IIS Metabase Writer", State: 0x1 (VSS_WS_STABLE)
30-Apr 06:22 mm-fd JobId 838: VSS Writer (BackupComplete): "COM+ REGDB
Writer", State: 0x1 (VSS_WS_STABLE) 30-Apr 06:22 mm-fd JobId 838: VSS
Writer (BackupComplete): "WMI Writer", State: 0x1 (VSS_WS_STABLE) 30-Apr
06:22 mm-fd JobId 838: VSS Writer (BackupComplete): "BITS Writer",
State: 0x1 (VSS_WS_STABLE) 30-Apr 06:22 back-dir JobId 838: Bacula
back-dir 5.0.3 (30Aug10): 30-Apr-2012 06:22:31
Build OS: x86_64-redhat-linux-gnu redhat
JobId: 838
Job: MM_Exchange.2012-04-30_05.05.00_59
Backup Level: Full
Client: "mm-fd" 5.0.3 (04Aug10)
Linux,Cross-compile,Win32
FileSet: "NTBackup" 2011-12-20 05:05:00
Pool: "ex-full-backup" (From Job FullPool override)
Catalog: "MyCatalog" (From Client resource)
Storage: "File" (From Job resource)
Scheduled time: 30-Apr-2012 05:05:00
Start time: 30-Apr-2012 05:05:05
End time: 30-Apr-2012 06:22:31
Elapsed time: 1 hour 17 mins 26 secs
Priority: 10
FD Files Written: 2
SD Files Written: 2
FD Bytes Written: 96,038,868,528 (96.03 GB)
SD Bytes Written: 96,038,868,780 (96.03 GB)
Rate: 20671.3 KB/s
Software Compression: None
VSS: yes
Encryption: no
Accurate: no
Volume name(s): ex-full-0078
Volume Session Id: 56
Volume Session Time: 1335214872
Last Volume Bytes: 96,110,084,699 (96.11 GB)
Non-fatal FD errors: 0
SD Errors: 0
FD termination status: OK
SD termination status: OK
Termination: Backup OK
30-Apr 06:22 back-dir JobId 838: Begin pruning Jobs older than 6 months
.
30-Apr 06:22 back-dir JobId 838: No Jobs found to prune.
30-Apr 06:22 back-dir JobId 838: Begin pruning Jobs.
30-Apr 06:22 back-dir JobId 838: No Files found to prune.
30-Apr 06:22 back-dir JobId 838: End auto prune.
And here is the output from logwatch. The phantom jobIDs are not listed
here either:
################### Logwatch 7.3 (03/24/06) ####################
Processing Initiated: Mon Apr 30 04:02:02 2012
Date Range Processed: yesterday
( 2012-Apr-29 )
Period is day.
Detail Level of Output: 0
Type of Output: unformatted
Logfiles for Host: back.fastsoft.com
##################################################################
--------------------- bacula Begin ------------------------
Jobs Run:
2012-04-29 830 MM_Exchange.2012-04-29_05.05.00_51
BackupOK
2012-04-29 831 DC1_DFS.2012-04-29_23.05.00_52
BackupOK
2012-04-29 832 DC2_DFS.2012-04-29_23.05.00_53
BackupOK
2012-04-29 833 MM_Logs.2012-04-29_23.05.00_54
BackupOK
2012-04-29 834 TS_Quickbooks.2012-04-29_23.05.00_55
BackupOK
2012-04-29 835 support-files.2012-04-29_23.05.00_56
BackupOK
2012-04-29 836 soup-files.2012-04-29_23.05.00_57
BackupOK
2012-04-29 837 BackupCatalog.2012-04-29_23.10.00_58
BackupOK
---------------------- bacula End -------------------------
--------------------- Disk Space Begin ------------------------
Filesystem Size Used Avail Use% Mounted on
/dev/mapper/VolGroup00-LogVol00
7.1T 3.8T 2.9T 57% /
/dev/sda3 92M 20M 67M 23% /boot
---------------------- Disk Space End -------------------------
###################### Logwatch End #########################
And the output form the client status from bconsole:
mm-fd Version: 5.0.3 (04 August 2010) VSS Linux Cross-compile Win32
Daemon started 18-Apr-12 08:50. Jobs: run=25 running=0.
Heap: heap=0 smbytes=91,694 max_bytes=174,983 bufs=83 max_bufs=119
Sizeof: boffset_t=8 size_t=4 debug=0 trace=1
Running Jobs:
Director connected at: 30-Apr-12 10:34
No Jobs running.
====
Terminated Jobs:
JobId Level Files Bytes Status Finished Name
======================================================================
801 Incr 12 27.40 M OK 25-Apr-12 23:18 MM_Logs
806 Full 2 96.02 G OK 26-Apr-12 06:52 MM_Exchange
809 Incr 10 31.02 M OK 26-Apr-12 23:18 MM_Logs
814 Full 2 96.05 G OK 27-Apr-12 07:10 MM_Exchange
817 Incr 8 29.56 M OK 27-Apr-12 23:19 MM_Logs
822 Full 2 96.02 G OK 28-Apr-12 06:26 MM_Exchange
825 Incr 8 49.44 M OK 28-Apr-12 23:18 MM_Logs
830 Full 2 96.02 G OK 29-Apr-12 06:26 MM_Exchange
833 Diff 93 419.6 M OK 29-Apr-12 23:20 MM_Logs
838 Full 2 96.03 G OK 30-Apr-12 06:22 MM_Exchange
====
*
--
Karyn Stump
IT Administrator
FastSoft, Inc
karyn AT fastsoft DOT com
------------------------------------------------------------------------------
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
|