On Update, Portmaster fails to connect to secure DNS

[AwfulMoo]

What happened?

After getting an update notification for Portmaster, and the program completing the update, Portmaster will ask to restart. Upon doing so, it will fail to connect to the Secure DNS without a device restart. (Or possibly the underlying core program).

What did you expect to happen?

I expected Portmaster to restart and work correctly as normal.

How did you reproduce it?

Has occurred on three separate instances. Each after an update of Portmaster.

Additional information

Clicking on the "Secure DNS Error" notification shows the following:
"The internal DNS server failed. Restart Portmaster to try again. Error: listen udp [::1]:53: bind: cannot assign requested address."

Debug-Info: https://support.safing.io/privatebin/?091ff248e2feed83#FdK4Fev92YNdUz8LG6PkAiMTRjEnGiHCfR5TbzQ96DsE

[github-actions]

Greetings and welcome to our community! As this is the first issue you opened here, we wanted to share some useful infos with you:

• 🗣️ Our community on Discord is super helpful and active. We also have an AI-enabled support bot that knows Portmaster well and can give you immediate help.
• 📖 The Wiki answers all common questions and has many important details. If you can't find an answer there, let us know, so we can add anything that's missing.

[Raphty]

You seem to have a Portmaster restart issue, a restart of the whole system should fix that.

[AwfulMoo]

You seem to have a Portmaster restart issue, a restart of the whole system should fix that.

A system restart does fix the "Secure DNS Error" issue, but the underlying issue reoccurs every time there is an update.

Next time an update comes through, I'll be required to restart my system once more, despite Portmaster only prompting for a program restart.

[dhaavi]

I am not sure why it cannot bind after a restart.

How do you restart Portmaster? Do you use the buttons in the UI/notification or do you use systemctl directly?

Is there any other service maybe grabbing that port between restart?

I can see that the API is listening, as well as the IPv4 Secure DNS module - so it must be something else interfering.

[AwfulMoo]

I've been using the buttons in notifications to restart after an update.

I do have two other things running on port 53, but they're bound to different addresses (dnsmasq and systemd-resolved).

Restarting portmaster (via UI or systemctl) seems to work perfectly fine when it's not the result of an update. So nothing is jumping into that port while I'm trying to replicate.

I did notice that the loopback address used is different to what the documentation states.

localhost is a special value, which will make the Portmaster listen on both 127.0.0.1:53 and ::1.

However mine is 127.0.0.17:53 (as per netstat). The setting within portmaster still shows localhost:53.

---

Additionally I forced Portmaster to restart onto the same address/port as systemd-resolved in an attempt to replicate the issue, but instead it threw a completely different error as per below.

Conflicting DNS Software
Restart Portmaster after you have deactivated or properly configured the conflicting software: systemd-resolved (/usr/lib/systemd/systemd-resolved)

I've turned on debug logging now, so will hopefully get more details when the next update is pushed out.

[AwfulMoo]

And we're back!

Unfortunately i don't really have much additional info.
the logs even with debug mode don't really offer much help )at least not to me...)

I'm fairly certain I've managed to rule out a port 53 conflict, see the ss command i ran and output below

user@os:~$ sudo ss -tulpn | grep 53
udp   UNCONN 0      0          127.0.0.17:53         0.0.0.0:*    users:(("portmaster-core",pid=44166,fd=24))
udp   UNCONN 0      0       192.168.122.1:53         0.0.0.0:*    users:(("dnsmasq",pid=1244,fd=5))          
udp   UNCONN 0      0       127.0.0.53%lo:53         0.0.0.0:*    users:(("systemd-resolve",pid=617,fd=13))  
udp   UNCONN 0      0             0.0.0.0:5353       0.0.0.0:*    users:(("portmaster-core",pid=44166,fd=14))
udp   UNCONN 0      0             0.0.0.0:5353       0.0.0.0:*    users:(("avahi-daemon",pid=679,fd=12))     
udp   UNCONN 0      0                [::]:5353          [::]:*    users:(("portmaster-core",pid=44166,fd=16))
udp   UNCONN 0      0                [::]:5353          [::]:*    users:(("avahi-daemon",pid=679,fd=13))     
udp   UNCONN 0      0                [::]:55310         [::]:*    users:(("avahi-daemon",pid=679,fd=15))     
tcp   LISTEN 0      4096    127.0.0.53%lo:53         0.0.0.0:*    users:(("systemd-resolve",pid=617,fd=14))  
tcp   LISTEN 0      32      192.168.122.1:53         0.0.0.0:*    users:(("dnsmasq",pid=1244,fd=6)) 

And the logs show only minimal info

> ^[[36m231017 22:16:58.564 dater/file:099 ▶ DEBU 086^[[0m updater: setting active version of resource all/intel/portmaster/notifications.yaml from <nil> to 20230821.9.6
> ^[[34m231017 22:16:58.566 ules/start:204 ▶ INFO 087^[[0m modules: started profiles
> ^[[34m231017 22:16:58.566 ules/start:204 ▶ INFO 088^[[0m modules: started processes
> ^[[36m231017 22:16:58.566 v/location:294 ▶ DEBU 089^[[0m netenv: getting new device locations
> ^[[34m231017 22:16:58.567 ules/start:204 ▶ INFO 090^[[0m modules: started network
> ^[[34m231017 22:16:58.567 ules/start:204 ▶ INFO 091^[[0m modules: started netquery
> ^[[34m231017 22:16:58.571 /resolvers:462 ▶ INFO 092^[[0m resolver: no scopes loaded
> ^[[34m231017 22:16:58.572 ules/start:204 ▶ INFO 093^[[0m modules: started resolver
> ^[[36m231017 22:16:58.621 sts/module:092 ▶ DEBU 094^[[0m intel/filterlists: using cache database
> ^[[34m231017 22:16:58.621 ules/start:204 ▶ INFO 095^[[0m modules: started filterlists
> ^[[34m231017 22:16:58.621 ules/start:204 ▶ INFO 096^[[0m modules: started intel
> ^[[33m231017 22:16:58.902 v/location:303 ▶ WARN 097^[[0m netenv: failed to get IPv4 device location from traceroute: failed to send icmp packet: write ip4 0.0.0.0->1.1.1.1: sendto: operation not permitted
> ^[[36m231017 22:16:58.902 v/location:111 ▶ DEBU 099^[[0m netenv: added new device location to IPv4 scope: TZ(48/158) from timezone
> ^[[36m231017 22:16:58.902 v/location:111 ▶ DEBU 100^[[0m netenv: added new device location to IPv6 scope: TZ(48/158) from timezone
> ^[[34m231017 22:16:58.971 /conntrack:049 ▶ INFO 101^[[0m nfq: deleted 0 conntrack entries to reset permanent connection verdicts
> ^[[34m231017 22:16:58.973 ules/start:204 ▶ INFO 102^[[0m modules: started interception
> ^[[34m231017 22:16:58.973 ules/start:204 ▶ INFO 103^[[0m modules: started compat
> ^[[34m231017 22:16:58.973 ules/start:204 ▶ INFO 104^[[0m modules: started core
> ^[[34m231017 22:16:58.973 ules/start:204 ▶ INFO 105^[[0m modules: started filter
> ^[[34m231017 22:16:58.973 ules/start:204 ▶ INFO 106^[[0m modules: started nameserver
> ^[[34m231017 22:16:58.973 dules/mgmt:118 ▶ INFO 107^[[0m modules: finished managing
> ^[[34m231017 22:16:58.973 ver/module:146 ▶ INFO 108^[[0m nameserver: starting to listen on 127.0.0.17:53
> ^[[34m231017 22:16:58.973 ver/module:146 ▶ INFO 109^[[0m nameserver: starting to listen on [::1]:53
> ^[[33m231017 22:16:58.974 ver/module:153 ▶ WARN 110^[[0m nameserver: failed to listen on [::1]:53: listen udp [::1]:53: bind: cannot assign requested address
> ^[[36m231017 22:16:59.093 et_handler:260 ▶ DEBU 112^[[0m filter: fast-track accepting api connection: OUT TCP 127.0.0.1:35326 <-> 127.0.0.1:817
> ^[[36m231017 22:16:59.093 connection:994 ▶ DEBU 113^[[0m filter: connection OUT TCP 127.0.0.1:35326 <-> 127.0.0.1:817 fast-tracked
> ^[[36m231017 22:16:59.093 et_handler:260 ▶ DEBU 114^[[0m filter: fast-track accepting api connection: IN TCP 127.0.0.1:817 <-> 127.0.0.1:35326
> ^[[36m231017 22:16:59.094 connection:994 ▶ DEBU 115^[[0m filter: connection IN TCP 127.0.0.1:817 <-> 127.0.0.1:35326 fast-tracked
> ^[[36m231017 22:16:59.129 entication:505 ▶ DEBU 116^[[0m api: issued session cookie
> ^[[34m231017 22:16:59.129 d-response:051 ▶ INFO 117^[[0m api request: 127.0.0.1:35326 HIJ /api/database/v1
> ^[[34m231017 22:16:59.130 i/database:128 ▶ INFO 118^[[0m api request: init websocket 127.0.0.1:35326 /api/database/v1
> ^[[31m231017 22:16:59.185 les/worker:098 ▶ ERRO 119^[[0m nameserver: service-worker dns resolver failed (1): listen udp [::1]:53: bind: cannot assign requested address - restarting in 2s

Finally i tried changing the in use port (to a randomly picked 5392) and restarting Portmaster and I still got the same error

"Secure DNS Error
The internal DNS server failed. Restart Portmaster to try again. Error: listen udp [::1]:5392: bind: cannot assign requested address"

Restarting the Portmaster Service also does not seem to fix the issue, a full computer restart appears to be the only way.
Is it possible there is a locked file or something that is not accessible until after a full restart?

[github-actions]

This issue has been automatically marked as inactive because it has not had activity in the past two months.

If no further activity occurs, this issue will be automatically closed in one week in order to increase our focus on active topics.

[github-actions]

This issue has been automatically closed because it has not had recent activity. Thank you for your contributions.

If the issue has not been resolved, you can find more information in our Wiki or continue the conversation on our Discord.