wsdd 0.6.3 no longer functional on FreeBSD

[koitsu]

FreeBSD port maintainers recently upgraded from 0.6.2 to 0.6.3 and PR 252742 and now the daemon no longer functions (meaning: Network Neighbourhood no longer shows the machine where wsdd is running).

It will take me some time to figure out why (I'll end up using git bisect to figure out what commit broke things), and I probably won't have time to do the analysis until this weekend.

I at least wanted to report it first.

[koitsu]

The number of commits between 0.6.2 and 0.6.3 were so few, I was able to track it down quickly:

The issue was introduced in 1ed74fe / #72. Reverting this commit restores proper functionality. Quick revert diff (since git revert did not work cleanly due to CHANGELOG.md conflicts):

diff --git a/src/wsdd.py b/src/wsdd.py
index f5a6e50..57069e5 100755
--- a/src/wsdd.py
+++ b/src/wsdd.py
@@ -183,16 +183,6 @@ class MulticastHandler:
             for handler in self.message_handlers[s]:
                 handler.handle_request(msg, address)

-    def send(self, msg, addr):
-        # Request from a client must be answered from a socket that is bound
-        # to the WSD port, i.e. the recv_socket. Messages to multicast
-        # addresses are sent over the dedicated send socket.
-        if addr == self.multicast_address:
-            self.send_socket.sendto(msg, addr)
-        else:
-            self.recv_socket.sendto(msg, addr)
-
-
 # constants for WSD XML/SOAP parsing
 WSA_URI = 'http://schemas.xmlsoap.org/ws/2004/08/addressing'
 WSD_URI = 'http://schemas.xmlsoap.org/ws/2005/04/discovery'
@@ -1549,7 +1539,7 @@ def send_outstanding_messages(block=False):
         addr = send_queue[-1][2]
         msg = send_queue[-1][3]
         try:
-            mch.send(msg, addr)
+            mch.send_socket.sendto(msg, addr)
         except Exception as e:
             logger.error('error while sending packet on {}: {}'.format(
                 mch.interface.name, e))

I don't know if it matters -- I strongly doubt it -- but FreeBSD 11.4-STABLE (where this is being tested) uses Python 3.7.9. The system in question has no firewall, is IPv4-only, etc.. It's the same box (and client) described in #49. Daemon is launched with flags -4 -i em0 -w WORKGROUP.

I don't know where the bug lies, and I would rather not have to go through another ktrace analysis like last time if I can avoid it (it's very time-consuming). :) But best I can tell based on the above code, the if on my system could be proving false, which causes self.recv_socket.sendto to be used -- while in 0.6.2, self.send_socket.sendto would have been used (note send vs. recv). Or there is some OO/scope problem (re: self).

If running the daemon with -vvvvvv (both with and without the revert) would be helpful, let me know.

[christgau]

I just fired up my 12.2-RELEASE machine. The host appears automatically upon boot and also if I start the daemon manually from the command line (without any arguments). The machine uses vanilla v0.6.3 (manually installed, not from ports). However, a manual refresh in Explorer causes an [Errno 45] Operation not supported which only appears for IPv6. For IPv4, no error is printed but the host is also not discovered. So, I can confirm the issue basically. I could swear I had tested the commit before the release also on FreeBSD but apparently that's wrong 😒

As you pointed out, the issue really comes from the commit for solving #72. Formally, the requirement is that answers to multicast requests are answered from a fixed port. This was the reason for the patch you quoted above. On Linux, it's ok to use recv_socket which is bound to required UDP port (3702). Opposite to Linux, the socket is also bound to the multicast group address on FreeBSD. Sending on such a bound IPv4 socket causes the source address to be the multicast address which Windows doesn't accept. For IPv6, such an operation is not allowed. Therefore, we got the error message in that case and no messages goes out which ultimately prevents the host from appearing in Windows.

This finally means the code needs to be adjusted properly instead of using the hacky way with the recv_socket. It also means, you don't need to run a ktrace analysis 😉

Until there is a proper fix, you might consider to replace recv_socket with send_socket here for the port

wsdd/src/wsdd.py

Lines 190 to 193 in cf87b9a

	if addr == self.multicast_address:
	self.send_socket.sendto(msg, addr)
	else:
	self.recv_socket.sendto(msg, addr)

Although it does not comply 100% with the standard, it restores functionality.

[koitsu]

Thanks for the analysis! Very interesting how substantially different FreeBSD and Linux are in this regard and how this manifests.

Can this not be achieved with an if platform.system() == 'FreeBSD' check somewhere? Ports folks have a patch that does what you ask but I wasn't sure if there's a proper way to solve this upstream (i.e. in wsdd itself). I thought I'd ask you beforehand :)

[christgau]

Can this not be achieved with an if platform.system() == 'FreeBSD' check somewhere?

Yes, but I'd like to have a solution that works both on Linux and FreeBSD without such #ifdef-like differentiations. I have already something in preparation which I'll push to a new branch for testing/review.

[black-ish]

I recently also upgraded from an old wsdd version to 0.6.3 and ecnountered a weird thing that made no sense to me and then i read this issue and found a "solution" to that.

Turns out the that " self.recv_socket.sendto(msg, addr) " on line 193 is just weird as I had to make a new iptables rule that was INCOMING (server) from the RECEIVING end (client) but was routed through the OUTGOING (server iptables) table on the server.
Like it did a loop only on the OUTPUT table.

Replacing the "recv" with "send" now has made actual sense in terms of firewall rules.
Oh and that's on Linux.

"-A WSD-OUT -o eth2 -p udp -m udp -s 172.16.0.5-d 172.16.0.10 --sport 3702 --dport 49152:65535 -j ACCEPT"
is the rule I had to add, where "172.16.0.5" is the client "172.16.0.10" is the server and the dports are the ephemeral ports on windows

"DENY-Server-OUTPUT IN= OUT=eth2 SRC=172.16.0.5 DST=172.16.0.10 LEN=1275 TOS=0x00 PREC=0x00 TTL=64 ID=50660 DF PROTO=UDP SPT=3702 DPT=58534 LEN=1255"
This is what iptables is blocking when "recv" is in line 193.

[christgau]

Turns out the that " self.recv_socket.sendto(msg, addr) " on line 193 is just weird

True, this looks strange but it was required to solve #72 and make the message to come the intended source addresses. Now, I changed to the code to use dedicated sockets for the different types of traffic (see issue-80 branch). This works both on FreeBSD and Linux based on my testing. I would highly appreciate if you could check if the daemon works in your environments as well.

[black-ish]

I tried it out and it's the same behaviour, still need the new iptables rule.
I also just check with a Windows ruleset (Windows to Windows) of mine and the same is happening there so that seems indeed to be the intended behaviour.
That is kinda dumb. So you have to open up ports from 1025-65335 due to ephemeral ports ragne being different on different systems..

[christgau]

I tried it out and it's the same behaviour, still need the new iptables rule.

Compared to v0.6.3 the behavior of the code in the issue's branch concerning ports is/should be the same. This is intended. The current usage of ports complies to what is documented here: https://docs.microsoft.com/en-us/windows/win32/wsdapi/discovery-and-metadata-exchange-message-patterns Before v0.6.3 the behavior was actually wrong.

That is kinda dumb. So you have to open up ports from 1025-65335 due to ephemeral ports ragne being different on different systems..

I do not understand why you have to open the firewall for traffic on ephemeral ports. For a WSD host, you could just check for the source port of the outgoing traffic being 3702. Actually, before v0.6.3 it appeared to be even more difficult to get a proper firewall setup, at least according to the original post in #72.

For me, this minimal ruleset works to get wsdd to run (with DROP policy):

-A INPUT -d 239.255.255.250/32 -p udp -m udp --dport 3702 -j ACCEPT
-A INPUT -p tcp -m state --state NEW -m tcp --dport 5357 -j ACCEPT
-A INPUT -m state --state RELATED,ESTABLISHED -j ACCEPT

# simple rule for IGMP 
-A OUTPUT -d 224.0.0.0/4 -j ACCEPT
-A OUTPUT -d 239.255.255.250/32 -p udp -m udp --dport 3702 -j ACCEPT
-A OUTPUT -p udp -m udp --sport 3702 -j ACCEPT
-A OUTPUT -m state --state RELATED,ESTABLISHED -j ACCEPT

[black-ish]

It was actually easier, the simplest ruleset I got away with was:

-A WSD-IN -i eth2 -p udp -m udp -d 239.255.255.250 --dport 3702 -j ACCEPT
-A WSD-IN -i eth2 -p tcp -m tcp -d 172.16.0.5 --dport 5357 -j ACCEPT

-A WSD-OUT -o eth2 -p udp -m udp -s 172.16.0.5 -d 239.255.255.250 --dport 3702 -j ACCEPT
-A WSD-OUT -o eth2 -p tcp -m tcp -s 172.16.0.0/24 --dport 5357 -j ACCEPT

Server was visible and accessible from every computer in the same network.

Now, if I did it a little more restrictive I would add the ephemeral ports range of Win10 "49152:65535", just because I like to understand how it all works and reducing it to allow only what is actually needed for a service.

EDIT: Nevermind most of what I wrote!
When testing it seems some data was still left in memory/buffer somewhere and I still could find everything because of that.
There were also some rules I somehow never moved and were still present.
You are right, it is easier in a sense since now the sport in the extra iptable rule will always be 3702 and not some ephemeral port.

New rule I changed/added:
-A WSD-OUT -o eth2 -p udp -m udp -d 172.16.0.10 --sport 3702 --dport 49152:65535 -j ACCEPT
I still find it a little weird that in the OUTPUT table the destination is the server(172.16.0.10) though.

[Izorkin]

Checking commit ee8783c - working/
Used this firewal ruleset:

-A INPUT -p udp -m state --state NEW -m udp --sport 3702 -s 192.168.10.0/22 -j ACCEPT
-A INPUT -p udp -m state --state NEW -m udp --sport 3702 -s 192.168.11.0/24 -j ACCEPT
-A INPUT -p tcp -m state --state NEW -m tcp --sport 5357 -s 192.168.10.0/22 -j ACCEPT
-A INPUT -p tcp -m state --state NEW -m tcp --sport 5357 -s 192.168.11.0/24 -j ACCEPT

-A INPUT -p udp -m state --state NEW -m udp --dport 3702 -s 192.168.10.0/22 -j ACCEPT
-A INPUT -p udp -m state --state NEW -m udp --dport 3702 -s 192.168.11.0/24 -j ACCEPT
-A INPUT -p tcp -m state --state NEW -m tcp --dport 5357 -s 192.168.10.0/22 -j ACCEPT
-A INPUT -p tcp -m state --state NEW -m tcp --dport 5357 -s 192.168.11.0/24 -j ACCEPT

-A INPUT -p igmp -m state --state NEW -m pkttype --pkt-type multicast -d 239.255.255.250 -j ACCEPT

And found this error:

wsdd[66632]: 2021-01-27 18:57:06,467:wsdd ERROR(pid 66632): error in main loop
wsdd[66632]: Traceback (most recent call last):
wsdd[66632]:   File "/nix/store/klfrg96lb13lbd5jbqbpc4522cvfcvz0-wsdd-0.6.3/bin/.wsdd-wrapped", line 1703, in main
wsdd[66632]:     key.data.handle_request(key)
wsdd[66632]:   File "/nix/store/klfrg96lb13lbd5jbqbpc4522cvfcvz0-wsdd-0.6.3/bin/.wsdd-wrapped", line 210, in handle_request
wsdd[66632]:     handler.handle_request(msg, address)
wsdd[66632]:   File "/nix/store/klfrg96lb13lbd5jbqbpc4522cvfcvz0-wsdd-0.6.3/bin/.wsdd-wrapped", line 585, in handle_request
wsdd[66632]:     self.handle_message(msg, self.mch, address)
wsdd[66632]:   File "/nix/store/klfrg96lb13lbd5jbqbpc4522cvfcvz0-wsdd-0.6.3/bin/.wsdd-wrapped", line 407, in handle_message
wsdd[66632]:     retval = handler(header, body)
wsdd[66632]:   File "/nix/store/klfrg96lb13lbd5jbqbpc4522cvfcvz0-wsdd-0.6.3/bin/.wsdd-wrapped", line 625, in handle_probe_match
wsdd[66632]:     self.perform_metadata_exchange(endpoint, xaddr)
wsdd[66632]:   File "/nix/store/klfrg96lb13lbd5jbqbpc4522cvfcvz0-wsdd-0.6.3/bin/.wsdd-wrapped", line 672, in perform_metadata_exchange
wsdd[66632]:     with urllib.request.urlopen(request, None, 2.0) as stream:
wsdd[66632]:   File "/nix/store/2wwb85hrvvfzkhrlwcj3pqi60nlbi9cq-python3-3.8.7/lib/python3.8/urllib/request.py", line 222, in urlopen
wsdd[66632]:     return opener.open(url, data, timeout)
wsdd[66632]:   File "/nix/store/2wwb85hrvvfzkhrlwcj3pqi60nlbi9cq-python3-3.8.7/lib/python3.8/urllib/request.py", line 525, in open
wsdd[66632]:     response = self._open(req, data)
wsdd[66632]:   File "/nix/store/2wwb85hrvvfzkhrlwcj3pqi60nlbi9cq-python3-3.8.7/lib/python3.8/urllib/request.py", line 542, in _open
wsdd[66632]:     result = self._call_chain(self.handle_open, protocol, protocol +
wsdd[66632]:   File "/nix/store/2wwb85hrvvfzkhrlwcj3pqi60nlbi9cq-python3-3.8.7/lib/python3.8/urllib/request.py", line 502, in _call_chain
wsdd[66632]:     result = func(*args)
wsdd[66632]:   File "/nix/store/2wwb85hrvvfzkhrlwcj3pqi60nlbi9cq-python3-3.8.7/lib/python3.8/urllib/request.py", line 1379, in http_open
wsdd[66632]:     return self.do_open(http.client.HTTPConnection, req)
wsdd[66632]:   File "/nix/store/2wwb85hrvvfzkhrlwcj3pqi60nlbi9cq-python3-3.8.7/lib/python3.8/urllib/request.py", line 1354, in do_open
wsdd[66632]:     r = h.getresponse()
wsdd[66632]:   File "/nix/store/2wwb85hrvvfzkhrlwcj3pqi60nlbi9cq-python3-3.8.7/lib/python3.8/http/client.py", line 1347, in getresponse
wsdd[66632]:     response.begin()
wsdd[66632]:   File "/nix/store/2wwb85hrvvfzkhrlwcj3pqi60nlbi9cq-python3-3.8.7/lib/python3.8/http/client.py", line 307, in begin
wsdd[66632]:     version, status, reason = self._read_status()
wsdd[66632]:   File "/nix/store/2wwb85hrvvfzkhrlwcj3pqi60nlbi9cq-python3-3.8.7/lib/python3.8/http/client.py", line 268, in _read_status
wsdd[66632]:     line = str(self.fp.readline(_MAXLINE + 1), "iso-8859-1")
wsdd[66632]:   File "/nix/store/2wwb85hrvvfzkhrlwcj3pqi60nlbi9cq-python3-3.8.7/lib/python3.8/socket.py", line 669, in readinto
wsdd[66632]:     return self._sock.recv_into(b)
wsdd[66632]: socket.timeout: timed out

[christgau]

@Izorkin based on the log, you are using wsdd now in the discovery mode (client) while the original error was related to the normal (host) operation mode. So this is completely unrelated. In addition, the timeout is not really a fault of wsdd and it is not an error per se. Two possibilities:

1. The other side (the wsd host in that case) does not respond quick enough
2. Your firewall setup prevents establishing a connection to the other side, maybe because the OUTPUT chain is too restrictive.

For the first point, you might check if the default timeout of 2.0 seconds could be increased and a higher values resolves the issue:

wsdd/src/wsdd.py

Line 672 in ee8783c

with urllib.request.urlopen(request, None, 2.0) as stream:

If this really turns out to be a problem, please open a new issue or a PR, if you have a patch.

For the second point, please check your firewall rules, but a discussion of the ruleset might be out of scope... at least for this issue.

[Izorkin]

@christgau resolved this error with timeout of 5.0 seconds. Thanks.

[christgau]

@koitsu have you been able to check whether the issue branch solved the problem for you on FreeBSD? Would be nice to see if it works for you in order to prepare a new release

[koitsu]

Sorry Steffan, I haven't. I've been running with a local copy of wsdd with 1ed74fe reverted.

I was not aware of the issue-80 branch until your above comment. (The instance I saw Linux iptables and iptables log output being discussed in a FreeBSD ticket, I wasn't sure what to think.) I'll switch to that branch and report back here.

[koitsu]

I can confirm branch issue-80 fixes the original problem I reported here.

If a new release is made, please let me know here so that I can update FreeBSD PR 252742 and advise the port maintainer to simply update to the newer version, rather than run with a unique patch.

[christgau]

Great. Thanks for testing and yeah, the this was definitely not the best place to bring up the Linux firewall discussion, although it appeared to be related it a first glance. I'll prepare a new release in the next few days (if not today).

[black-ish]

Sorry about that, thought it was related and didn't want to open a new issue, when this seemed very similiar.

[christgau]

@koitsu v0.6.4 is out which finally solved the issue