Log messages disappear

Niall O'Reilly Niall.oReilly at ucd.ie
Fri Jun 15 11:26:33 UTC 2012


During preparation for some server upgrades, I've encountered a problem
with logging.  At a certain point, the log messages from dhcpd no longer
appear in the log file.  This seems to be whenever the syslog daemon is
reloaded (nightly logrotate, manual -HUP, or whatever).  Subsequently
reloading dhcpd appears to clear the problem, so that messages once again 
appear as expected.

Some relevant details follow below.  I'm sure I can forge a solution,
but I'ld prefer to take advantage of any relevant prior experience to
save myself some "hammer-and-bellows" work.  I'm not looking for 
extended help, but rather for indications such as "Yup, we had that, 
we did X ...", or even (WIBN) "Send in a bug report".

Old server environment -- AFAICS without problem
	hardware platform i386
	RHEL 3.4
	syslogd 1.4.1 (bundled with distro)
	ISC dhcpd 3.1.0 built from source with paranoia feature
	invoked as /usr/sbin/dhcpd -user dhcpd -chroot /local/var/dhcpd/
	default logging configuration (dwz: no logging configured in dhcpd.conf)

New server environment -- with problem
	hardware platform x86_64
	RHEL 6.0
	rsyslogd 4.6.2 (bundled with distro)
	ISC dhcpd 4.2.3-P2 built from source with paranoia feature
	invoked as /usr/local/sbin/dhcpd -user dhcpd -chroot /local/var/dhcpd
	default logging configuration

On the new server, when log messages are no longer appearing, lsof is telling me

dhcpd     24138    dhcpd  cwd       DIR              253,2     4096    1048595 /local/var/dhcpd
dhcpd     24138    dhcpd  rtd       DIR              253,2     4096    1048595 /local/var/dhcpd
dhcpd     24138    dhcpd  txt       REG              253,1  6710190     295585 /usr/local/sbin/dhcpd
dhcpd     24138    dhcpd  mem       REG              253,1   150672     295432 /lib64/ld-2.12.so
dhcpd     24138    dhcpd  mem       REG              253,1  1838296     295433 /lib64/libc-2.12.so
dhcpd     24138    dhcpd  mem       REG              253,1    61624     264731 /lib64/libnss_files-2.12.so
dhcpd     24138    dhcpd    0u      CHR                1,3      0t0    1049796 /local/var/dhcpd/dev/null
dhcpd     24138    dhcpd    1u      CHR                1,3      0t0    1049796 /local/var/dhcpd/dev/null
dhcpd     24138    dhcpd    2u      CHR                1,3      0t0    1049796 /local/var/dhcpd/dev/null
dhcpd     24138    dhcpd    4u      raw                         0t0    1937623 00000000:0001->00000000:0000 st=07
dhcpd     24138    dhcpd    5u     pack            1937628      0t0        ALL type=SOCK_PACKET
dhcpd     24138    dhcpd    6w      REG              253,2    67814    1048648 /local/var/dhcpd/db/dhcpd.leases
dhcpd     24138    dhcpd    7u     IPv4            1937630      0t0        UDP *:bootps 
dhcpd     24138    dhcpd   20u     IPv4            1937616      0t0        UDP *:47430 
dhcpd     24138    dhcpd   21u     IPv6            1937617      0t0        UDP *:57820 

Under normal conditions, I see the following

dhcpd      6090    dhcpd  cwd       DIR              253,2     4096    1048595 /local/var/dhcpd
dhcpd      6090    dhcpd  rtd       DIR              253,2     4096    1048595 /local/var/dhcpd
dhcpd      6090    dhcpd  txt       REG              253,1  6710190     295585 /usr/local/sbin/dhcpd
dhcpd      6090    dhcpd  mem       REG              253,1   150672     295432 /lib64/ld-2.12.so
dhcpd      6090    dhcpd  mem       REG              253,1  1838296     295433 /lib64/libc-2.12.so
dhcpd      6090    dhcpd  mem       REG              253,1    61624     264731 /lib64/libnss_files-2.12.so
dhcpd      6090    dhcpd    0u      CHR                1,3      0t0    1049796 /local/var/dhcpd/dev/null
dhcpd      6090    dhcpd    1u      CHR                1,3      0t0    1049796 /local/var/dhcpd/dev/null
dhcpd      6090    dhcpd    2u      CHR                1,3      0t0    1049796 /local/var/dhcpd/dev/null
dhcpd      6090    dhcpd    3u     unix 0xffff880294b970c0      0t0    2269598 socket
dhcpd      6090    dhcpd    4u      raw                         0t0    2269603 00000000:0001->00000000:0000 st=07
dhcpd      6090    dhcpd    5u     pack            2269608      0t0        ALL type=SOCK_PACKET
dhcpd      6090    dhcpd    6w      REG              253,2    26019    1048636 /local/var/dhcpd/db/dhcpd.leases
dhcpd      6090    dhcpd    7u     IPv4            2269610      0t0        UDP *:bootps 
dhcpd      6090    dhcpd   20u     IPv4            2269596      0t0        UDP *:dtpt 
dhcpd      6090    dhcpd   21u     IPv6            2269597      0t0        UDP *:27977 

The key difference seems to be that FD 3 is missing under problem conditions.
I expect that this is where log entries should be written.

Ideally, dhcpd would notice this and try to recover.  Maybe it does, and can't
succeed on account of the chroot jail.  But then we should probably have
noticed a problem in the old environment.

Otherwise, I expect I'll have to set up triggers for dhcpd in the logrotate 
configuration and in the rsyslog init-script.


Best regards,
Niall O'Reilly



More information about the dhcp-users mailing list