Hide Forgot
+++ This bug was initially created as a clone of Bug #668385 +++ Description of problem: DS pipe log script is getting executed as many times as the service is restarted. This happens when you place the ds-logpipe.py script in the /etc/sysconfig/dirsrv-$inst_name file to start the DS pipelog script when the instance is started. Version-Release number of selected component (if applicable): DS90 How reproducible: Consistently Steps to Reproduce: 1. Configure access logs for named pipe. Set these access log attributes using ldapmodify. nsslapd-accesslog-maxlogsperdir: 1 nsslapd-accesslog-logexpirationtime: -1 nsslapd-accesslog-logrotationtime: -1 nsslapd-accesslog: /var/log/dirsrv/slapd-$inst_name/access.pipe nsslapd-accesslog-logbuffering: off 2. Append the below line into the /etc/sysconfig/dirsrv-$inst_name file. /usr/bin/ds-logpipe.py /var/log/dirsrv/slapd-inst/access.pipe --plugin=/usr/share/dirsrv/data/logregex.py logregex.regex="err=32" > /tmp/test_access & 3. Restart the DS instance using the "service restart dirsrv" command 4. Make sure the ds-logpipe.py script is started after running the above command. 5. Restart the dirsrv service one more time. 6. ds-logpipe.py is being executed everytime the service restarted. Actual results: DS pipe log script is getting executed as many times as the service is restarted. Expected results: It is expected to run only one instance of the DS pipe log script. --- Additional comment from rmeggins on 2011-02-07 22:11:42 EST --- Created attachment 477547 [details] 0001-Bug-668385-DS-pipe-log-script-is-executed-as-many-ti.patch --- Additional comment from rmeggins on 2011-02-10 11:47:37 EST --- To ssh://git.fedorahosted.org/git/389/ds.git 30cb812..1132e09 master -> master commit 1132e09752c8f9aba7a963bfc91a8941000012ca Author: Rich Megginson <rmeggins> Date: Thu Feb 3 18:42:37 2011 -0700 Reviewed by: nkinder (Thanks!) Branch: master Fix Description: The main thing was adding a pid file for the script itself, so it can know if it is running or not. This is the new '-i' argument. The other tricky part was figuring out, when reading the pipe, it is hard to know if the server has really exited or not, and therefore, if the script can exit. When the server is starting up, when it daemonizes, it will close and reopen the log file descriptors. We can detect this as reading just an eof (line == None) from the pipe and nothing else. In this case, we can just reopen the log. When we open the log file, if reading from a server, we always set a timer because the open will block until something writes to the pipe. However, readline() will always return and will never block. Even at eof, if the other side has closed the pipe, readline() will just return None. The documentation on the wiki has been updated with the new information about how to set up the init scripts to use the logpipe. Platforms tested: RHEL6 x86_64 Flag Day: no Doc impact: no To ssh://git.fedorahosted.org/git/389/ds.git f0e39fd..ceec7ba 389-ds-base-1.2.8 -> 389-ds-base-1.2.8 commit ceec7ba4e3b9d8baadf2a34591658484606fab9b Author: Rich Megginson <rmeggins> Date: Thu Feb 3 18:42:37 2011 -0700
Checking in 0009-bump-version-to-1.2.8.rc3.patch; /cvs/dist/rpms/389-ds-base/RHEL-6/0009-bump-version-to-1.2.8.rc3.patch,v <-- 0009-bump-version-to-1.2.8.rc3.patch initial revision: 1.1 done RCS file: /cvs/dist/rpms/389-ds-base/RHEL-6/0010-Bug-668385-DS-pipe-log-script-is-executed-as-many-ti.patch,v done Checking in 0010-Bug-668385-DS-pipe-log-script-is-executed-as-many-ti.patch; /cvs/dist/rpms/389-ds-base/RHEL-6/0010-Bug-668385-DS-pipe-log-script-is-executed-as-many-ti.patch,v <-- 0010-Bug-668385-DS-pipe-log-script-is-executed-as-many-ti.patch initial revision: 1.1 done RCS file: /cvs/dist/rpms/389-ds-base/RHEL-6/0011-bump-version-to-1.2.8.rc4-bump-ds-console-version-to.patch,v done Checking in 0011-bump-version-to-1.2.8.rc4-bump-ds-console-version-to.patch; /cvs/dist/rpms/389-ds-base/RHEL-6/0011-bump-version-to-1.2.8.rc4-bump-ds-console-version-to.patch,v <-- 0011-bump-version-to-1.2.8.rc4-bump-ds-console-version-to.patch initial revision: 1.1 done Checking in 389-ds-base-git.sh; /cvs/dist/rpms/389-ds-base/RHEL-6/389-ds-base-git.sh,v <-- 389-ds-base-git.sh new revision: 1.11; previous revision: 1.10 done Checking in 389-ds-base.spec; /cvs/dist/rpms/389-ds-base/RHEL-6/389-ds-base.spec,v <-- 389-ds-base.spec new revision: 1.20; previous revision: 1.19 done
Tested with the latest 389-ds-base and it fails. [root@ds90-rhel6-32vm slapd-ds90]# rpm -qi 389-ds-base Name : 389-ds-base Relocations: (not relocatable) Version : 1.2.8.2 Vendor: Red Hat, Inc. Release : 1.el6 Build Date: Thu 14 Apr 2011 06:53:22 PM EDT Install Date: Sun 17 Apr 2011 01:33:14 PM EDT Build Host: x86-003.build.bos.redhat.com Group : System Environment/Daemons Source RPM: 389-ds-base-1.2.8.2-1.el6.src.rpm Size : 4094342 License: GPLv2 with exceptions Signature : (none) Packager : Red Hat, Inc. <http://bugzilla.redhat.com/bugzilla> URL : http://port389.org/ Summary : 389 Directory Server (base) Description : 389 Directory Server is an LDAPv3 compliant server. The base package includes the LDAP server and command line utilities for server administration. [root@ds90-rhel6-32vm slapd-ds90]# [root@ds90-rhel6-32vm slapd-ds90]# cat /etc/sysconfig/dirsrv-ds90 # This file is sourced by dirsrv upon startup to set # the default environment for a single specific directory # server instances. To set defaults for all instances, edit # the file in the same directory called dirsrv. # These settings are used by the start-dirsrv and # start-slapd scripts (as well as their associates stop # and restart scripts). Do not edit them unless you know # what you are doing. SERVER_DIR=/usr/lib/dirsrv ; export SERVER_DIR SERVERBIN_DIR=/usr/sbin ; export SERVERBIN_DIR CONFIG_DIR=/etc/dirsrv/slapd-ds90 ; export CONFIG_DIR INST_DIR=/usr/lib/dirsrv/slapd-ds90 ; export INST_DIR RUN_DIR=/var/run/dirsrv ; export RUN_DIR DS_ROOT= ; export DS_ROOT PRODUCT_NAME=slapd ; export PRODUCT_NAME # Put custom instance specific settings below here. /usr/bin/ds-logpipe.py /var/log/dirsrv/slapd-ds90/access.pipe --plugin=/usr/share/dirsrv/data/logregex.py logregex.regex="err=32" > /tmp/test_access & [root@ds90-rhel6-32vm slapd-ds90]# [root@ds90-rhel6-32vm slapd-ds90]# ls -al /var/log/dirsrv/slapd-ds90 total 32 drwxrwx---. 2 nobody nobody 4096 Apr 17 14:39 . drwxr-xr-x. 4 root root 4096 Apr 17 13:46 .. -rw-------. 1 nobody nobody 0 Apr 17 13:46 access prw-------. 1 nobody nobody 0 Apr 17 14:37 access.pipe -rw-------. 1 nobody nobody 63 Apr 17 14:39 access.pipe.rotationinfo -rw-------. 1 nobody nobody 63 Apr 17 13:46 access.rotationinfo -rw-------. 1 nobody nobody 0 Apr 17 13:46 audit -rw-------. 1 nobody nobody 63 Apr 17 13:46 audit.rotationinfo -rw-------. 1 nobody nobody 7159 Apr 17 14:39 errors -rw-------. 1 nobody nobody 63 Apr 17 13:46 errors.rotationinfo [root@ds90-rhel6-32vm slapd-ds90]# ps -ef |grep log root 1121 1 0 Apr10 ? 00:01:02 /sbin/rsyslogd -c 4 gdm 1783 1745 0 Apr10 ? 00:00:00 plymouth-log-viewer --icon gdm 1798 1 0 Apr10 ? 00:00:00 /usr/bin/pulseaudio --start --log-target=syslog root 17841 1 0 14:39 pts/1 00:00:00 python /usr/bin/ds-logpipe.py /var/log/dirsrv/slapd-ds90/access.pipe --plugin=/usr/share/dirsrv/data/logregex.py logregex.regex=err=32 root 17935 16232 0 14:43 pts/1 00:00:00 grep log [root@ds90-rhel6-32vm slapd-ds90]# service dirsrv restart ds90 Shutting down dirsrv: ds90... [ OK ] Starting dirsrv: ds90... [ OK ] [root@ds90-rhel6-32vm slapd-ds90]# ps -ef |grep log root 1121 1 0 Apr10 ? 00:01:02 /sbin/rsyslogd -c 4 gdm 1783 1745 0 Apr10 ? 00:00:00 plymouth-log-viewer --icon gdm 1798 1 0 Apr10 ? 00:00:00 /usr/bin/pulseaudio --start --log-target=syslog root 17841 1 0 14:39 pts/1 00:00:00 python /usr/bin/ds-logpipe.py /var/log/dirsrv/slapd-ds90/access.pipe --plugin=/usr/share/dirsrv/data/logregex.py logregex.regex=err=32 root 17969 1 0 14:43 pts/1 00:00:00 python /usr/bin/ds-logpipe.py /var/log/dirsrv/slapd-ds90/access.pipe --plugin=/usr/share/dirsrv/data/logregex.py logregex.regex=err=32 root 18038 16232 0 14:44 pts/1 00:00:00 grep log [root@ds90-rhel6-32vm slapd-ds90]# service dirsrv restart ds90 Shutting down dirsrv: ds90... [ OK ] Starting dirsrv: ds90... [ OK ] [root@ds90-rhel6-32vm slapd-ds90]# ps -ef |grep log root 1121 1 0 Apr10 ? 00:01:02 /sbin/rsyslogd -c 4 gdm 1783 1745 0 Apr10 ? 00:00:00 plymouth-log-viewer --icon gdm 1798 1 0 Apr10 ? 00:00:00 /usr/bin/pulseaudio --start --log-target=syslog root 17841 1 0 14:39 pts/1 00:00:00 python /usr/bin/ds-logpipe.py /var/log/dirsrv/slapd-ds90/access.pipe --plugin=/usr/share/dirsrv/data/logregex.py logregex.regex=err=32 root 17969 1 0 14:43 pts/1 00:00:00 python /usr/bin/ds-logpipe.py /var/log/dirsrv/slapd-ds90/access.pipe --plugin=/usr/share/dirsrv/data/logregex.py logregex.regex=err=32 root 18070 1 2 14:44 pts/1 00:00:00 python /usr/bin/ds-logpipe.py /var/log/dirsrv/slapd-ds90/access.pipe --plugin=/usr/share/dirsrv/data/logregex.py logregex.regex=err=32 root 18138 16232 0 14:44 pts/1 00:00:00 grep log [root@ds90-rhel6-32vm slapd-ds90]#
The steps to reproduce the bug were old. I have now tested with updated documentation from the wiki... and it passes. [root@ds90-rhel6-32vm sysconfig]# cat /etc/sysconfig/dirsrv-ds90 # This file is sourced by dirsrv upon startup to set # the default environment for a single specific directory # server instances. To set defaults for all instances, edit # the file in the same directory called dirsrv. # These settings are used by the start-dirsrv and # start-slapd scripts (as well as their associates stop # and restart scripts). Do not edit them unless you know # what you are doing. SERVER_DIR=/usr/lib/dirsrv ; export SERVER_DIR SERVERBIN_DIR=/usr/sbin ; export SERVERBIN_DIR CONFIG_DIR=/etc/dirsrv/slapd-ds90 ; export CONFIG_DIR INST_DIR=/usr/lib/dirsrv/slapd-ds90 ; export INST_DIR RUN_DIR=/var/run/dirsrv ; export RUN_DIR DS_ROOT= ; export DS_ROOT PRODUCT_NAME=slapd ; export PRODUCT_NAME # Put custom instance specific settings below here. accpidfile=$RUN_DIR/dslogpipe-ds90-acc.pid # see if there is already a logpipe running - doing a stop or # restart (which first calls stop) should have made the old # one exit, but let's make sure we kill it first if [ -f $accpidfile ] ; then accpid=`cat $accpidfile` if [ -n "$accpid" ] ; then kill "$accpid" > /dev/null 2>&1 fi fi # only log failed binds python /usr/bin/ds-logpipe.py /var/log/dirsrv/slapd-ds90/access.pipe -u nobody \ -s $RUN_DIR/slapd-ds90.pid \ -i $accpidfile --plugin=/usr/share/dirsrv/data/failedbinds.py \ failedbinds.logfile=/var/log/dirsrv/slapd-ds90/access.failedbinds & # sleep gives the script a chance to create the pipe, if necessary sleep 1 [root@ds90-rhel6-32vm sysconfig]# [root@ds90-rhel6-32vm sysconfig]# [root@ds90-rhel6-32vm sysconfig]# ps -ef | grep log root 1121 1 0 Apr10 ? 00:01:02 /sbin/rsyslogd -c 4 gdm 1783 1745 0 Apr10 ? 00:00:00 plymouth-log-viewer --icon gdm 1798 1 0 Apr10 ? 00:00:00 /usr/bin/pulseaudio --start --log-target=syslog root 18497 16232 0 15:02 pts/1 00:00:00 grep log [root@ds90-rhel6-32vm sysconfig]# service dirsrv stop ds90 Shutting down dirsrv: ds90... [ OK ] [root@ds90-rhel6-32vm sysconfig]# service dirsrv start ds90 Starting dirsrv: ds90... [ OK ] [root@ds90-rhel6-32vm sysconfig]# [root@ds90-rhel6-32vm sysconfig]# [root@ds90-rhel6-32vm sysconfig]# ps -ef | grep log root 1121 1 0 Apr10 ? 00:01:02 /sbin/rsyslogd -c 4 gdm 1783 1745 0 Apr10 ? 00:00:00 plymouth-log-viewer --icon gdm 1798 1 0 Apr10 ? 00:00:00 /usr/bin/pulseaudio --start --log-target=syslog nobody 18552 1 0 15:02 pts/1 00:00:00 python /usr/bin/ds-logpipe.py /var/log/dirsrv/slapd-ds90/access.pipe -u nobody -s /var/run/dirsrv/slapd-ds90.pid -i /var/run/dirsrv/dslogpipe-ds90-acc.pid --plugin=/usr/share/dirsrv/data/failedbinds.py failedbinds.logfile=/var/log/dirsrv/slapd-ds90/access.failedbinds root 18621 16232 0 15:03 pts/1 00:00:00 grep log [root@ds90-rhel6-32vm sysconfig]# service dirsrv restart ds90 Shutting down dirsrv: ds90... [ OK ] Starting dirsrv: ds90... [ OK ] [root@ds90-rhel6-32vm sysconfig]# ps -ef | grep log root 1121 1 0 Apr10 ? 00:01:02 /sbin/rsyslogd -c 4 gdm 1783 1745 0 Apr10 ? 00:00:00 plymouth-log-viewer --icon gdm 1798 1 0 Apr10 ? 00:00:00 /usr/bin/pulseaudio --start --log-target=syslog nobody 18655 1 0 15:03 pts/1 00:00:00 python /usr/bin/ds-logpipe.py /var/log/dirsrv/slapd-ds90/access.pipe -u nobody -s /var/run/dirsrv/slapd-ds90.pid -i /var/run/dirsrv/dslogpipe-ds90-acc.pid --plugin=/usr/share/dirsrv/data/failedbinds.py failedbinds.logfile=/var/log/dirsrv/slapd-ds90/access.failedbinds root 18724 16232 0 15:03 pts/1 00:00:00 grep log [root@ds90-rhel6-32vm sysconfig]#
An advisory has been issued which should help the problem described in this bug report. This report is therefore being closed with a resolution of ERRATA. For more information on therefore solution and/or where to find the updated files, please follow the link below. You may reopen this bug report if the solution does not work for you. http://rhn.redhat.com/errata/RHEA-2011-0533.html