Questions about log messages

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".

johnpoz

@tinfoilmatt yeah I don't think many devices do that any more - but if you should be able to see the mac address of these link local addresses in the NDP table.. There was just recently a thread where someone was trying to track down a device sending dhcpv6 on his network.. NDP table should give you the mac, or if pfsense is seeing the traffic you can do a packet capture and get the mac address.

https://forum.netgate.com/topic/197269/unknown-dhcp-ping

They were trying track down what was sending it - which turns out was the hardware his pfsense was running on ipmp port plugged into the same switch so he was seeing the blocks in his firewall lan log.

stephenw10

Ok so you have public IPv6 addresses on your internal devices and most of this traffic is from some WAN side devices sending traffic to those internal devices.

That traffic is unroutable it should never be sent by those devices.

Do you actually see that traffic in a pcap on WAN? With the correct localhost source address?

And now you are also seeing this outbound in a pcap on LAN?

bimmerdriver

Hi All,

Thank you for the replies.

I understand link-local messages are not routable. There is no need to keep restating this.

When I originally noticed these messages in the log, they were all fe80:5::X addressed toward the Atlas probe that's connected to my LAN. I used Wireshark on the WAN and found that they were all originally fe80::X, yet they were appearing in the log as fe80:5::X, hence why I referred to them as "mangled" either by FreeBSD or pfSense. If they are fe80:5::X on the WAN, yet they are being reported in the pfSense log as fe80:5::x, then the bits in the address must have been changed in FreeBSD or pfSense.

I later noticed that there were occasionally some of these inbound messages to other addresses (not the probe). I unfortunately don't have any of them captured.

I also later noticed that there are occasionally some of the logged messages are originating from a Pixel phone (4a) on my LAN, with the destinations being Google or WhatsApp, based on whois. I don't have any of them captured. I searched on the internet and found some instances of Android phones doing this, so I will disregard these messages.

However, I think the incoming messages must have a different explanation. I've had the probe since 2019 and the messages only started to appear a couple of years ago when I first reported it.