Questions about log messages

bimmerdriver

There are some messages in the log that I'm wondering about.

There are a lot of these messages:

Aug 7 12:26:00 sshguard 79849 Now monitoring attacks.
Aug 7 12:26:00 sshguard 85926 Exiting on signal.
Aug 7 11:56:00 sshguard 85926 Now monitoring attacks.
Aug 7 11:56:00 sshguard 20604 Exiting on signal.
Aug 7 11:54:00 sshguard 20604 Now monitoring attacks.
Aug 7 11:54:00 sshguard 83856 Exiting on signal.
Aug 7 11:26:00 sshguard 83856 Now monitoring attacks.
Aug 7 11:26:00 sshguard 2326 Exiting on signal.

Does this mean that SSH is exiting for some reason and restarting?

There are hundreds of these messages:

Aug 8 03:32:55 kernel cannot forward src fe80:5::2a0:a50f:fcc3:d7ec, dst 2001:XXXX:XXXX:b00:1:b3ff:XXXX:9f24, nxt 58, rcvif hn0, outif hn1
Aug 8 03:32:51 kernel cannot forward src fe80:5::2a0:a50f:fcc3:d7ec, dst 2001:XXXX:XXXX:b00:1:b3ff:XXXX:9f24, nxt 58, rcvif hn0, outif hn1
Aug 8 03:32:47 kernel cannot forward src fe80:5::2a0:a50f:fcc3:d7ec, dst 2001:XXXX:XXXX:b00:1:b3ff:XXXX:9f24, nxt 58, rcvif hn0, outif hn1
Aug 8 01:37:52 kernel cannot forward src fe80:5::bac2:530f:fc39:164a, dst 2001:XXXX:XXXX:b00:1:b3ff:XXXX:9f24, nxt 58, rcvif hn0, outif hn1
Aug 8 01:37:48 kernel cannot forward src fe80:5::bac2:530f:fc39:164a, dst 2001:XXXX:XXXX:b00:1:b3ff:XXXX:9f24, nxt 58, rcvif hn0, outif hn1
Aug 8 01:37:44 kernel cannot forward src fe80:5::bac2:530f:fc39:164a, dst 2001:XXXX:XXXX:b00:1:b3ff:XXXX:9f24, nxt 58, rcvif hn0, outif hn1
Aug 8 01:25:49 kernel cannot forward src fe80:5::bac2:530f:fcd4:fdd2, dst 2001:XXXX:XXXX:b00:1:b3ff:XXXX:9f24, nxt 58, rcvif hn0, outif hn1
Aug 8 01:25:45 kernel cannot forward src fe80:5::bac2:530f:fcd4:fdd2, dst 2001:XXXX:XXXX:b00:1:b3ff:XXXX:9f24, nxt 58, rcvif hn0, outif hn1
Aug 8 01:25:41 kernel cannot forward src fe80:5::bac2:530f:fcd4:fdd2, dst 2001:XXXX:XXXX:b00:1:b3ff:XXXX:9f24, nxt 58, rcvif hn0, outif hn1

The destination of these link-local messages is a RIPE Atlas probe that I have on my LAN. The messages are not all from the same link-local address, but every single one starts with fe80:5.

pfSense 2.7.0 release is running on a hyper-v server, connected to a virtual switch, connected to a physical NIC, connected to the bridged port of the ISP router, connected to an ONT. The service is gigabit fiber. hn0 is the WAN. hn1 is the LAN.

The messages appear in bursts, perhaps 5-10 from each of several link-local addresses. There are no other messages being sent to other destinations on my LAN. I sent a question to the RIPE team, but I haven't heard anything back yet. I thought I would ask here to see if anyone has seen anything like this.

Gertjan

@bimmerdriver

Your other messages : "No DHCP4 gateway" means : implies that pfSens doesn't know what to do with incoming (LAN) IPV6 traffic : it can't route it out to elsewhere, typically the Internet.
Make IPv6 work.

this FreeBSD kernel cannot forward src fe80:5, read the first 3, 4 items, says the same thing : make IPv6 work and the message will be gone.

About SSHGaurd : I can confirm that this process loves to restart often, and its on my 'do do list' to find out what the reason is, who is signalling sshguard to restart .... All it really does is 'being verbose in the logs' and as such quiet inoffensive.
I guess it's the pf reload process that syncs pfsense settings to the firewall,NAT, aliases etc etc that also 'kicks' sshguard.

@bimmerdriver said in Questions about log messages:

Does this mean that SSH is exiting

Noop.
sshguard "tails" the system (and other ?) log for known messages, the inverse of

so if it finds failed login attempts, and to many of them, it start to blacklist the offending IPs.

stephenw10

Yup you can't route non-routable link local addresses. It would need to do some sort of NAT if that address is local to pfSense.

sshguard restarting is caused by the logs filling an being rotated. Since sshguard monitors the logs it has to be restarted for the new file. The log spam is a problem though:
https://redmine.pfsense.org/issues/12747

Steve

bimmerdriver

@Gertjan said in Questions about log messages:

@bimmerdriver

Your other messages : "No DHCP4 gateway" means : implies that pfSens doesn't know what to do with incoming (LAN) IPV6 traffic : it can't route it out to elsewhere, typically the Internet.
Make IPv6 work.

What "other messages" are you referring to? Are you referring to some other post? IPv6 is working fine. The messages that I posted above are only for the probe, not any other devices.

this FreeBSD kernel cannot forward src fe80:5, read the first 3, 4 items, says the same thing : make IPv6 work and the message will be gone.

Again, IPv6 is working fine.

I'm wondering where these link-local messages are coming from. hn0 is connected to the bridged port of the ISP router, which is connected to an ONT. I will see if I can ping these addresses from pfSense.

About SSHGaurd : I can confirm that this process loves to restart often, and its on my 'do do list' to find out what the reason is, who is signalling sshguard to restart .... All it really does is 'being verbose in the logs' and as such quiet inoffensive.
I guess it's the pf reload process that syncs pfsense settings to the firewall,NAT, aliases etc etc that also 'kicks' sshguard.

I looked in the log again and all of the messages are on an exact minute interval, and they are often spaced by a multiple of 5 minutes apart. It's not random.

@bimmerdriver said in Questions about log messages:

Does this mean that SSH is exiting

Noop.
sshguard "tails" the system (and other ?) log for known messages, the inverse of

so if it finds failed login attempts, and to many of them, it start to blacklist the offending IPs.

There are no messages for failed login attempts. Other than hundreds of the messages that I posted above, the only other messages in the Authentication section are for successful logins.

stephenw10

It restarts whenever any log it's monitoring rotates. So that might be the firewall log if you have a lot of hits on WAN. It doesn't matter whether or not the log contains auth attempts.

Check /var/log and see which log is rotating.

bimmerdriver

I tried to ping some of the link-local addresses. There were no replies.

I tried to tracert some of the link-local addresses. The replies were all like this:

1 fe80::215:5dff:fe67:5b00%hn0 304.394 ms !A 294.270 ms !A 299.203 ms !A

According to the man pages for freebsd tracert:

!A Communication with destination network administratively prohibited.

This is strange.

stephenw10

Look in the NDP table (Diag NDP). Use the MAC there to reference the ARP table. That should show you what those clients are.

bimmerdriver

@stephenw10 said in Questions about log messages:

It restarts whenever any log it's monitoring rotates. So that might be the firewall log if you have a lot of hits on WAN. It doesn't matter whether or not the log contains auth attempts.

Check /var/log and see which log is rotating.

I'm not clear what to look for in /var/log to see which logs are rotating. I don't think there are a lot of hits on the WAN. This is a home network. (Admittedly, I have a lot more devices than most home networks, but it's not like this is a business.)

Here are some messages from this morning:

Aug 10 07:56:00 sshguard 10572 Now monitoring attacks.
Aug 10 07:56:00 sshguard 76388 Exiting on signal.
Aug 10 07:26:00 sshguard 76388 Now monitoring attacks.
Aug 10 07:26:00 sshguard 86952 Exiting on signal.
Aug 10 06:57:00 sshguard 86952 Now monitoring attacks.
Aug 10 06:57:00 sshguard 45952 Exiting on signal.
Aug 10 06:31:00 sshguard 45952 Now monitoring attacks.
Aug 10 06:31:00 sshguard 96906 Exiting on signal.
Aug 10 06:28:00 sshguard 96906 Now monitoring attacks.
Aug 10 06:28:00 sshguard 34476 Exiting on signal.
Aug 10 05:59:00 sshguard 34476 Now monitoring attacks.
Aug 10 05:59:00 sshguard 69239 Exiting on signal.

SteveITS

@bimmerdriver
The log files should have a timestamp, just look for files with timestamps when the "exiting" happens.

bimmerdriver

@stephenw10 said in Questions about log messages:

Look in the NDP table (Diag NDP). Use the MAC there to reference the ARP table. That should show you what those clients are.

Here are a few messages from this morning:

Aug 10 05:47:17 kernel cannot forward src fe80:5::b68a:5f0f:fcb2:1040, dst 2001:XXXX:XXXX:b00:1:b3ff:fedd:9f24, nxt 58, rcvif hn0, outif hn1
Aug 10 05:47:13 kernel cannot forward src fe80:5::b68a:5f0f:fcb2:1040, dst 2001:XXXX:XXXX:b00:1:b3ff:fedd:9f24, nxt 58, rcvif hn0, outif hn1
Aug 10 05:47:09 kernel cannot forward src fe80:5::b68a:5f0f:fcb2:1040, dst 2001:XXXX:XXXX:b00:1:b3ff:fedd:9f24, nxt 58, rcvif hn0, outif hn1

The link-local address is not in the NDP table. Note, the address is fe80:5::, which is consistent with every other instance of this and is also not consistent with every other link-local address in the NDP table. All of the other addresses are fe80::, as if they are generated from a MAC.

stephenw10

The last 3 octets are from the MAC of the device generating this: b2:10:40. Is there a MAC with those last 3 octets in the ARP table?

stephenw10

@bimmerdriver said in Questions about log messages:

I'm not clear what to look for in /var/log to see which logs are rotating.

Run ls -ls /var/log. Look at the timestamps on the logs and see which are close together.

So for example here:

128 -rw-------  1 root        wheel       127166 Aug 10 17:01 filter.log
504 -rw-------  1 root        wheel       512364 Aug 10 16:11 filter.log.0
504 -rw-------  1 root        wheel       512374 Aug 10 12:47 filter.log.1
500 -rw-------  1 root        wheel       511147 Aug 10 09:29 filter.log.2
504 -rw-------  1 root        wheel       512737 Aug 10 06:15 filter.log.3
504 -rw-------  1 root        wheel       513620 Aug 10 03:02 filter.log.4
504 -rw-------  1 root        wheel       512701 Aug  9 23:47 filter.log.5
500 -rw-------  1 root        wheel       511470 Aug  9 20:20 filter.log.6

The filter (firewall) log is rotating at ~3hr intervals.

bimmerdriver

@stephenw10 Two of the logs are turning over.

896 -rw------- 1 root wheel 397866 Aug 10 21:15 /var/log/filter.log
80 -rw------- 1 root wheel 40307 Aug 10 19:19 /var/log/filter.log.0.bz2
80 -rw------- 1 root wheel 37061 Aug 10 17:03 /var/log/filter.log.1.bz2
80 -rw------- 1 root wheel 37364 Aug 10 14:20 /var/log/filter.log.2.bz2
80 -rw------- 1 root wheel 38950 Aug 10 11:57 /var/log/filter.log.3.bz2
80 -rw------- 1 root wheel 38231 Aug 10 09:50 /var/log/filter.log.4.bz2
80 -rw------- 1 root wheel 38185 Aug 10 06:31 /var/log/filter.log.5.bz2
72 -rw------- 1 root wheel 36820 Aug 10 03:32 /var/log/filter.log.6.bz2

656 -rw------- 1 root wheel 332422 Aug 10 21:16 /var/log/nginx.log
24 -rw------- 1 root wheel 8896 Aug 10 21:00 /var/log/nginx.log.0.bz2
24 -rw------- 1 root wheel 9210 Aug 10 20:31 /var/log/nginx.log.1.bz2
24 -rw------- 1 root wheel 9038 Aug 10 20:02 /var/log/nginx.log.2.bz2
24 -rw------- 1 root wheel 9047 Aug 10 19:33 /var/log/nginx.log.3.bz2
24 -rw------- 1 root wheel 9017 Aug 10 19:04 /var/log/nginx.log.4.bz2
24 -rw------- 1 root wheel 8963 Aug 10 18:35 /var/log/nginx.log.5.bz2
24 -rw------- 1 root wheel 9098 Aug 10 18:06 /var/log/nginx.log.6.bz2

The GUI Service tab is filled with messages like this:

Aug 10 17:09:31 nginx 10.28.92.22 - - [10/Aug/2023:17:09:31 -0700] "GET /widgets/widgets/snort_alerts.widget.php?getNewAlerts=1691712571391 HTTP/2.0" 200 252 "https://pfsense.localdomain/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/115.0.0.0 Safari/537.36"
Aug 10 17:09:30 nginx 10.28.92.243 - - [10/Aug/2023:17:09:30 -0700] "POST /getstats.php HTTP/2.0" 200 134 "https://pfsense.localdomain/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/115.0.0.0 Safari/537.36"
Aug 10 17:09:30 nginx 10.28.92.22 - - [10/Aug/2023:17:09:30 -0700] "POST /getstats.php HTTP/2.0" 200 133 "https://pfsense.localdomain/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/115.0.0.0 Safari/537.36"
Aug 10 17:09:29 nginx 10.28.92.22 - - [10/Aug/2023:17:09:29 -0700] "POST /widgets/widgets/gateways.widget.php HTTP/2.0" 403 3549 "https://pfsense.localdomain/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/115.0.0.0 Safari/537.36"

bimmerdriver

@stephenw10 said in Questions about log messages:

The last 3 octets are from the MAC of the device generating this: b2:10:40. Is there a MAC with those last 3 octets in the ARP table?

I looked through the log and I did not see a single instance of one of the source addresses matching with a device in my network.

I found a couple of websites that convert local-link addresses to MAC and they all rejected the addresses, saying they do not correspond to a MAC.

I'm really baffled by this.

stephenw10

Are 10.28.92.22 and 10.28.92.243 your clients? Do they have the pfSense dashboard open all the time?

The only mitigation for this currently is to reduce what's logged and increase the log sizes. Though one of our devs is looking at this now.

bimmerdriver

@stephenw10 said in Questions about log messages:

Are 10.28.92.22 and 10.28.92.243 your clients? Do they have the pfSense dashboard open all the time?

The only mitigation for this currently is to reduce what's logged and increase the log sizes. Though one of our devs is looking at this now.

Both of the clients had the dashboard open while I was monitoring this. I closed one of them.

The messages going into the log from the GUI are very verbose and they should only be logged in a debugging mode. I didn't see any message that appeared to be an error.

Also, the SSH messages are going into both system / general and authentication. They should not be duplicated.

It would also be great if SNORT had its own log.

SteveITS

@bimmerdriver The GUI log is (just) the web server access log so it logs all requests.

Snort does have logs, the alerts are logged but also there’s a log tab on the Snort menu where one can pick one of several log files.

bimmerdriver

I used WireShark to check what's happening on the WAN side of pfSense. The pings are coming from the WAN, however, it appears that the addresses are getting mangled. The "5" is not present in the actual addresses. For example, the actual address for an address logged as "fe80:5::2a0:a50f:fcc3:d7ec" should be "fe80::2a0:a50f:fcc3:d7ec".

Also, looking at the GUI Service log, the messages are being logged at at least 1 Hz, up to 5 Hz. If I didn't know any better, I would suspect that someone left a debug flag set in the code.

Should I log these issues as bugs?

SteveITS

@bimmerdriver
re: the GUI log, web servers log all GET and POST etc. requests they receive. That’s how they track usage on the web site. To not have it log anything, don’t make requests, i.e. log out of pfSense and/or close your browser. What you’ve posted looks like normal web server log entries.

https://redmine.pfsense.org/issues/12833

bimmerdriver

@SteveITS said in Questions about log messages:

https://redmine.pfsense.org/issues/12833

With all due respect, with so many messages going into the log, if an actual error happens, it will be lost. I can see that someone troubleshooting a problem or investigating a possible security breach might want to see every single request, but there should be an option to turn off non-critical messages.