Bacula is an open software enterprise backup system! Check out the official site here
Complex but useful software, which could automate the whole backup process of all your servers.
Some errors are easy to track some are not, so here is one error with a misleading error message if you do not know or forget the details of how the daemons works.
Here is the error extracted from the logs:
01-Sep 00:45 backup01-de-dir JobId 8789: No prior Full backup Job record found. 01-Sep 00:45 backup01-de-dir JobId 8789: No prior or suitable Full backup found in catalog. Doing FULL backup. 01-Sep 00:45 backup01-de-dir JobId 8789: Job srv123us.2017-09-01_00.45.28_34 waiting 103 seconds for scheduled start time. 01-Sep 00:47 backup01-de-dir JobId 8789: Start Backup JobId 8789, Job=srv123us.2017-09-01_00.45.28_34 01-Sep 00:47 backup01-de-dir JobId 8789: Using Device "web" to write. 01-Sep 00:51 srv123us-fd JobId 8789: Warning: bsock.c:112 Could not connect to Storage daemon on 1.1.1.1:9103. ERR=Connection timed out 01-Sep 01:17 srv123us-fd JobId 8789: Fatal error: bsock.c:118 Unable to connect to Storage daemon on 1.1.1.1:9103. ERR=Interrupted system call 01-Sep 01:17 srv123us-fd JobId 8789: Fatal error: job.c:1893 Failed to connect to Storage daemon: 1.1.1.1:9103 01-Sep 01:17 backup01-de-dir JobId 8789: Fatal error: Bad response to Storage command: wanted 2000 OK storage 01-Sep 01:17 backup01-de-dir JobId 8789: Error: Bacula backup01-de-dir 7.0.5 (28Jul14): Build OS: x86_64-pc-linux-gnu ubuntu 16.04 JobId: 8789 Job: srv123us.2017-09-01_00.45.28_34 Backup Level: Full (upgraded from Incremental) Client: "srv123us" 7.0.5 (28Jul14) x86_64-pc-linux-gnu,ubuntu,16.04 FileSet: "web" 2017-11-07 17:19:45 Pool: "web-full" (From Job FullPool override) Catalog: "ucdn" (From Client resource) Storage: "web" (From Job resource) Scheduled time: 01-Sep-2018 00:47:11 Start time: 01-Sep-2018 00:47:11 End time: 01-Sep-2018 01:17:23 Elapsed time: 30 mins 12 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: 4719 Volume Session Time: 1510075534 Last Volume Bytes: 0 (0 B) Non-fatal FD errors: 2 SD Errors: 0 FD termination status: Error SD termination status: Waiting on FD Termination: *** Backup Error ***
But when we check the status of client from “bconsole” (Bacula’s management Console), everything seems OK, the backup server (Director daemon = bacula-dir) connects and get the report from the client daemon (Bacula File service = bacula-fd) in the server, even when you run a backup job, the status report is OK, the backup is running on the client, here is the output:
srv@local ~ # bconsole
Connecting to Director localhost:9101
1000 OK: 1 backup01-de-dir Version: 7.0.5 (28 July 2014)
Enter a period to cancel a command.
*status
Status available for:
1: Director
2: Storage
3: Client
4: Scheduled
5: All
Select daemon type for status (1-5): 3
The defined Client resources are:
1: srv1us
2: srv2us
3: srv123us
Select Client (File daemon) resource (1-3): 3
Connecting to Client srv123us at 108.61.250.36:9102
srv123us-fd Version: 7.0.5 (28 July 2014) x86_64-pc-linux-gnu ubuntu 16.04
Daemon started 23-Feb-17 00:43. Jobs: run=1 running=0.
Heap: heap=98,304 smbytes=571,344 max_bytes=571,361 bufs=97 max_bufs=97
Sizes: boffset_t=8 size_t=8 debug=0 trace=0 mode=0,0 bwlimit=0kB/s
Plugin: bpipe-fd.so
Running Jobs:
JobId 8789 Job srv123us.2017-09-01_00.45.28_34 is running.
Incremental Backup Job started: 01-Sep-17 00:45
Files=0 Bytes=0 AveBytes/sec=0 LastBytes/sec=0 Errors=0
Bwlimit=0
Files: Examined=5 Backed up=0
SDReadSeqNo=6 fd=5
Director connected at: 01-Sep-17 01:10
====
Terminated Jobs:
====
As you can see, everything seems OK of the status, there was a running job in the client server and it seemed the backup process had been running without errors for more then 20 minutes, but then suddenly got Fatal error (the first log):
01-Sep 00:51 srv123us-fd JobId 8789: Warning: bsock.c:112 Could not connect to Storage daemon on 1.1.1.1:9103. ERR=Connection timed out 01-Sep 01:17 srv123us-fd JobId 8789: Fatal error: bsock.c:118 Unable to connect to Storage daemon on 1.1.1.1:9103. ERR=Interrupted system call 01-Sep 01:17 srv123us-fd JobId 8789: Fatal error: job.c:1893 Failed to connect to Storage daemon: 1.1.1.1:9103 01-Sep 01:17 backup01-de-dir JobId 8789: Fatal error: Bad response to Storage command: wanted 2000 OK storage
And the problem is that, the Director (backup server) connects to the File Service of the client (the daemon on the client), but the opposite connection is not possible! When the backup is ready, the client daemon bacula file service connects to the bacula storage service (which could be on the same server with the director, but it could be on another server) to send the backup files and here is the problem! Client could not connect to the storage! So always check the two way connections: backup server -> client server-port:9102 and backup server-port:9103 (or storage server) <- client.
In the world of bacula:
bacula-dir -> bacula-fd:9102
bacula-sd:9103 -> bacula-fd
Misleading error on causal look it seems like bacula-sd is returning error to bacula-fd (which would mean that bacula-fd could connect to bacula-sd after all), but in reality bacula-dir received and logged that bacula-fd did not connect to bacula-sd resulting in Fatal error.
In our situation the firewall of the backup server was denying the connections from the client, but it could be a DNS resolve issue or another network problem. Most common problems are firewall or DNS resolve issues. The solution – just add accept rule for the IP of the client to connect to port 9103 of the backup (storage) server.