Opensnitch gets confused when ping running at the same time as browsing with Firefox

[jspiros]

Using the latest 0.6.0-rc.5-1 release Debian package on a Debian testing/unstable system. Had issues with earlier versions and NFS due to not having eBPF module, but now that it bundles it, NFS works well, so I assume eBPF is working.

Today I noticed some weird sluggishness in Firefox that I intuited may be network issues, so I started a test ping to google.com in a terminal window while I continued browsing. (The ping did reveal some packet loss, I need to check the switches between me and my router as the router shows no dropped packets).

As I loaded up printables.com in Firefox, I got an opensnitch popup relating to the ping google.com process but it seemed to think ping was trying to send ICMP to a printables.com domain. Indeed, even now as I loaded the page to report this issue, I got a similar popup, again relating to the still-running ping command, but some unrelated IP that I presume has to do with GitHub.

So, in short, it seems Opensnitch is getting confused. I didn't react quickly enough to screenshot the popups but I found the event log portion where the printables event occured.

(The screenshot makes the UI look broken, I think that's just because I'm using qt5ct under Cinnamon to try and theme Qt sensibly, and I clearly have failed. Other Qt programs are having similar issues, it's not Opensnitch's fault, I just haven't gotten around to fixing it yet.)

[jspiros]

Oh, and if it helps, I think in both the case of Printables.com and GitHub, I had to authenticate with both sites, and the popup occurred around when I was authenticating, either during or right after. It wouldn't surprise me if something those sites are doing while authenticating is related to Opensnitch's confusion.

[gustavo-iniguez-goya]

Hi @jspiros ,

Thank you for reporting this issue. Please, set LogLevel to DEBUG under Preferences -> Nodes, and see if there're ebpf events in the log file /var/log/opensnitchd.log (specially [eBPF exec event], but also [ebpf conn]).

Do you usually suspend your computer?

Given the description of the problem, it could be caused by: 1) a problem with the cache of domains+CNAMEs, where multiple domains are hosted on the same IP and depending on the rules it could cause this behavior (allow->wget to www.github.developerdan.com (185.199.109.153) , but we return from cache lightswitch05.github.io for 185.199.109.153, so the rule doesn't match and we show a pop-up). 2) ebpf not working as expected, we fallback to proc and we don't return the correct process. But given the screenshot doesn't seem to be the case.

None of the both possible causes really explains this behaviour. printables.com seems to be hosted on cloudflare, while google on google and github on .. github.

Anyway, if you manage to reproduce it again, I'd love the read the debug logs. It's a pity that we don't have right now a way of displaying all the details of a connection (I'll add it ASAP).

[jspiros]

I never suspend my computer. I am able to reproduce this most of the time, even between reboots. I've attached the section of the debug log that starts when I start the ping, and ends when I deny the false ping to printables.com. opensnitchd.log

[gustavo-iniguez-goya]

thank you!

This is what's happenning:

Firefox tries to load media.printables.com, and first it tries to resolve the domain:

[2023-05-06 09:29:50] ^[[100m DBG  ✔ /usr/lib/firefox/firefox -> media.printables.com:53 (allow-always-simple-192-168-0-0-16)
[2023-05-06 09:29:50] ^[[100m DBG  new connection udp => 37670:192.168.0.6 -> 192.168.254.1 (media.printables.com):53 uid: 1000
[2023-05-06 09:29:50] ^[[100m DBG  [ebpf conn] in cache: udp37670192.168.0.6192.168.254.153, 2720 -> /usr/lib/firefox/firefox
[2023-05-06 09:29:50] ^[[100m DBG  ✔ /usr/lib/firefox/firefox -> media.printables.com:53 (allow-always-simple-192-168-0-0-16)
[2023-05-06 09:29:50] ^[[100m DBG  New DNS record: 172.67.5.123 -> media.printables.com

The query returns 172.67.5.123 for media.printables.com, which is correct.

Then it establishes a udp connection (quic?) to the domain:

[2023-05-06 09:29:50] ^[[100m DBG  new connection udp => 47809:192.168.0.6 -> 172.67.5.123 (media.printables.com):443 uid: 1000
[2023-05-06 09:29:50] ^[[100m DBG  [ebpf conn] not in cache, but in execEvents: udp47809192.168.0.6172.67.5.123443, 2720 -> /usr/lib/firefox/firefox
[2023-05-06 09:29:50] ^[[100m DBG  [ebpf conn] adding item to cache: udp47809192.168.0.6172.67.5.123443
[2023-05-06 09:29:50] ^[[100m DBG  ✔ /usr/lib/firefox/firefox -> media.printables.com:443 (allow-always-list-usr-lib-firefox-firefox-443)

good.

Now the strange behaviour is that just after the firefox 443 connection, there's an ICMP to 172.67.5.123: [2023-05-06 09:29:51] ^[[100m DBG new connection icmp => 0:192.168.0.6 -> 172.67.5.123 (media.printables.com):0 uid: 4294967295

When we receive a connection that's not a DNS query, we look in the domains cache to see if the IP has a domain, then we associate it, hence the 172.67.5.123 (media.printables.com):.

Then we proceed to lookup the process that initiated that ICMP:

[2023-05-06 09:29:51] ^[[100m DBG  new connection icmp => 0:192.168.0.6 -> 172.67.5.123 (media.printables.com):0 uid: 4294967295
[2023-05-06 09:29:51] ^[[100m DBG  [0/1] outgoing connection uid: 1000, 0:192.168.0.6 -> 172.67.5.123:0 || netlink response: 1:0.0.0.0 -> 0.0.0.0:0 inode: 45055 - loopback: f$
[2023-05-06 09:29:51] ^[[100m DBG  GetSocketInfo() invalid: 1:0.0.0.0 -> 0.0.0.0:0
[2023-05-06 09:29:51] ^[[100m DBG  netlink socket not found, adding entry:  0:192.168.0.6 -> 172.67.5.123:0 || 1:0.0.0.0 -> 0.0.0.0:0 inode: 45055 state: close
[2023-05-06 09:29:51] ^[[100m DBG  [0/1] outgoing connection uid: 1000, 0:192.168.0.6 -> 172.67.5.123:0 || netlink response: 1:0.0.0.0 -> 0.0.0.0:0 inode: 45055 - loopback: f$
[2023-05-06 09:29:51] ^[[100m DBG  GetSocketInfo() invalid: 1:0.0.0.0 -> 0.0.0.0:0
[2023-05-06 09:29:51] ^[[100m DBG  netlink socket not found, adding entry:  0:192.168.0.6 -> 172.67.5.123:0 || 1:0.0.0.0 -> 0.0.0.0:0 inode: 45055 state: close
[2023-05-06 09:29:51] ^[[100m DBG  new pid lookup took (4390): 4.667572ms
[2023-05-06 09:29:51] ^[[100m DBG  [0] PID found 4390 [45055]

The ICMP connection was not found via ebpf (no [ebpf] traces), so we fallback to procfs, dumping the inodes to see if any of them matched the properties of the connection.

The left side of || is what we expect, and the right side what the kernel dumps filtering by source port. We didn't get any valid inode for the connection (GetSocketInfo() invalid: 1:0.0.0.0 -> 0.0.0.0:0) but as a last resort we added the entry in the hope to find the PID.

We found the PID by that inode, but unfortunately it's the PID of ping instead of firefox's.

soo, one solution could be intercept ICMP packets at ebpf level. A workaround for this particular problem would be to allow ICMP, adding a firewall rule to nftables (either using the GUI or just using nft).

[jspiros]

Very interesting. I wonder if/why Firefox is sending the ICMP packets. On my macOS machine (where I use Little Snitch), I never see anything related to Firefox sending ICMP for these sites (and I think it supports catching ICMP; at least, it allows the creation of rules for ICMP, TCP, UDP, IRTP, and ICMPv6, so I assume so), so maybe it's something specific to my Linux machine and not even Firefox itself.

Anyway, I hope OpenSnitch will eventually use eBPF for ICMP too so it doesn't get confused (and I can be more sure about what process is doing it). For now, it's not that big of a deal, though I prefer some alert to none so I'm not going to create a rule as a workaround.

[swx-1]

most likely ICMP is from firefox captive portal, try disabling it and see if it fixes the issue:

https://support.mozilla.org/en-US/kb/how-stop-firefox-making-automatic-connections#w_network-detection

[gustavo-iniguez-goya]

The reason of this behaviour was explained in detail here: https://github.com/evilsocket/opensnitch/discussions/946#discussioncomment-6035934

Sorry for not update this issue with the link.