Bug 726147 - Log error messages into syslog in SysV init scripts
Summary: Log error messages into syslog in SysV init scripts
Keywords:
Status: CLOSED ERRATA
Alias: None
Product: Fedora
Classification: Fedora
Component: bacula
Version: 15
Hardware: All
OS: Linux
unspecified
high
Target Milestone: ---
Assignee: Andreas Thienemann
QA Contact: Fedora Extras Quality Assurance
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2011-07-27 16:48 UTC by Edouard Bourguignon
Modified: 2012-01-25 22:31 UTC (History)
9 users (show)

Fixed In Version: bacula-5.0.3-22.fc15
Doc Type: Bug Fix
Doc Text:
Clone Of:
Environment:
Last Closed: 2012-01-20 15:46:30 UTC
Type: ---
Embargoed:


Attachments (Terms of Use)
bacula-dir.conf (8.61 KB, text/plain)
2011-08-11 12:24 UTC, Edouard Bourguignon
no flags Details
proposed patch that adds loging errors into syslog (2.63 KB, patch)
2011-08-16 13:08 UTC, Honza Horak
no flags Details | Diff

Description Edouard Bourguignon 2011-07-27 16:48:11 UTC
Description of problem:
Can't start bacula-dir service via systemd or init.d

Version-Release number of selected component (if applicable):
bacula-director-common-5.0.3-9.fc15.x86_64

How reproducible:
static

Steps to Reproduce:
1. yum install bacula-director-common
2. service bacula-dir start
  
Actual results:
Nothing, systemctl says bacula-dir is started, but no process are really launched.


Expected results:
bacula-dir should start as expected

Additional info:
bacula -c /etc/bacula/bacula-dir.conf works fine as a workaround. Trying to debug bacula-dir initscript seeams to be hard, can't add any debug commands after the sourcing of /etc/init.d/functions.

Comment 1 Edouard Bourguignon 2011-08-04 14:09:26 UTC
anyone here?

Comment 2 Honza Horak 2011-08-08 16:10:12 UTC
It works by me, does /var/log/bacula/bacula.log say anything?

Comment 3 Edouard Bourguignon 2011-08-08 16:43:42 UTC
nope /var/log/bacula/bacula.log is empty.

Have same problem on F15 hosts running bacula-dir with mysql or postgresql support.

Comment 4 Honza Horak 2011-08-09 13:24:16 UTC
What about /var/log/messages? Anything suspicious there?
And what does 'systemctl status bacula-dir.service' say?
Can you attach your config files (with all confidential values like passwords cleared)?

Comment 5 Edouard Bourguignon 2011-08-09 17:54:33 UTC
[root@osiris ~]# /etc/init.d/bacula-dir start
Starting bacula-dir (via systemctl):                       [  OK  ]
[root@osiris ~]# /etc/init.d/bacula-dir status
bacula-dir.service - SYSV: Bacula-dir is the Backup-server, which is the program that schedules backups and controls the bacula-client and the bacula-storage daemons.
          Loaded: loaded (/etc/rc.d/init.d/bacula-dir)
          Active: active (exited) since Tue, 09 Aug 2011 19:43:47 +0200; 7min ago
         Process: 2987 ExecStart=/etc/rc.d/init.d/bacula-dir start (code=exited, status=6/NOTCONFIGURED)
          CGroup: name=systemd:/system/bacula-dir.service

I thought it could be selinux preventing bacula start, but I have nothing in /var/log/audit/audit.log

Nothing in /var/log/messages

But when I manually start bacula with:

bacula-dir -c /etc/bacula/bacula-dir.conf -v -f -u bacula -g bacula

Nothing in the log too but I can connect with bconsole and everything seems fine.

Comment 6 Edouard Bourguignon 2011-08-09 17:56:43 UTC
[root@osiris ~]# /etc/init.d/bacula-dir start
+ . /etc/rc.d/init.d/functions
++ TEXTDOMAIN=initscripts
++ umask 022
++ PATH=/sbin:/usr/sbin:/bin:/usr/bin
++ export PATH
++ '[' 2870 -ne 1 -a -z '' ']'
++ /bin/mountpoint -q /cgroup/systemd
++ /bin/mountpoint -q /sys/fs/cgroup/systemd
++ case "$0" in
++ _use_systemctl=1
++ '[' -z '' ']'
++ COLUMNS=80
++ '[' -z '' ']'
++ '[' -r /dev/stderr ']'
+++ /sbin/consoletype
++ CONSOLETYPE=pty
++ '[' -z '' ']'
++ '[' -z '' ']'
++ '[' -f /etc/sysconfig/i18n ']'
++ . /etc/profile.d/lang.sh
++ unset LANGSH_SOURCED
++ '[' -z '' ']'
++ '[' -f /etc/sysconfig/init ']'
++ . /etc/sysconfig/init
+++ BOOTUP=color
+++ RES_COL=60
+++ MOVE_TO_COL='echo -en \033[60G'
+++ SETCOLOR_SUCCESS='echo -en \033[0;32m'
+++ SETCOLOR_FAILURE='echo -en \033[0;31m'
+++ SETCOLOR_WARNING='echo -en \033[0;33m'
+++ SETCOLOR_NORMAL='echo -en \033[0;39m'
+++ AUTOSWAP=no
+++ ACTIVE_CONSOLES='/dev/tty[1-6]'
+++ SINGLE=/sbin/sushell
++ '[' pty = serial ']'
++ __sed_discard_ignored_files='/\(~\|\.bak\|\.orig\|\.rpmnew\|\.rpmorig\|\.rpmsave\)$/d'
++ '[' 1 = 1 ']'
++ '[' xstart = xstart -o xstart = xstop -o xstart = xrestart -o xstart = xreload -o xstart = xtry-restart -o xstart = xforce-reload -o xstart = xcondrestart ']'
++ systemctl_redirect /etc/init.d/bacula-dir start
++ local s
++ local prog=bacula-dir
++ local command=start
++ local options=
++ case "$command" in
++ s='Starting bacula-dir (via systemctl): '
++ '[' -n '' ']'
++ action 'Starting bacula-dir (via systemctl): ' /bin/systemctl start bacula-dir.service
++ local STRING rc
++ STRING='Starting bacula-dir (via systemctl): '
++ echo -n 'Starting bacula-dir (via systemctl):  '
Starting bacula-dir (via systemctl):  ++ shift
++ /bin/systemctl start bacula-dir.service
++ success 'Starting bacula-dir (via systemctl): '
++ '[' color '!=' verbose -a -z '' ']'
++ echo_success
++ '[' color = color ']'
++ echo -en '\033[60G'
                                                           ++ echo -n '['
[++ '[' color = color ']'
++ echo -en '\033[0;32m'
++ echo -n '  OK  '
  OK  ++ '[' color = color ']'
++ echo -en '\033[0;39m'
++ echo -n ']'
]++ echo -ne '\r'
++ return 0
++ return 0
++ rc=0
++ echo

++ return 0
++ exit 0


Seems the initscript try to start bacula via systemctl, where is define the unit bacula.service?

Comment 7 Honza Horak 2011-08-10 07:27:40 UTC
(In reply to comment #5)
>          Process: 2987 ExecStart=/etc/rc.d/init.d/bacula-dir start
> (code=exited, status=6/NOTCONFIGURED)
>           CGroup: name=systemd:/system/bacula-dir.service

It seems like there is only one place where starting the service can fail with status 6 - the following peace of init script:

checkconf() {
        # Check if we still have our @@PLACEHOLDERS@@ in the config.
        # If yes, refuse to start, the user has never touched the config.
        grep -q '^[^#].*_PASSWORD@@' $CONFIG
        if [ $? -eq 0 ]; then
                echo -n "Error: Program has not been configured"
                echo_failure
                echo
                exit 6
        fi
}

The above checks whether there is any "un-commented" line containing "_PASSWORD@@", which means the config files haven't been changed after install. 

Nevertheless, it can fail even if the properly commented line has some white characters in the beginning, e.g. the first line is commented correctly, but init script will fail, but not in the second case:
  #Password = "@@SD_PASSWORD@@"
#  Password = "@@SD_PASSWORD@@"

Can this be your case, Edouard?

Comment 8 Edouard Bourguignon 2011-08-10 20:13:40 UTC
stupid checkconf function, I'm not in that case but my password still match the  grep '^[^#].*_PASSWORD@@'... because it ends with _PASSWORD@@
I will try to change all our passwords.

Comment 9 Edouard Bourguignon 2011-08-10 20:21:10 UTC
No luck, if this was the checkconf I should see the error message "Error: Default password in config" which is not the case. service bacula-dir start just print "OK" but no bacula process.

Comment 10 Honza Horak 2011-08-11 10:27:23 UTC
Is the output of "systemctl status bacula-dir.service" different now after you've changed all passwords?

I think I've reproduced your issue with the following:
1) keep default passwords (@@SD_PASSWORD@@, etc.) in /etc/bacula/bacula-dir.conf 2) run bacula-dir using the old way: 
   # service bacula-dir start
3) see that systemd reports [OK]
4) run "systemctl status bacula-dir" 
5) see that systemd reports "status=6/NOTCONFIGURED"

I think the only confusion can be the "[OK]" message, which is printed even if exit code is 6 (program not configured). This seems like an issue in systemd, so I've reported this as a bug #729932.

Comment 11 Edouard Bourguignon 2011-08-11 12:14:14 UTC
No same output, even if I change all my password and don't keep any default password (@@*_PASSWORD@@), I get the NOTCONFIGURED status (cf Comment 5).

It seems systemd is not calling back the initscript.

Comment 12 Edouard Bourguignon 2011-08-11 12:23:47 UTC
Even if systemd is not correctly handling the exit status code 6, I still think there is a problem on the bacula side. I mean I have configured it, I didn't have this problem on F14 or older Fedora. So why the initscript returns a not configured state?

Thanks for your time.

I will add my bacula-dir.conf

Comment 13 Edouard Bourguignon 2011-08-11 12:24:30 UTC
Created attachment 517784 [details]
bacula-dir.conf

Comment 14 Honza Horak 2011-08-16 06:52:10 UTC
(In reply to comment #13)
> Created attachment 517784 [details]
> bacula-dir.conf

I've tried your config and it works for me. 

You can try to add the following line into your bacula-dir init script, just to know where the init script exits:

--- /etc/init.d/bacula-dir.orig	2011-08-16 08:45:26.746998024 +0200
+++ /etc/init.d/bacula-dir	2011-08-16 08:42:28.283000439 +0200
@@ -38,6 +38,7 @@ checkconf() {
 	# If yes, refuse to start, the user has never touched the config.
 	grep -q '^[^#].*_PASSWORD@@' $CONFIG
 	if [ $? -eq 0 ]; then
+		logger -t bacula-dir "Error: Default password in config file $CONFIG"
 		echo -n "Error: Default password in config"
 		echo_failure
 		echo

If it exists because config file check fails, you should see the following message in /var/log/messages:
bacula-dir: Error: Default password in config file /etc/bacula/bacula-dir.conf

Comment 15 Edouard Bourguignon 2011-08-16 12:11:16 UTC
Ok it's working now with my password! I had to comment the checkconf function.

Should be great to include the logger in the default initscript since I never get the echo -n "Error: Default password in config" (because of systemd?). But may be this will be fixed when systemd will handle exit code 6.

BTW what is the use to check if the conf file was edited or not? Is it dangerous to run bacula with default conf file? The default file is quite ok and works fine (if checkconf is not call).
 It's a bit uncommon to provide a service that can't be run out of the box. I don't remember this was the case with previous version of bacula-dir. I loose a lot of time just because my password were ending by __PASSWORD@@ it's weird, isn't it?

Comment 16 Honza Horak 2011-08-16 12:58:15 UTC
(In reply to comment #15)
> Ok it's working now with my password! I had to comment the checkconf function.
> 
> Should be great to include the logger in the default initscript since I never
> get the echo -n "Error: Default password in config" (because of systemd?). But
> may be this will be fixed when systemd will handle exit code 6.

I think a reasonable change would be logging all error messages using syslog instead of printing them in SysV init script. This can be changed in F15, so I'm changing the subject of this bug.

However, if we use systemd native unit files and specify StandardOutput=syslog, it will do the same thing, so it won't be an issue in F16 any more, after bug #657216 will be resolved.
 
> BTW what is the use to check if the conf file was edited or not? Is it
> dangerous to run bacula with default conf file? The default file is quite ok
> and works fine (if checkconf is not call).

Generally, using default passwords is a security issue, and this check is in bacula init script from its initial build. In F14 (before systemd) all messages were printed correctly when you tried "service bacula-dir start", so every user was aware of what was wrong. 

>  It's a bit uncommon to provide a service that can't be run out of the box. I
> don't remember this was the case with previous version of bacula-dir. I loose a
> lot of time just because my password were ending by __PASSWORD@@ it's weird,
> isn't it?

I think it's no problem to accept, that it is not allowed to use passwords ending with "__PASSWORD@@". But it should be documented at least. There is already a feature request to a Fedora-specific README file in bug#556669, but still unresolved. I've added some points that should be considered there, you can add some others..

Comment 17 Honza Horak 2011-08-16 13:08:09 UTC
Created attachment 518484 [details]
proposed patch that adds loging errors into syslog

Comment 18 Edouard Bourguignon 2011-08-16 14:34:14 UTC
Great! Everything is making sense now for me, I'm now able to use bacula correctly. Thanks for your time.

I will check the bug #556669, I agree to it should be great to have a fedora specific readme file.

Anything about bug #724894 ?

Comment 19 Simone Caronni 2012-01-20 15:46:30 UTC
Added a README.Fedora in version 5.2.4-2 in rawhide. There's a note on how to quickly setup a running system and a note about the blank passwords.

Comment 20 Fedora Update System 2012-01-24 10:27:40 UTC
bacula-5.0.3-20.fc16 has been submitted as an update for Fedora 16.
https://admin.fedoraproject.org/updates/bacula-5.0.3-20.fc16

Comment 21 Fedora Update System 2012-01-24 10:30:03 UTC
bacula-5.0.3-20.fc15 has been submitted as an update for Fedora 15.
https://admin.fedoraproject.org/updates/bacula-5.0.3-20.fc15

Comment 22 Fedora Update System 2012-01-25 08:40:04 UTC
bacula-5.0.3-22.fc16 has been submitted as an update for Fedora 16.
https://admin.fedoraproject.org/updates/bacula-5.0.3-22.fc16

Comment 23 Fedora Update System 2012-01-25 08:41:43 UTC
bacula-5.0.3-22.fc15 has been submitted as an update for Fedora 15.
https://admin.fedoraproject.org/updates/bacula-5.0.3-22.fc15

Comment 24 Fedora Update System 2012-01-25 22:28:26 UTC
bacula-5.0.3-22.fc16 has been pushed to the Fedora 16 stable repository.  If problems still persist, please make note of it in this bug report.

Comment 25 Fedora Update System 2012-01-25 22:31:15 UTC
bacula-5.0.3-22.fc15 has been pushed to the Fedora 15 stable repository.  If problems still persist, please make note of it in this bug report.


Note You need to log in before you can comment on or make changes to this bug.