Speed-Test icon indicating copy to clipboard operation
Speed-Test copied to clipboard

Macos Binary stops executing at "OpenSpeedTest-Server : Start Request Received!"

Open kamil6x opened this issue 1 year ago • 35 comments

Installed version 2.1.8 on Macos 12.6.7 (21G651) Intel. The app opens and gets as far as displaying the notification "OpenSpeedTest-Server : Start Request Received!". Any ideas what the issue could be?

kamil6x avatar Sep 29 '23 15:09 kamil6x

Quit OpenSpeedTest-Server and open it again. Restart your Mac and try to open it again. Is port 3000 already in use? Are there any other apps that can prevent this app from obtaining an IP/port?

openspeedtest avatar Sep 29 '23 15:09 openspeedtest

@openspeedtest

Hi, I'm also running into this issue. I've tried the release from the mac app store, and from the downloadable dmg file.

netstat -anvp tcp | awk 'NR<3 || /LISTEN/'|grep 3001 returns nothing.

Changing the port doesn't make a difference. If I click stop, I get a "Process Not Found!" error.

I've tried running the binary from the command line hoping there would be some console log output explaining the issue, but it doesn't output any obvious error messages. This is only for the x64 mac. I have another arm mac where this works fine.

Rebooting doesn't fix it.

Is there a way to turn up verbosity to see what could be happening here?

zestysoft avatar Feb 21 '24 08:02 zestysoft

You must have a valid IP address with a default gateway. Is any firewall application running?

openspeedtest avatar Feb 21 '24 08:02 openspeedtest

No firewall app. Plenty of interfaces to choose from, including a tun that belongs to a vpn (cloudflare Warp) though. How does the app know which interface to use?

$ netstat -nr|grep default
default            192.168.100.1      UGScg                en13
default            link#22            UCSIg               utun0
 $ ifconfig en13
en13: flags=8863<UP,BROADCAST,SMART,RUNNING,SIMPLEX,MULTICAST> mtu 1500
        options=6464<VLAN_MTU,TSO4,TSO6,CHANNEL_IO,PARTIAL_CSUM,ZEROINVERT_CSUM>
        ether 64:4b:f0:38:56:b1
        inet6 fe80::886:eaba:2219:44e5%en13 prefixlen 64 secured scopeid 0x21
        inet6 fdad:4ee3:df83:3f4b:142d:14ac:9204:dd3d prefixlen 64 autoconf secured
        inet 192.168.100.17 netmask 0xffffff00 broadcast 192.168.100.255
        nd6 options=201<PERFORMNUD,DAD>
        media: autoselect (2500Base-T <full-duplex,flow-control>)
        status: active

Disabling the VPN didn't help:

$ netstat -nr|grep default
default            192.168.100.1      UGScg                en13
Screenshot 2024-02-21 at 1 42 02 AM

zestysoft avatar Feb 21 '24 09:02 zestysoft

FWIW, here's the output from the console when I try to run it from the cli:

 $ /Applications/OpenSpeedTest-Server.app/Contents/MacOS/OpenSpeedTest-Server
2024-02-21 01:43:18.458 OpenSpeedTest-Server[8650:3887214] WARNING: Secure coding is not enabled for restorable state! Enable secure coding by implementing NSApplicationDelegate.applicationSupportsSecureRestorableState: and returning YES.
objc[8665]: Class WebSwapCGLLayer is implemented in both /System/Library/Frameworks/WebKit.framework/Versions/A/Frameworks/WebCore.framework/Versions/A/Frameworks/libANGLE-shared.dylib (0x7ffb49841ff0) and /Applications/OpenSpeedTest-Server.app/Contents/Frameworks/Electron Framework.framework/Versions/A/Libraries/libGLESv2.dylib (0x107361250). One of the two will be used. Which one is undefined.
OpenSpeedTest-Server : Start Request Received!

zestysoft avatar Feb 21 '24 09:02 zestysoft

If I run: nc -l 3001 I can see it listening on that port:

$ netstat -anvp tcp | awk 'NR<3 || /LISTEN/'|grep 3001
tcp4       0      0  *.3001                 *.*                    LISTEN       131072  131072  12097      0 00000 00000202 00000000000ead07 00000000 00000900      2      0 000001

zestysoft avatar Feb 21 '24 09:02 zestysoft

@zestysoft Create a new Local Account and run OST.

vishnunuk avatar Feb 21 '24 11:02 vishnunuk

@zestysoft MacOS Version? For Mac Requires macOS 10.13 or later. @kamil6x

vishnunuk avatar Feb 21 '24 11:02 vishnunuk

@zestysoft MacOS Version? For Mac Requires macOS 10.13 or later. @kamil6x

Sonoma 14.3.1

zestysoft avatar Feb 21 '24 19:02 zestysoft

I disconnected my MBP from all external equipment, and rebooted the machine in Safe Mode (held the Shift key, saw in red "SAFE BOOT" when I logged in). Same result.

I created a new admin account and logged into that while also in safe mode. Same result.

This is just a simple app that serves some html and javascript right? Is there really no way to crank up logging?

zestysoft avatar Feb 21 '24 20:02 zestysoft

One more follow up -- I asked someone else to run this on their intel mbp (same version of the OS) and they reproduced the issue too.

zestysoft avatar Feb 21 '24 21:02 zestysoft

@zestysoft I am not able to reproduce this issue on my Intel MacBook Pro running 14.3.1 (23D60). If you have any clues about potential conflicting software, please let me know. It's also running fine on my M1 Mac Mini. Screenshot 2024-02-22 at 7 13 26 AM Perhaps a list of other software you are running would be helpful? However, creating a new account should rule out that issue, correct?

openspeedtest avatar Feb 22 '24 01:02 openspeedtest

from terminal

/Applications/OpenSpeedTest-Server.app/Contents/MacOS/OpenSpeedTest-Server ; exit;
2024-02-22 07:24:35.991 OpenSpeedTest-Server[2105:25064] WARNING: Secure coding is not enabled for restorable state! Enable secure coding by implementing NSApplicationDelegate.applicationSupportsSecureRestorableState: and returning YES.
objc[2114]: Class WebSwapCGLLayer is implemented in both /System/Library/Frameworks/WebKit.framework/Versions/A/Frameworks/WebCore.framework/Versions/A/Frameworks/libANGLE-shared.dylib (0x7ffb45934ff0) and /Applications/OpenSpeedTest-Server.app/Contents/Frameworks/Electron Framework.framework/Versions/A/Libraries/libGLESv2.dylib (0x113dec250). One of the two will be used. Which one is undefined.
OpenSpeedTest-Server : Checking port 3000 status.
OpenSpeedTest-Server :  Port 3000 not available.
OpenSpeedTest-Server : Trying new port. Checking... 3001
OpenSpeedTest-Server : Checking port 3001 status.
OpenSpeedTest-Server : Port 3001 is available. 
OpenSpeedTest-Server : Starting...
OpenSpeedTest-Server : Started.
OpenSpeedTest-Server : Now go to 👉 : http://192.168.1.201:3001  	📋

openspeedtest avatar Feb 22 '24 01:02 openspeedtest

New VM via Parallels using Intel MBP. Screenshot 2024-02-22 at 8 37 45 AM

openspeedtest avatar Feb 22 '24 03:02 openspeedtest

Perhaps a list of other software you are running would be helpful? However, creating a new account should rule out that issue, correct?

I mentioned previously that I booted into safe mode AND created a new account. I thought that should mean we could rule out other software, but ???

I'd like to debug this software if that's possible and get to the bottom of this, is it in another repo? It looks like it's electron based?

zestysoft avatar Feb 22 '24 04:02 zestysoft

Running the same version of MacOS from the Intel MBP through VMWare Fusion: Screenshot 2024-02-21 at 10 27 23 PM

zestysoft avatar Feb 22 '24 06:02 zestysoft

I noticed that the MBP you're using is dated 2014 which I'm pretty sure isn't an Apple approved machine for running 14.3.1?

zestysoft avatar Feb 22 '24 06:02 zestysoft

@zestysoft Yes, it's a Mid 2014 RMBP. Latest MacOS running using OCLP. Maybe Some security features disabled by OCLP?. But how parallels worked and VMWARE replicated the same issue. I am going to try x86 MacOS using Proxmox.

openspeedtest avatar Feb 22 '24 06:02 openspeedtest

@zestysoft

Not even starting the Express server, just stuck at the first step. Not even checking the port or finding the IP address.

Can you create a mobile hotspot Wi-Fi and connect your Mac to it? I am feeling hopeless, but it's just my wish. Also, please look at the console for crash reports or other errors from 'openspeedtest'

If you understand Electron and are interested in debugging, I can send you the code. Also you can view the full code by uncompressing app.asar in resources folder. If I am able to replicate this issue, I will try to fix this ASAP.
Screenshot 2024-02-22 at 12 41 52 PM

openspeedtest avatar Feb 22 '24 07:02 openspeedtest

From Proxmox VM. Screenshot 2024-02-22 at 2 56 21 PM I am running out of ideas. Maybe upload the faulty VMware VM to Google Drive and share the link with [email protected]?

openspeedtest avatar Feb 22 '24 09:02 openspeedtest

I think 'log' might have found something:

2024-02-22 14:07:21.849275-0800 0x5842 Error 0x234f8 165 0 tccd: [com.apple.TCC:access] TCCDProcess: identifier=com.openspeedtest.server, pid=2418, auid=501, euid=501, binary_path=/Applications/OpenSpeedTest-Server.app/Contents/MacOS/OpenSpeedTest-Server attempted to call TCCAccessRequest for kTCCServiceAccessibility without the recommended com.apple.private.tcc.manager.check-by-audit-token entitlement

zestysoft avatar Feb 22 '24 22:02 zestysoft

There were some other errors, but when I ran it on the arm mac, that error was unique to the x86 system. The other errors existed on both so, I assume, can be ignored.

zestysoft avatar Feb 22 '24 22:02 zestysoft

@zestysoft OpenSpeedTest-Server doesn't require any permissions. Anyway, try https://learn.jamf.com/bundle/technical-articles/page/Resetting_Transparency_Consent_and_Control_Prompts_on_macOS.html. Have you enabled any Accessibility features system-wide?

openspeedtest avatar Feb 22 '24 23:02 openspeedtest

No nothing like that. I tried two things -- granting the app Full Disk access which usually gives it the keys to the kingdom, and also resetting everything via that tccutil command.

I even tried completely disabling TCC but even with SIP disabled I don't think that's possible.

If you run your binary in your vm and grep log, does that return any errors? It's possible that's just a red herring.

Something like sudo log stream|grep -i "openspeedtest"|grep -v "runningboardd"

zestysoft avatar Feb 22 '24 23:02 zestysoft

@zestysoft yea https://pastebin.com/arNvqkEi
This is another option https://github.com/openspeedtest/Speed-Test/issues/112#issuecomment-1913429299

I think SIP is in an unknown state on my machine due to OCLP, it might also be disabled in Proxmox. However, I am certain that I would receive more than 10 emails per day if this were a widespread issue. I have no idea how to replicate this issue. The fact that a VMware VM replicated this issue is confusing. Perhaps VMware adapted some user preferences automatically? If this is a common issue after a MacOS software update, I am going to receive a lot of emails very soon. Therefore, I am very interested in finding the cause and possible fix for this issue.

openspeedtest avatar Feb 23 '24 00:02 openspeedtest

nginx works.

I do receive this prompt first: Screenshot 2024-02-22 at 4 42 02 PM

I don't get that with the electron app even after the tcc reset?

I thought maybe nginx had some extra entitlement, but for OST:

codesign -d --entitlements - /Applications/OpenSpeedTest-Server.app
Executable=/Applications/OpenSpeedTest-Server.app/Contents/MacOS/OpenSpeedTest-Server
[Dict]
	[Key] com.apple.security.cs.allow-dyld-environment-variables
	[Value]
		[Bool] true
	[Key] com.apple.security.cs.allow-jit
	[Value]
		[Bool] true
	[Key] com.apple.security.cs.allow-unsigned-executable-memory
	[Value]
		[Bool] true

for nginx:

codesign -d --entitlements - /usr/local/Cellar/nginx/1.25.4/bin/nginx
Executable=/usr/local/Cellar/nginx/1.25.4/bin/nginx

I agree there has got to be something specific about my physical system, my vm, the person who opened this issue, and my friend's Intel system than the greater public but man, this is a head scratcher!

The VM I've been using was spun up previously and isn't prestine -- it's something I use for testing and has been upgraded a few macos versions. I wonder if something carried over from a past update.

Leme spin up a new pristine vm and see what happens there. Maybe I can do some kinda diff between the two -- some errant plist policy file?

zestysoft avatar Feb 23 '24 01:02 zestysoft

Firewall is enabled in both the VM and on the physical system, but afaik, that wouldn't prevent an app from listening to a port, just prevent traffic from hitting it. And as we've seen nginx and nc didn't have any trouble on the same port(s)? I'll explore further.

EDIT: Disabling the firewall didn't help.

One interesting thing though -- now that nginx is running as a service on port 3000:

/Applications/OpenSpeedTest-Server.app/Contents/MacOS/OpenSpeedTest-Server 
2024-02-22 17:32:52.788 OpenSpeedTest-Server[1194:9059] WARNING: Secure coding is not enabled for restorable state! Enable secure coding by implementing NSApplicationDelegate.applicationSupportsSecureRestorableState: and returning YES.
objc[1202]: Class WebSwapCGLLayer is implemented in both /System/Library/Frameworks/WebKit.framework/Versions/A/Frameworks/WebCore.framework/Versions/A/Frameworks/libANGLE-shared.dylib (0x7ffb43eaaff0) and /Applications/OpenSpeedTest-Server.app/Contents/Frameworks/Electron Framework.framework/Versions/A/Libraries/libGLESv2.dylib (0x1150c2250). One of the two will be used. Which one is undefined.
OpenSpeedTest-Server : Checking port 3000 status.
OpenSpeedTest-Server :  Port 3000 not available.
OpenSpeedTest-Server : Trying new port. Checking... 3001

So it seems to at least properly know about port status.

zestysoft avatar Feb 23 '24 01:02 zestysoft

@zestysoft If the application can find the port status, then it's likely due to the NIC/default gateway. External firewall or router with some security features enabled may have rejected the request from the OpenSpeedTest Server. That's why I suggested to test using a mobile hotspot.

openspeedtest avatar Feb 23 '24 01:02 openspeedtest

@zestysoft If the application can find the port status, then it's likely due to the NIC/default gateway. External firewall or router with some security features enabled may have rejected the request from the OpenSpeedTest Server. That's why I suggested to test using a mobile hotspot.

Got it. I have a arm mac sitting right next to this intel connected to the same ethernet switch getting all the same network settings from the same gateway device. Let me switch to wifi and see if that makes any difference. Maybe something about the caldigit eth device.

Edit: switching to wifi didn't help.

zestysoft avatar Feb 23 '24 01:02 zestysoft

Okay, I've made some progress. I had to go through a udemy course to understand how electron works :)

I've been debugging the code, and the problem happens in the then clause after this:

tcpPortUsed.check(Port, ipAddressV4)

In that function, this executes: client.connect({port: opts.port, host: opts.host}, function() {});

this returns an object that shows "pending" for the connection because the port it's trying to connect to doesn't have a listener on it -- it's gonna try until it eventually times out.

this, in turn, executes and sits there until the connection times out .then(function (inUse) {

which drops me into the empty error handling block. I added code to output the error:

             }, function (err) {
                logMessage(ServerName + err)         
             });

which shows the connection times out: Screenshot 2024-02-23 at 1 26 30 AM

zestysoft avatar Feb 23 '24 09:02 zestysoft