Hey guys,

I'm having an odd issue with bacula 7.0.5 (on CentOS 7) in that I can start it manually in debug mode. However it doesn't start correctly either using the config script. And it doesn't work if I try to start up bacula using the same flags as the init script.

If I try to start up bacula director using the service, it claims that it's running, but there's nothing listening on the default port of 9101:

#systemctl status bacula-dir

● bacula-dir.service - Bacula-Director, the Backup-server

   Loaded: loaded (/usr/lib/systemd/system/bacula-dir.service; enabled; vendor preset: disabled)

   Active: active (running) since Sun 2016-03-13 19:31:03 UTC; 8s ago

     Docs: man:bacula-dir(8)

 Main PID: 413 (bacula-dir)

   CGroup: /system.slice/bacula-dir.service

           └─413 /usr/sbin/bacula-dir -f -c /etc/bacula/bacula-dir.conf -u bacula -g bacula

Mar 13 19:31:03 ops systemd[1]: Started Bacula-Director, the Backup-server.

Mar 13 19:31:03 ops systemd[1]: Starting Bacula-Director, the Backup-server... 

After that I can confirm that bacula director is "running" but not listening:

[root@ops:/etc/bacula] #ps -ef|grep bacula-dir |grep -v grep | grep -v -i screen

bacula     522     1  0 19:34 ?        00:00:00 /usr/sbin/bacula-dir -f -c /etc/bacula/bacula-dir.conf -u bacula -g bacula

Nothing listening on port 9101:

[root@ops:/etc/bacula] #netstat -tulpn | grep -i listen |grep bacula

tcp        0      0 0.0.0.0:9102            0.0.0.0:*               LISTEN      30659/bacula-fd

tcp        0      0 0.0.0.0:9103            0.0.0.0:*               LISTEN      30820/bacula-sd

[root@ops:/etc/bacula] #lsof -i :9101

[root@ops:/etc/bacula] #

And bconsole can't connect:

[root@ops:/etc/bacula] #bconsole

Connecting to Director ops.jokefire.com:9101

If I start bacula-director manually using the same command as the init script, I get this error:

[root@ops:/etc/bacula] #/usr/sbin/bacula-dir -f -c /etc/bacula/bacula-dir.conf -u bacula -g bacula

bacula-dir: dird.c:972-0 Could not open Catalog "JokefireCatalog", database "bacula".

bacula-dir: dird.c:977-0 mysql.c:198 Unable to connect to MySQL server.

Database=bacula User=admin

MySQL connect failed either server not running or your authorization is incorrect.

13-Mar 19:36 bacula-dir ERROR TERMINATION

Please correct configuration file: /etc/bacula/bacula-dir.conf

I'm also seeing the same messages in the bacula log.

Here it's saying that the username or password is incorrect! However that can't be, because I am able to connect to the database using the same information from the bacula-dir.conf:

# Generic catalog service

Catalog {

  Name = JokefireCatalog

# Uncomment the following line if you want the dbi driver

#  dbdriver = "dbi:mysql"; dbaddress = localhost; dbport = 3306

   dbname = "bacula"; dbuser = "admin"; dbpassword = "secret" ; dbaddress = "localhost"

}

And if I copy and paste the authorization from the conf into the command line i can connect without any problem:

[root@ops:/etc/bacula] #mysql -uadmin -psecret -h localhost -D bacula

Reading table information for completion of table and column names

You can turn off this feature to get a quicker startup with -A

Welcome to the MariaDB monitor.  Commands end with ; or \g.

Your MariaDB connection id is 58

Server version: 10.0.24-MariaDB MariaDB Server

Copyright (c) 2000, 2016, Oracle, MariaDB Corporation Ab and others.

Type 'help;' or '\h' for help. Type '\c' to clear the current input statement.

MariaDB [bacula]>

And the most puzzling piece to this whole thing is, if I start up bacula director in debug mode with the -d100 flag and the -c flag pointing to the same config that the init script is using, everything works just fine!

[root@ops:~] #bacula-dir -d100 -c /etc/bacula/bacula-dir.conf &

[1] 910

[root@ops:~] #bacula-dir: dird.c:194-0 Debug level = 100

bacula-dir: address_conf.c:264-0 Initaddr 0.0.0.0:9101

bacula-dir: jcr.c:128-0 read_last_jobs seek to 192

bacula-dir: jcr.c:135-0 Read num_items=10

bacula-dir: dir_plugins.c:148-0 Load dir plugins

bacula-dir: dir_plugins.c:150-0 No dir plugin dir!

bacula-dir: mysql.c:697-0 db_init_database first time

bacula-dir: mysql.c:165-0 mysql_init done

bacula-dir: mysql.c:190-0 mysql_real_connect done

bacula-dir: mysql.c:192-0 db_user=admin db_name=bacula db_password=secret

bacula-dir: mysql.c:215-0 opendb ref=1 connected=1 db=1ad8750

bacula-dir: mysql.c:237-0 closedb ref=0 connected=1 db=1ad8750

bacula-dir: mysql.c:244-0 close db=1ad8750

ops.jokefire.com: bnet_server.c:87-0 Addresses 0.0.0.0:9101

ops.jokefire.com: job.c:1528-0 wstorage=File

ops.jokefire.com: job.c:1537-0 wstore=File where=Job resource

ops.jokefire.com: job.c:1211-0 JobId=0 created Job=*JobMonitor*.2016-03-13_19.43.56_01

Only at that point, when I run in debug mode everything is working and I can use bacula as I normally would:

[root@ops:~] #bconsole

Connecting to Director ops.jokefire.com:9101

ops.jokefire.com: bnet.c:566-0 who=client host=104.130.30.247 port=9101

ops.jokefire.com: job.c:1528-0 wstorage=File

ops.jokefire.com: job.c:1537-0 wstore=File where=Job resource

ops.jokefire.com: job.c:1211-0 JobId=0 created Job=-Console-.2016-03-13_19.45.40_03

ops.jokefire.com: cram-md5.c:60-0 send: auth cram-md5 challenge <579002952.1457898340 AT ops.jokefire DOT com> ssl=2

ops.jokefire.com: cram-md5.c:119-0 cram-get received: auth cram-md5 <1031769781.1457898340@bconsole> ssl=2

ops.jokefire.com: cram-md5.c:139-0 sending resp to challenge: GG+iFS+RUx+PO9Ige6/HqC

ops.jokefire.com: bnet.c:232-0 TLS server negotiation established.

1000 OK: 1 ops.example.com Version: 7.0.5 (28 July 2014)

Enter a period to cancel a command.

So what I'm trying to figure out, and could use some help with, is why does bacula director not start up correctly using the init script, however it works fine when I run the bacula-dir command in debug mode using the same bacula-dir.conf that is being used by the init script?

Any help would be appreciated!

Thanks,

Tim

--

GPG me!!

gpg --keyserver pool.sks-keyservers.net --recv-keys F186197B