rsyslog not keeping up with dhcpd

[Alex Moen]

I have a virtual Centos7 machine on IBM ESX hardware. It is being 
utilized as a DHCP server for the ISP that I work for. It seems that 
rsyslog is not keeping up with the logging that dhcpd is generating, or 
dhcpd is not sending the logs to rsyslog.

First of all, dhcpd is issuing between 20 and 40 leases per second, 
according to /var/state/dhcpd/dhcpd.leases. If I tail -f /var/log/dhcpd, 
I will see log entries flow for about 5 seconds, then 25 seconds of 
nothing, then another 5 seconds of logs, then 25 seconds of nothing... 
and so on. This is very predictable, and changes very little, offsetting 
a few log entries at a time so the logging times creeps forward slowly. 
If I tail -f /var/state/dhcpd/dhcpd.leases, the lease file is constantly 
being updated, no 25 second pause at any time. So, for the time being, I 
am blaming rsyslog for not keeping up with dhcpd and giving the benefit 
of the doubt to dhcpd.

I have looked at the performance graph for the virtual machine, and have 
not seen any issues with hardware latency. There is plenty of CPU 
overhead, lots of extra memory, and very low disk latency (<= 1 ms). 
Also, if there was an issue with hardware, I would believe that I would 
see the same kind of behavior in the lease file as I do in the log file.

Top shows:

top - 15:36:38 up 21 days, 6:22, 2 users, load average: 0.12, 0.11, 0.13
Tasks: 89 total, 4 running, 85 sleeping, 0 stopped, 0 zombie
%Cpu(s): 1.6 us, 1.6 sy, 0.0 ni, 96.8 id, 0.0 wa, 0.0 hi, 0.0 si, 0.0 st
KiB Mem : 3882828 total, 825304 free, 178580 used, 2878944 buff/cache
KiB Swap: 4095996 total, 4094748 free, 1248 used. 3193348 avail Mem


rsyslog.conf file contents:
cat /etc/rsyslog.conf

$ModLoad imuxsock
$ModLoad imjournal
$WorkDirectory /var/lib/rsyslog
$ActionFileDefaultTemplate RSYSLOG_TraditionalFileFormat
$IncludeConfig /etc/rsyslog.d/*.conf
$OmitLocalLogging on
$IMJournalStateFile imjournal.state

local4.* /var/log/dhcpd
local7.* /var/log/boot.log
*.info;mail.none;authpriv.none;cron.none;local4.none /var/log/messages
authpriv.* /var/log/secure
mail.* -/var/log/maillog
cron.* /var/log/cron
*.emerg :omusrmsg:*
uucp,news.crit /var/log/spooler

The only file in /etc/rsyslog.d is listen.conf:
cat /etc/rsyslog.d/listen.conf

$SystemLogSocketName /run/systemd/journal/syslog


Config pertaining to logging for dhcpd is:

log-facility local4;
if exists agent.circuit-id
{
log ( info, concat(
"ALLIED TELESYN: OPTION82-INFO: Lease for ", binary-to-ascii (10, 8, 
".", leased-address),
" is connected on DSLAM ", ( option agent.remote-id),
" interface ", binary-to-ascii (10, 8, ".", substring( option 
agent.circuit-id, 0, 2)),
", using VLAN ", binary-to-ascii (10, 16, "", substring( option 
agent.circuit-id, 2, 2))
));

log ( info, concat(
"PARADYNE: OPTION82-INFO: Lease for ", binary-to-ascii (10, 8, ".", 
leased-address),
" agent-circuit-id info is: ", (option agent.circuit-id)
));

log ( info, concat(
"CALIX: OPTION82-INFO: Lease for ", binary-to-ascii (10, 8, ".", 
leased-address),
" is connected on DSLAM ", ( option agent.remote-id ),
" VLAN and Port: ", ( option agent.circuit-id )
));

log ( info, concat(
"RAW DATA: Lease for ", binary-to-ascii (10, 8, ".", leased-address),
" raw option-82 info is CID: ", binary-to-ascii (10, 8, ".", option 
agent.circuit-id),
" AID: ", binary-to-ascii (16, 8, ".", option agent.remote-id)
));
}



I'm open to any suggestions or comments... I have rtfm'd, but I can't 
find anything that pertains. I have also googled, but with no success.

Thanks for any help!

Alex
-- 
Alex Moen
NSTII
North Dakota Telephone Company
701-662-6481