Project

General

Profile

Actions

Bug #13530

open

Remote Logging strange behavior

Added by Marcelo Cury over 1 year ago. Updated 6 months ago.

Status:
Incomplete
Priority:
Normal
Assignee:
-
Category:
Logging
Target version:
-
Start date:
Due date:
% Done:

0%

Estimated time:
Release Notes:
Default
Affected Plus Version:
22.05
Affected Architecture:
SG-3100

Description

My SG-3100 (22.05) is configured to send logs to a remote syslog server in my LAN on port 1514.

pfsense remote logs configuration:
  • System Events
  • Firewall Events
  • DNS Events
  • DHCP Events
  • General Authentication Events
  • VPN Events
  • Gateway Monitor Events
  • Network Time Protocol Events

It has been working fine for several days but today I noticed that the Firewall Events stopped ( filterlog ).
The problem didn't happen with other events such as dhcpd, dpinger, filterdns, php-fpm, dhclient, unbound...

I'm not sure what could have triggered the issue, but I fixed by going in Status > System > Logs > Settings > Remote Logging Options and clicked in Save .

2022-09-29T18:36:09.000-03:00 filterlog[41290]: 4,,,1000000103,mvneta2,match,block,in,4,0x0,,239,35008,0,none,6,tcp,40,91.191.209.198,x.x.x.x,47587,3474,0,S,1457975303,,1024,,
2022-09-29T18:36:18.000-03:00 filterlog[41290]: 4,,,1000000103,mvneta2,match,block,in,4,0x0,,45,28891,0,DF,6,tcp,52,123.160.221.63,x.x.x.x,48931,8410,0,S,1759706956,,65535,,mss;nop;wscale;nop;nop;sackOK
2022-09-29T18:36:26.000-03:00 filterlog[41290]: 4,,,1000000103,mvneta0,match,block,in,4,0x0,,241,43257,0,none,6,tcp,44,198.199.107.80,y.y.y.y,41585,46738,0,S,2466400818,,1024,,mss
2022-09-29T18:36:35.000-03:00 filterlog[41290]: 4,,,1000000103,mvneta0,match,block,in,4,0x0,,245,25298,0,none,6,tcp,44,78.128.113.158,y.y.y.y,45686,29828,0,S,1291403791,,1024,,mss
2022-09-29T18:36:42.000-03:00 filterlog[41290]: 4,,,1000000103,mvneta2,match,block,in,4,0x0,,238,19919,0,none,6,tcp,40,5.188.206.38,x.x.x.x,46182,19202,0,S,1628533656,,1024,,
2022-09-29T18:36:43.000-03:00 filterlog[41290]: 158,,,1644897877,mvneta1.10,match,pass,in,4,0x0,,64,1756,0,DF,6,tcp,60,192.168.10.4,50.17.133.142,45699,443,0,S,2029797087,,29200,,mss;sackOK;TS;nop;wscale
2022-09-29T18:36:47.000-03:00 filterlog[41290]: 158,,,1644897877,mvneta1.10,match,pass,in,4,0x0,,64,5909,0,DF,6,tcp,60,192.168.10.4,50.17.133.142,45700,443,0,S,405679345,,29200,,mss;sackOK;TS;nop;wscale
h1. *LAST FIREWALL EVENT ABOVE*
2022-09-29T18:36:49.000-03:00 dhcpd[49200]: Wrote 0 class decls to leases file.
2022-09-29T18:36:49.000-03:00 dhcpd[49200]: Server starting service.
2022-09-29T18:36:49.000-03:00 dhcpd[49200]: Sending on Socket/fallback/fallback-net
2022-09-29T18:36:49.000-03:00 dhcpd[49200]: Sending on BPF/mvneta1.100/00:08:a2:0c:c4:1c/192.168.255.248/29
2022-09-29T18:36:49.000-03:00 dhcpd[49200]: Listening on BPF/mvneta1.100/00:08:a2:0c:c4:1c/192.168.255.248/29
2022-09-29T18:36:49.000-03:00 dhcpd[49200]: Sending on BPF/mvneta1.10/00:08:a2:0c:c4:1c/192.168.10.0/27
2022-09-29T18:36:49.000-03:00 dhcpd[49200]: Listening on BPF/mvneta1.10/00:08:a2:0c:c4:1c/192.168.10.0/27
2022-09-29T18:36:49.000-03:00 dhcpd[49200]: Sending on BPF/mvneta1.20/00:08:a2:0c:c4:1c/192.168.20.0/24
2022-09-29T18:36:49.000-03:00 dhcpd[49200]: Listening on BPF/mvneta1.20/00:08:a2:0c:c4:1c/192.168.20.0/24
2022-09-29T18:36:49.000-03:00 dhcpd[49200]: Wrote 0 leases to leases file.
2022-09-29T18:36:49.000-03:00 dhcpd[49200]: Wrote 0 new dynamic host decls to leases file.
2022-09-29T18:36:49.000-03:00 dhcpd[49200]: Wrote 0 deleted host decls to leases file.
2022-09-29T18:36:49.000-03:00 dhcpd[49200]: All rights reserved.
2022-09-29T18:36:49.000-03:00 dhcpd[49200]: For info, please visit https://www.isc.org/software/dhcp/
2022-09-29T18:36:49.000-03:00 dhcpd[49200]: Database file: /var/db/dhcpd.leases
2022-09-29T18:36:49.000-03:00 dhcpd[49200]: Copyright 2004-2021 Internet Systems Consortium.
2022-09-29T18:36:49.000-03:00 dhcpd[49200]: Config file: /etc/dhcpd.conf
2022-09-29T18:36:49.000-03:00 dhcpd[49200]: Internet Systems Consortium DHCP Server 4.4.2-P1
2022-09-29T18:36:49.000-03:00 dhcpd[49200]: PID file: /var/run/dhcpd.pid
2022-09-29T18:36:49.000-03:00 dhcpd[49200]: For info, please visit https://www.isc.org/software/dhcp/
2022-09-29T18:36:49.000-03:00 dhcpd[49200]: All rights reserved.
2022-09-29T18:36:49.000-03:00 dhcpd[49200]: Copyright 2004-2021 Internet Systems Consortium.
2022-09-29T18:36:49.000-03:00 dhcpd[49200]: Internet Systems Consortium DHCP Server 4.4.2-P1
2022-09-29T18:38:54.000-03:00 dhcpd[49200]: DHCPACK on 192.168.10.13 to 08:00:23:f2:fa:1c via mvneta1.10
2022-09-29T18:38:54.000-03:00 dhcpd[49200]: DHCPREQUEST for 192.168.10.13 from 08:00:23:f2:fa:1c via mvneta1.10
2022-09-29T18:50:05.000-03:00 dpinger[58536]: NET_DHCP z.z.z.z: Alarm latency 10631us stddev 1319us loss 22%
2022-09-29T18:50:10.000-03:00 filterdns[55605]: Adding Action: pf table: plex_wans_ip host: a.a.a.a
2022-09-29T18:50:10.000-03:00 filterdns[55605]: merge_config: configuration reload
2022-09-29T18:50:24.000-03:00 php-fpm[447]: /index.php: Successful login for user 'admin_user' from: 192.168.255.254 (LDAP/rpi3)
2022-09-29T18:57:03.000-03:00 dhcpd[49200]: DHCPACK on 192.168.10.8 to a8:db:03:51:f4:fe via mvneta1.10
2022-09-29T18:57:03.000-03:00 dhcpd[49200]: DHCPREQUEST for 192.168.10.8 from a8:db:03:51:f4:fe via mvneta1.10

Actions #1

Updated by Marcelo Cury over 1 year ago

Kindly change the Priority from this bug from normal to low or very low.
Thanks.

Actions #2

Updated by Jim Pingle over 1 year ago

  • Status changed from New to Incomplete

Unless this can be replicated and reliably reproduced there doesn't seem to be anything actionable here. Without some leads on why it stopped or how to make it stop again, there isn't anything to be done.

If anyone can reproduce it, please detail the steps involved and we can look into it deeper.

Actions #3

Updated by Louis B over 1 year ago

Yep, I just started logging pfsense alarms in GrayLog, and .... it does not work. The firewall logging stops after some time. >> The logging stops on pfSense itself (!) <<, so it is logical that there are no alarm send to the remote system as well. I am running the actual 2.7 build.

Some remarks:
- I did discover the problem, because the graylog server did not show new filterlog alarms, the pfsense dashboard filter widget did not show new alarms and also in the logfile menu there were no new alarms in the filterlog.
- Before I connected the graylog server 2days ago, I never noticed this behavoir (I will disconnect graylog and check if I see the issue again, I do NOT expect that).
- other alarms/messages are still there and forwarded!
- the clear all alarm command in systemlog settings does not change fix the situation
- enabling and disabling the alarm forwarding does not solve the issue as well
- a reboot does! :)
- I noticed that at least sometimes the firewall alarm system did recover after a couple of hours, going to die again shortly after
- the number of alarms generated on my system is relatively low, my pfsense system is more that powerfull enough to deal with that
- my graylog-server is a local server (running in a jail on my truenas system)
- I just copied all files from /var/log to my pc to take a look at the filterlog, perhaps a coincidence
- however is seems just for a short moment and the number of alarms in the log is abnormal low.

Actions #4

Updated by Louis B over 1 year ago

I did some further test. Not only the firewall log stops but also e.g. unbound. I disabled forwarding to GrayLog. At this moment, before I know the cause/it is repaired, it is NO OPTION, because it not working properly, and perhaps more severe, it STOPS local alarming.

Actions #5

Updated by Jim Pingle over 1 year ago

Again, there isn't enough to go on there. It works fine and doesn't stop on many systems in other places (including my own lab). You need to start a forum thread to discuss the issue until you can identify more specific details about why it is stopping in your case, as it has to be specific to your setup/environment/etc.

Actions #6

Updated by Louis B over 1 year ago

Jim, I am still trying to interconnect connect pfsense with my gray log server and there are surely multiple issues below the surface. I try to help!! You should not trow problems to the forum all the time!!

For info:
- after some time can be hours, at least the firewall log collection and as such also forwarding stops.
- strange thing is that in that can WAN-related alarms seems to work better than other ones
- I also noticed that in the situation where the logging hangs, a single fw-message arrives on the graylog platform, where that message is not even in the local logging
- even an reboot does in a lot of cases not fix the problem
- after some time (can be hours), the logging may be returning (for a shorter or longer time)
- DNS-logging (definition the server: log-queries: yes), does stop mostly earlier. That can be 'fixed' by restarting the dns

Actions #7

Updated by Jordan G 6 months ago

unsuccessfully attempted reproducing with my 3100 and graylog - will monitor further to see if anything occurs

Actions

Also available in: Atom PDF