Syslog service in pfSense v2.8.1 often stop itself

tsmalmbe

@slu Yes exactly I needed this very obvious steps clearly spelled out to me :) Thank you.

provels

FWIW, I see the service stop randomly, too, but I just use a second HDD mounted on the system drive for my remote logging, so no remote syslog server that might require FW rules. I'd suggest turning on notifications on Watchdog as well so you can check logs.

stephenw10

Do you see any errors logged before it stops? I assume you're using syslog-ng locally for the extra disk?

provels

@stephenw10 Get back to you later.

provels

@stephenw10 Yes, syslog-ng. I'm actually seeing the same type of messages the remote log server users are. Rinse/repeat.
I enabled the watchdog a few days ago but no new notifications of restart since. Notifications are working, as I just enabled the service and waited for the syslogd restart to confirm. From all the repeated entries I see, it seems syslogd get restarted often, far more often than the watchdog would indicate. Some normal, expected actions from syslog-ng? Archiving? Don't know, just blathering. Excuse me if I state the obvious...

Sep 30 17:09:30	syslogd		sendto: Connection refused
Sep 30 17:09:30	syslogd		kernel boot file is /boot/kernel/kernel
Sep 30 17:09:29	syslogd		exiting on signal 15
Sep 30 17:09:01	syslogd		sendto: Connection refused
Sep 30 17:09:01	syslogd		kernel boot file is /boot/kernel/kernel

stephenw10

Hmm, good question. It must be syslog-ng restarting. I would expect that to be logged somewhere though...

provels

@stephenw10 I see a string of these. The => syslog start is the one watchdog started after I enabled it. Doesn't really seem to follow logic, though...
Daemon exited gracefully, not restarting; exitcode='0'

Sep 30 17:08:05	syslogd		exiting on signal 15
Sep 30 17:08:00	syslogd		sendto: Connection refused
Sep 30 17:07:58	supervise/syslog-ng	46549	Daemon exited gracefully, not restarting; exitcode='0'
=> Sep 30 11:17:02	syslogd		kernel boot file is /boot/kernel/kernel
Sep 20 08:43:22	syslogd		sendto: Connection refused
Sep 20 08:43:22	syslogd		kernel boot file is /boot/kernel/kernel
Sep 20 08:43:22	syslogd		exiting on signal 15
Sep 20 08:42:49	syslogd		sendto: Connection refused
Sep 20 08:42:49	syslogd		kernel boot file is /boot/kernel/kernel
Sep 20 08:41:53	syslogd		exiting on signal 15
Sep 20 08:41:47	syslogd		sendto: Connection refused
Sep 20 08:41:46	supervise/syslog-ng	39433	Daemon exited gracefully, not restarting; exitcode='0'
Sep 19 20:20:27	syslogd		kernel boot file is /boot/kernel/kernel
Sep 18 05:55:38	supervise/syslog-ng	64260	Daemon exited gracefully, not restarting; exitcode='0'
Sep 17 09:05:00	syslogd		sendto: Connection refused

provels

@stephenw10 Got a notification that syslogd was restarted at 00:15 today. Looks like the previous default.log gzipped at 23:50, so had that been what stopped syslogd, watchdog would have caught it a minute later.
SYSTEM LOG from last night to present

Oct 3 03:07:59	php-fpm	70563	/index.php: Successful login for user 'admin' from: 192.168.0.82 (Local Database)
Oct 3 03:01:00	root	93209	rc.update_bogons.sh is sleeping for 30028
Oct 3 03:01:00	root	92013	rc.update_bogons.sh is starting up.
Oct 3 01:01:00	php-cgi	63710	rc.dyndns.update: phpDynDNS (mydom.ddns.net): No change in my IP address and/or 25 days has not passed. Not updating dynamic DNS entry.
Oct 3 00:15:03	php-cgi	55524	notify_monitor.php: Message sent to admin@mydom.net OK
Oct 3 00:15:02	syslogd		kernel boot file is /boot/kernel/kernel
Oct 2 21:47:53	php-fpm	44887	/index.php: User logged out for user 'admin' from: 192.168.0.82 (Local Database)

SYSLOG-NG

Oct 3 00:00:00 fw syslog-ng[50722]: Configuration reload finished;
Oct 3 00:00:00 fw syslog-ng[50722]: Configuration reload request received, reloading configuration;
Oct 3 00:10:00 fw syslog-ng[50722]: Log statistics; processed='destination(_DEFAULT)=319', dropped='global(internal_source)=0', processed='global(internal_source)=319', queued='global(internal_source)=0', processed='global(msg_clones)=0', processed='source(_DEFAULT)=319', processed='src.internal(_DEFAULT#0)=319', processed='global(sdata_updates)=0', stamp='src.internal(_DEFAULT#0)=1759467600', queued='global(scratch_buffers_count)=0', processed='global(payload_reallocs)=312', processed='center(queued)=319', processed='center(received)=319', queued='global(scratch_buffers_bytes)=0'
Oct 3 00:15:02 localhost syslogd: kernel boot file is /boot/kernel/kernel
Oct 3 00:15:02 localhost syslogd: restart
Oct 3 00:20:00 fw syslog-ng[50722]: Log statistics; processed='destination(_DEFAULT)=359', dropped='global(internal_source)=0', processed='global(internal_source)=320', queued='global(internal_source)=0', processed='global(msg_clones)=0', processed='source(_DEFAULT)=359', processed='src.internal(_DEFAULT#0)=320', processed='global(sdata_updates)=0', stamp='src.internal(_DEFAULT#0)=1759468200', queued='global(scratch_buffers_count)=0', processed='global(payload_reallocs)=313', processed='center(queued)=359', processed='center(received)=359', queued='global(scratch_buffers_bytes)=0'

stephenw10

Hmm, well if syslog-ng is restarting that would certainbly explain why syslogd sees the refusals and hence ends up stopping. But I don't know why syslog-ng would be doing that,

DBMandrake

@sokeada Noticed this problem a couple of times myself over the last two weeks.

I don't use syslog-ng but do log System Events, General Authentication Events and VPN Events to a remote syslog server on a LibreNMS server.

Although I don't have the data to confirm it, after reading this thread the failures very likely correlate with a reboot of that remote server.

stephenw10

The workaround firewall rules should work for you there.

AlexanderK

i am facing the same issue.
Any fix expept from watchdog and rules?

provels

@AlexanderK At least with Watchdog you'll get informed when it happens. That will give you something to work with to try tracking it down in the logs. That said, mine stopped again a few days ago, coincidentally at 00:15 again (marked XXXX). Perhaps it is some timing issue in syslogd that works only 95% of the time? There re plenty of instances of syslogd exiting and successfully restarting a second later, but sometimes it doesn't without a kick in the pants. In any case, I'll stick with watchdog for the present, won't hurt. Just adding to the conversation, not a big issue for me.

XXXX Oct 14 00:15:02	syslogd		kernel boot file is /boot/kernel/kernel
Oct 8 02:45:53	syslogd		sendto: Connection refused
Oct 8 02:45:53	syslogd		kernel boot file is /boot/kernel/kernel
Oct 8 02:45:52	syslogd		exiting on signal 15
Oct 8 02:45:22	syslogd		sendto: Connection refused
Oct 8 02:45:22	syslogd		kernel boot file is /boot/kernel/kernel
Oct 8 02:44:27	syslogd		exiting on signal 15
Oct 8 02:44:21	syslogd		sendto: Connection refused
XXXX Oct 3 00:15:02	syslogd		kernel boot file is /boot/kernel/kernel
Sep 30 17:09:30	syslogd		sendto: Connection refused

stephenw10

If it's actually external you can add the work-around stateless floating rules to prevent the connection refused message.

provels

@stephenw10 If directed at me, it's not external. It's a second HDD internal to the FW, mounted as a directory on the system SSD. Not complaining.

stephenw10

No sorry that was at the previous poster. The workaround rule won't work for traffic to syslog-ng locally.