Questions about log messages

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.

SteveITS

@bimmerdriver That's all that log is. Errors aren’t logged to a web server access log. HTTP requests are. It could be used to, say, figure out which IP was logged in at what time and what pages they accessed.

bimmerdriver

@SteveITS said in Questions about log messages:

@bimmerdriver That's all that log is. Errors aren’t logged to a web server access log. HTTP requests are. It could be used to, say, figure out which IP was logged in at what time and what pages they accessed.

Okay, then there should be a setting to turn it off.

stephenw10

Add a note to that bug report.

It's more of an issue because sshguard spams the system log at rotation IMO.

bimmerdriver

@stephenw10 said in Questions about log messages:

Add a note to that bug report.

It's more of an issue because sshguard spams the system log at rotation IMO.

I updated that bug report and created another one for the mangled link-local addresses.

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

bimmerdriver

I have an update on the mangled link-local messages. I updated the bug report Mangled link-local addresses are being logged, but I'm following up here to get more visibility.

When I originally posted about this problem, I was only seeing messages being received from the WAN interface toward the probe on the LAN interface.

Since then, I confirmed using Wireshark that the actual messages being received on the WAN interface were not mangled, so they must be getting mangled in FreeBSD / pfSense.

I also noticed similar messages being sent to other addresses on the LAN. I unfortunately don't have any examples of these messages.

I also noticed messages being sent from a Pixel mobile phone toward Google and WhatsApp. I posted examples of these messages in the bug report.

The inbound messages are all mangled the same way: fe80:5:: as opposed to fe80::.

The outbound messages are all mangled the same way: fe80:6:: as opposed to fe80::.

The messages are not random, with respect to time or address, so something must be doing this.

Does anyone have a suggestion of anything I can do to troubleshoot this?

tinfoilmatt

@bimmerdriver said in Questions about log messages:

The inbound messages are all mangled the same way: fe80:5:: as opposed to fe80::.

The outbound messages are all mangled the same way: fe80:6:: as opposed to fe80::.

Both fe80:5::/128 (i.e., fe80:0005:0000:0000:0000:0000:0000:0000) and fe80:6::/128 (i.e., fe80:0006:0000:0000:0000:0000:0000:0000) are valid IPv6 host addresses and are within the fe80::/10 link-local reserved address block (i.e., fe80:0000:0000:0000:0000:0000:0000:0000 - febf:ffff:ffff:ffff:ffff:ffff:ffff:ffff).

johnpoz

@bimmerdriver to continue with what @tinfoilmatt was pointing out - both fe80:5 and fe80:6 are valid link-local.. But pfsense is not blocking it because its not on the same fe80:X address - but the fact that you can not route a link-local address to a GUA..

link-local address space fe80::/10

If you have some device that wants to talk to GUA address, it would need to be coming from a GUA address

If you assigned a ULA (fc00::/7), you could do some natting and route it and change it GUA.. but link-local by designed to only be used locally on the same network.

If you know what is generating the traffic - it most likely does not have a gua to use, and is stupidly trying to talk via its link-local which is never going to work.

edit: oh I see your on a pixel, so android - this is bad coding on their part.. It is not possible to talk to a gua from a link local, unless maybe the gua was actually on the same local network, but it sure isn't going to route..

tinfoilmatt

I agree with @johnpoz's diagnosis of drop due to link-local source destined for globally routable unicast.

This appears to be the root issue going back almost a couple years now (the improperly configured system logging aside)? And the subject of a Redmine?

@bimmerdriver, if I understand, you believe pfSense is 'mangling' your packets because of the "fe80:5[…]" and "fe80:6[…]" part of the IPv6 addresses you're observing as source addresses in these log messages. But these are valid link-local addresses.

Remember that the second-part of a link-local IPv6 address can sometimes help identify which LAN host is sending these packets. Meaning the "[…]02:61b6" part of fe80:5::1cce:5fff:fe02:616b, and the "[…]xx:3a14" part of fe80:6::e479:xxxx:xxxx:3a14 of these two (valid) link-local addresses.

In many cases, by-default a device will use the MAC address of an attached NIC as the final 48 bits of the 128 bit IPv6 link-local address it creates for it. So those LAN hosts may be identifiable if you observe any with the MAC addresses "xx:xx:xx:02:61:B6" or "xx:xx:xx:xx:3A:14".