Authentication URL failed to load. The operation couldn’t be completed. (NSURLErrorDomain error -999.)

Got a problem with Viscosity or need help? Ask here!

aleedom

Posts: 4
Joined: Fri Jan 27, 2023 7:02 am

Post by aleedom » Fri Jan 27, 2023 7:38 am
Hello, I am in the process of POCing a migration of our vpn system from using our current unstable radius based auth mechanism, to one using SAML (azure ad). The server is set up and working as expected, but when connecting to it with Viscosity I get intermittent failures when first starting a connection. I have tried restarting the Viscosity process, as well as fully rebooting my system without any noticeable change. FWIW, when testing with another vpn client (openvpn connect) I see no connection failures, and things work as expected.

The attached log is from the latest stable version of Viscosity, I also tried using the latest beta release with the same results.
Attachments
vpn-connection-failure.txt
Full log of connectin failure with sensitve bits redacted
(11.45 KiB) Downloaded 751 times

James

User avatar
Posts: 2341
Joined: Thu Sep 04, 2008 9:27 pm

Post by James » Sat Jan 28, 2023 2:19 am
Hi aleedom,

Thanks for the detailed information. It looks suspiciously like the OpenVPN server is issuing a web authentication request, but not actually needing a response to continue. We've made some small tweaks to the latest beta version in response to this - can you please give it a try and see if you run into the same problem?
https://www.sparklabs.com/support/kb/ar ... -versions/

Cheers,
James
Web: https://www.sparklabs.com
Support: https://www.sparklabs.com/support
Twitter: https://twitter.com/sparklabs

aleedom

Posts: 4
Joined: Fri Jan 27, 2023 7:02 am

Post by aleedom » Tue Jan 31, 2023 3:53 am
Thanks for the quick response, I updated to the latest beta version on Friday, and largly it does seem to be more stable. However I am occasionally getting a different error. Its hard to nail down the exact steps to reproduce, but like the first, it happens when I first trying to start a new session, after entering valid credentials. Re-attempting to start a connection succeeds, with credentials which were cached with the first attempt. Log snippet is below, let me know if you would like more details and I can provide a full log.
Code: Select all
2023-01-27 14:17:30: [OpenVPN Server] Peer Connection Initiated with [AF_INET]<vpn ip address>:1194
2023-01-27 14:17:30: SENT CONTROL [OpenVPN Server]: 'PUSH_REQUEST' (status=1)
2023-01-27 14:17:30: AUTH_PENDING received, extending handshake timeout from 60s to 180s
2023-01-27 14:17:30: Info command was pushed by server ('OPEN_URL:<a valid saml url>')
2023-01-27 14:17:30: URL authentication request received from server. Attempting to load URL...
2023-01-27 14:17:31: SENT CONTROL [OpenVPN Server]: 'PUSH_REQUEST' (status=1)
2023-01-27 14:17:31: Authentication URL successfully loaded.
2023-01-27 14:17:31: Error: Authentication URL failed to load. Server returned HTTP code 403.
2023-01-27 14:17:31: State changed to Disconnecting (Open URL Failed)
2023-01-27 14:17:31: event_wait : Interrupted system call (code=4)
2023-01-27 14:17:31: State changed to Disconnected (Process Terminated)

kevingunn

Posts: 5
Joined: Fri Oct 15, 2021 5:24 am

Post by kevingunn » Tue Jan 31, 2023 8:54 am
I am experiencing many of the same issues, though it's not consistent with all users. We just enabled SAML Auth on our OpenVPN-AS server (running 2.11.2). For some users, they can connect and remain connected without any issues. For other users, they have a harder time getting connected to the VPN or remaining connected.

One user had previously connected to the VPN this morning, but this afternoon he couldn't get connected again. I had him install the beta version. He was able to successfully connect after the third attempt. Snippet of the logs:
Code: Select all
2023-01-30 14:29:54: Viscosity Mac 1.10.5b9 (1619)
2023-01-30 14:29:54: Viscosity OpenVPN Engine Started
2023-01-30 14:29:54: Running on macOS 13.1
2023-01-30 14:29:54: ---------
2023-01-30 14:29:54: State changed to Connecting
2023-01-30 14:29:54: Checking reachability status of connection...
2023-01-30 14:29:56: URL authentication request received from server. Attempting to load URL...
2023-01-30 14:29:57: Authentication URL successfully loaded.
2023-01-30 14:29:57: SENT CONTROL [OpenVPN Server]: 'PUSH_REQUEST' (status=1)
2023-01-30 14:30:37: Error: Authentication URL failed to load. Server returned HTTP code 403.
2023-01-30 14:30:37: State changed to Disconnecting (Open URL Failed)
2023-01-30 14:30:37: SIGTERM[hard,] received, process exiting
2023-01-30 14:30:37: State changed to Disconnected (Process Terminated)
2023-01-30 14:30:44: Viscosity Mac 1.10.5b9 (1619)
2023-01-30 14:30:44: Viscosity OpenVPN Engine Started
2023-01-30 14:30:44: Running on macOS 13.1
2023-01-30 14:30:44: ---------
2023-01-30 14:30:44: State changed to Connecting
2023-01-30 14:30:44: Checking reachability status of connection...
2023-01-30 14:30:45: URL authentication request received from server. Attempting to load URL...
2023-01-30 14:30:45: Authentication URL successfully loaded.
2023-01-30 14:30:45: Error: Authentication URL failed to load. Server returned HTTP code 403.
2023-01-30 14:30:45: State changed to Disconnecting (Open URL Failed)
2023-01-30 14:30:46: SIGTERM[hard,] received, process exiting
2023-01-30 14:30:46: State changed to Disconnected (Process Terminated)
2023-01-30 14:30:59: Viscosity Mac 1.10.5b9 (1619)
2023-01-30 14:30:59: Viscosity OpenVPN Engine Started
2023-01-30 14:30:59: Running on macOS 13.1
2023-01-30 14:30:59: ---------
2023-01-30 14:30:59: State changed to Connecting
2023-01-30 14:30:59: Checking reachability status of connection...
2023-01-30 14:30:59: Connection is reachable. Starting connection attempt.
2023-01-30 14:30:59: URL authentication request received from server. Attempting to load URL...
2023-01-30 14:31:00: Authentication URL successfully loaded.
2023-01-30 14:31:00: SENT CONTROL [OpenVPN Server]: 'PUSH_REQUEST' (status=1)
2023-01-30 14:31:01: Error: Authentication URL failed to load. The operation couldn’t be completed. (NSURLErrorDomain error -999.)
2023-01-30 14:31:01: Initialization Sequence Completed
2023-01-30 14:31:01: DNS mode set to Full
2023-01-30 14:31:01: State changed to Connected

Happy to provide additional logs if needed. Any help will be appreciated as it's impacting a number of users being able to reliably connect to our VPN service.

James

User avatar
Posts: 2341
Joined: Thu Sep 04, 2008 9:27 pm

Post by James » Wed Feb 01, 2023 5:16 am
Hi Folks,

The important error message here is:
Code: Select all
Error: Authentication URL failed to load. Server returned HTTP code 403.
This indicates that the web server is explicitly rejecting the page load:
https://en.wikipedia.org/wiki/HTTP_403

I'm afraid there isn't much Viscosity can do about this. You'll need to check the web server logs to see why it's rejecting the page load. The server may be configured to reject Viscosity's user agent string, it may be configured to reject or is mishandling WebKit requests, it may limit the number of connections per IP or be hitting a rate or user limit, etc.

Cheers,
James
Web: https://www.sparklabs.com
Support: https://www.sparklabs.com/support
Twitter: https://twitter.com/sparklabs

aleedom

Posts: 4
Joined: Fri Jan 27, 2023 7:02 am

Post by aleedom » Wed Feb 01, 2023 5:56 am
A quick followup, while yes, you are absolutly correct about the 403. My problem is that I don't get any of these problems when using a different vpn client. I would really really really like to not have to migrate all of my users away from using Viscosity before/after migrating my vpn server to use saml.

kevingunn

Posts: 5
Joined: Fri Oct 15, 2021 5:24 am

Post by kevingunn » Thu Feb 02, 2023 2:11 am
I have a few users not using Viscosity and have also not reported any issues.

I wonder if there's some sort of encoding issue going on between the server and Viscosity. I was able to find the auth URL for failed requests (403 responses) and found the following:
Code: Select all
2023-02-01 09:38:01: Viscosity Mac 1.10.4 (1611)
2023-02-01 09:38:01: Viscosity OpenVPN Engine Started
2023-02-01 09:38:01: Running on macOS 12.6.0
2023-02-01 09:38:01: ---------
2023-02-01 09:38:01: State changed to Connecting
2023-02-01 09:38:01: Checking reachability status of connection...
2023-02-01 09:38:01: Connection is reachable. Starting connection attempt.
2023-02-01 09:38:02: VERIFY KU OK
2023-02-01 09:38:02: VERIFY EKU OK
2023-02-01 09:38:02: VERIFY OK: depth=0, CN=OpenVPN Server
2023-02-01 09:38:02: [OpenVPN Server] Peer Connection Initiated with [AF_INET]<vpn-ip>:1194
2023-02-01 09:38:02: SENT CONTROL [OpenVPN Server]: 'PUSH_REQUEST' (status=1)
2023-02-01 09:38:02: AUTH_PENDING received, extending handshake timeout from 60s to 180s
2023-02-01 09:38:02: Info command was pushed by server ('OPEN_URL:https://<vpn-domain>/saml/redirect/?RelayState=vpnauth~hostname~PG_IUn%2B6GLpfXb3XffJ')
2023-02-01 09:38:02: URL authentication request received from server. Attempting to load URL...
2023-02-01 09:38:03: Authentication URL successfully loaded.
2023-02-01 09:38:03: SENT CONTROL [OpenVPN Server]: 'PUSH_REQUEST' (status=1)
2023-02-01 09:38:03: Error: Authentication URL failed to load. Server returned HTTP code 403.
2023-02-01 09:38:03: State changed to Disconnecting (Open URL Failed)
2023-02-01 09:38:03: SIGTERM[hard,] received, process exiting
2023-02-01 09:38:03: State changed to Disconnected (Process Terminated)
2023-02-01 09:38:26: Viscosity Mac 1.10.4 (1611)
2023-02-01 09:38:26: Viscosity OpenVPN Engine Started
2023-02-01 09:38:26: Running on macOS 12.6.0
2023-02-01 09:38:26: ---------
2023-02-01 09:38:26: State changed to Connecting
2023-02-01 09:38:26: Checking reachability status of connection...
2023-02-01 09:38:26: Connection is reachable. Starting connection attempt.
2023-02-01 09:38:26: VERIFY KU OK
2023-02-01 09:38:26: VERIFY EKU OK
2023-02-01 09:38:26: VERIFY OK: depth=0, CN=OpenVPN Server
2023-02-01 09:38:26: [OpenVPN Server] Peer Connection Initiated with [AF_INET]<vpn-ip>:1194
2023-02-01 09:38:26: SENT CONTROL [OpenVPN Server]: 'PUSH_REQUEST' (status=1)
2023-02-01 09:38:27: AUTH_PENDING received, extending handshake timeout from 60s to 180s
2023-02-01 09:38:27: Info command was pushed by server ('OPEN_URL:https://<vpn-domain>/saml/redirect/?RelayState=vpnauth~hostname~PG_9bhZOghwGpfuf5TP')
2023-02-01 09:38:27: URL authentication request received from server. Attempting to load URL...
2023-02-01 09:38:27: Authentication URL successfully loaded.
2023-02-01 09:38:27: SENT CONTROL [OpenVPN Server]: 'PUSH_REQUEST' (status=1)
2023-02-01 09:38:28: SENT CONTROL [OpenVPN Server]: 'PUSH_REQUEST' (status=1)
2023-02-01 09:38:29: Initialization Sequence Completed
2023-02-01 09:38:30: State changed to Connected
Note the `%2B` in the first request that failed, while the second request didn't have any special characters in the relay token. It seems the relay token is being encoded and then causing the 403 error. Is it possible that Viscosity is encoding that part of the string and the server then is returning a 403 since it's not expecting the encoding? This seems consistent with errors in other logs. Anytime there's a '+', it's been encoded to '%2B', and then a 403 is returned. Successful authentication attempts do not have this character in the string.

kevingunn

Posts: 5
Joined: Fri Oct 15, 2021 5:24 am

Post by kevingunn » Thu Feb 02, 2023 6:01 am
Here's the logs from OpenVPN Connect that encounters the same '%2B' encoding in the auth string, but handles it and connects successfully:
Code: Select all
⏎[Feb 1, 2023, 12:08:42] EVENT: RESOLVE
⏎[Feb 1, 2023, 12:08:42] Contacting <vpn-ip>:1194 via UDP
⏎[Feb 1, 2023, 12:08:42] Connecting to [<vpn-domain>]:1194 (<vpn-ip>) via UDPv4
⏎[Feb 1, 2023, 12:08:42] EVENT: CONNECTING 
⏎[Feb 1, 2023, 12:08:42] Session is ACTIVE
⏎[Feb 1, 2023, 12:08:42] EVENT: GET_CONFIG ⏎[Feb 1, 2023, 12:08:42] Sending PUSH_REQUEST to server...
⏎[Feb 1, 2023, 12:08:42] Extending connection timeout from 59 to 180 for pending authentification
⏎[Feb 1, 2023, 12:08:42] EVENT: INFO WEB_AUTH::https://<vpn-domain>/saml/redirect/?RelayState=vpnauth~hostname~PG_%2Bn3efiLoGxwiSZTL
⏎[Feb 1, 2023, 12:08:42] EVENT: AUTH_PENDING timeout 180
⏎[Feb 1, 2023, 12:08:43] Sending PUSH_REQUEST to server...
⏎[Feb 1, 2023, 12:08:44] TunPersist: short-term connection scope
⏎[Feb 1, 2023, 12:08:44] TunPersist: new tun context
⏎[Feb 1, 2023, 12:08:44] EVENT: ASSIGN_IP
⏎[Feb 1, 2023, 12:08:44] Session token: [redacted]
⏎[Feb 1, 2023, 12:08:44] Connected via utun3
⏎[Feb 1, 2023, 12:08:44] EVENT: CONNECTED username@<vpn-domain>:1194 (<vpn-ip>) via /UDPv4

James

User avatar
Posts: 2341
Joined: Thu Sep 04, 2008 9:27 pm

Post by James » Thu Feb 02, 2023 3:42 pm
Thanks for the follow up. We've managed to replicate this, and we've pushed out an updated beta version to address it. It also addresses some changes OpenVPN-AS have made to their Import from Server process that would result in a configuration failing to import when SAML was active.
https://www.sparklabs.com/support/kb/ar ... -versions/

Cheers,
James
Web: https://www.sparklabs.com
Support: https://www.sparklabs.com/support
Twitter: https://twitter.com/sparklabs

kevingunn

Posts: 5
Joined: Fri Oct 15, 2021 5:24 am

Post by kevingunn » Fri Feb 03, 2023 6:58 am
Thank you for following up on the issue. We have a number of users on the latest beta version and it seems to have fixed the issues we were running into. Also, I was able to successfully import a connection profile from OpenVPN AS using the 'Import from Server' option (whereas this was not working previously).

We'll continue to test and monitor, but it seems to have fixed it.

Thanks.
13 posts Page 1 of 2