Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

stubby stalls the system startup process on macOS 11.0.1, when having stubby startup as a system service #272

Closed
owah opened this issue Nov 11, 2020 · 13 comments

Comments

@owah
Copy link

owah commented Nov 11, 2020

Hello all,

I've upgraded my laptop to the latest macOS 11 release candidate version, which will officially release tomorrow. After the successful upgrade and logging in, the system was completely unresponsive. Every click to open a program literally took several minutes. After waiting for the activity monitor to open, stubby seemed to be the culprit by hogging 100% cpu, but also all of the available kernel time. Killing the process through activity monitor did not work.

My solution was to rename the stubby binary, so that the homebrew startup service script, could not launch the binary on startup. I first tried to disable the startup script (brew services stop stubby), but the system would just hang and not execute the command. After rebooting and having stubby fail to launch, the system was responsive again, despite not being able to resolve names.

I've launched stubby manually and this did not produce any issues. Only when having stubby launch on startup, the system will hang.

I am not sure how to debug this, as most system utilities are stalling. The only thing that worked was renaming the binary and then on the next system startup, disable stubby.

@saradickinson
Copy link
Contributor

The home-brew formula installs a plist file that controls the service in a directory such as /usr/local/Cellar/stubby/0.3.0/homebrew.mxcl.stubby.plist. You can edit this file and remove the

          <key>RunAtLoad</key>
          <true/>

lines to stop stubby starting automatically at load (start) time. You can still stop/start manually.

You can the also update the ProgramArugements clause to include a extra string

            <string>-l</string>

which will enable logging for stubby, and add these two lines

    <key>StandardErrorPath</key>
    <string>/var/log/stubby.log</string>
    <key>StandardOutPath</key>
    <string>/var/log/stubby.log</string>

which will send the logging to the above file. This may help you see where stubby gets stuck on start up... HTH

@hewz-github
Copy link

I also have the same issue when I run stubby as an brew service.
Even I edit /usr/local/Cellar/stubby/0.3.0/homebrew.mxcl.stubby.plist just like below, the system was totally unresponsive after login.

<?xml version="1.0" encoding="UTF-8"?>
<!DOCTYPE plist PUBLIC "-//Apple//DTD PLIST 1.0//EN" "http://www.apple.com/DTDs/PropertyList-1.0.dtd">
<plist version="1.0">
<dict>
	<key>KeepAlive</key>
	<true/>
	<key>Label</key>
	<string>homebrew.mxcl.stubby</string>
	<key>ProgramArguments</key>
	<array>
		<string>/usr/local/opt/stubby/bin/stubby</string>
		<string>-C</string>
		<string>/usr/local/etc/stubby/stubby.yml</string>
		<string>-l</string>
	</array>
	<key>StandardErrorPath</key>
	<string>/var/log/stubby.log</string>
	<key>StandardOutPath</key>
	<string>/var/log/stubby.log</string>
</dict>
</plist>"

I got the log when the circumstances happened;

[17:40:49.603592] STUBBY: Stubby version: Stubby 0.3.0
[17:40:49.617200] STUBBY: Read config from file /usr/local/etc/stubby/stubby.yml
[17:40:49.618107] STUBBY: DNSSEC Validation is OFF
[17:40:49.618147] STUBBY: Transport list is:
[17:40:49.618185] STUBBY:   - TLS
[17:40:49.618200] STUBBY: Privacy Usage Profile is Strict (Authentication required)
[17:40:49.618213] STUBBY: (NOTE a Strict Profile only applies when TLS is the ONLY transport!!)
[17:40:49.618226] STUBBY: Starting DAEMON....

It seems the system halt after logging Starting DAEMON.....

cf. I attached My stubby setting file.
stubby.yml.txt

About my Mac
macOS version:
11.0.1 (20B29)
System:
MacBook Pro (13-inch, 2019, Two Thunderbolt 3 ports)

@hewz-github
Copy link

hewz-github commented Nov 16, 2020

To workaround this issue,
Instead of using homebrew-services, I used launchctl to load stubby as an daemon service,
because I thought this was more proper procedure to install services.

I put the plist file as below in /Library/LaunchDaemon then loaded it by launchctl:

hewz@MacBook-Pro ~ % sudo launchctl load /Library/LaunchDaemons/org.getdns.stubby.plist

plist file(org.getdns.stubby.plist)

<?xml version="1.0" encoding="UTF-8"?>
<!DOCTYPE plist PUBLIC "-//Apple//DTD PLIST 1.0//EN" "http://www.apple.com/DTDs/PropertyList-1.0.dtd">
<plist version="1.0">
<dict>
	<key>KeepAlive</key>
	<true/>
	<key>Label</key>
	<string>org.getdns.stubby</string>
	<key>ProgramArguments</key>
	<array>
		<string>/usr/local/opt/stubby/bin/stubby</string>
		<string>-C</string>
		<string>/usr/local/etc/stubby/stubby.yml</string>
		<string>-l</string>
	</array>
	<key>RunAtLoad</key>
	<true/>
	<key>StandardErrorPath</key>
	<string>/var/log/stubby.log</string>
	<key>StandardOutPath</key>
	<string>/var/log/stubby.log</string>
	<key>UserName</key>
	<string>root</string>
</dict>
</plist>

But the issue was appeared as same as I experienced using homebrew-services.

So this result suggests stubby has some bug while user login process.

About my Mac
macOS version:
11.0.1 (20B29)
System:
MacBook Pro (13-inch, 2019, Two Thunderbolt 3 ports)

@saradickinson
Copy link
Contributor

@hewz-github home-brew uses launchctl under the hood so the two approaches are equivalent. From you log it appears that Stubby is starting correctly - that is exactly what you should see when stubby launches. So two other things to look at:

  1. can you perform a DNS lookup to 127.0.0.1 and see additional output in the log? If so, stubby is running fine, but is not receiving system DNS requests. To test this try
    dig @127.0.0.1 www.example.com or
    getdns_query @127.0.0.1 www.example.com and you should see something like
[15:42:59.517925] STUBBY: Starting DAEMON....
[10:07:53.869734] STUBBY: 145.100.185.15                           : Conn opened: TLS - Strict Profile
[10:07:53.943798] STUBBY: 145.100.185.15                           : Verify passed : TLS
[10:07:56.979066] STUBBY: 145.100.185.16                           : Conn opened: TLS - Strict Profile
[10:07:57.032507] STUBBY: 145.100.185.16                           : Verify passed : TLS
[10:08:04.031710] STUBBY: 145.100.185.15                           : Conn closed: TLS - Resps=     1, Timeouts  =     0, Curr_auth =Success, Keepalive(ms)= 10000
[10:08:04.031812] STUBBY: 145.100.185.15                           : Upstream   : TLS - Resps=     1, Timeouts  =     0, Best_auth =Success
[10:08:04.031852] STUBBY: 145.100.185.15                           : Upstream   : TLS - Conns=     1, Conn_fails=     0, Conn_shuts=      0, Backoffs     =     0
  1. check the system DNS settings to see what they are: System Preferences->Network->Advanced->DNS. The 'DNS Servers' should be 127.0.0.1 and ::1.

@hewz-github
Copy link

hewz-github commented Nov 24, 2020

@saradickinson DNS settings has been 127.0.0.1 and ::1, which means once I've changed its setting from router IP to local IP (127.0.0.1 and ::1), restart my Mac and login my account, the screen freezes every time.
Plus, it seems to be quite challenging to perform dig or getdns_query under non-responsible screen on macOS.

@saradickinson
Copy link
Contributor

OK - thanks for testing. There is clearly something strange happening with the service, particularly if you say it works fine if you start stubby from the command line... I don't have access to a Big Sur test machine but I'll try to sort one out. Sorry this is an issue for you.

@owah
Copy link
Author

owah commented Nov 25, 2020

Hello,

Sorry, I have been quite busy the last couple of days, but I just want to corroborate the findings and logs here. I have the same settings etc. resulting in the issues I described in my initial comment.

@hewz-github
Copy link

hewz-github commented Dec 3, 2020

Hi - I updated the OS on my Mac to 11.1 Beta (20C5048k), also I upgraded Xcode and Homebrew to adapt "Big Sur v11.1" compatibility.

Then the issue seems to be cleared away...

Are there any fix on macOS side or other Homebrew formula related to this issue?... 🤔

@saradickinson
Copy link
Contributor

Thanks for this report and very glad the issue cleared up.

No recent changes in the stubby formula that I can see. I did find this (oldish) post which does seem to indicate you need the latest Xcode for homebrew to work on Big Sur
Homebrew/brew#7803

@hewz-github
Copy link

Quick Update: macOS 11.1 Beta 2(20C5061b) seems to be okay to run stubby via Homebrew installation.

@hewz-github
Copy link

hewz-github commented Dec 4, 2020

I did find this (oldish) post which does seem to indicate you need the latest Xcode for homebrew to work on Big Sur
Homebrew/brew#7803

Yes, definitely you need to install beta version Xcode matches beta version macOS to run Homebrew.

@saradickinson
Copy link
Contributor

Thanks again - I've added a reference to this issue on the Stubby homebrew installation page:
https://dnsprivacy.org/wiki/pages/viewpage.action?pageId=3145812

@saradickinson
Copy link
Contributor

Closing this issue as does not appear to occur with the most recent macOS releases

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

3 participants