GlobalProtect-openconnect icon indicating copy to clipboard operation
GlobalProtect-openconnect copied to clipboard

Published 20 hours ago • verified publisher icon yuezk

1.4.3 Hangs on "Connecting..."

Open outpaddling opened this issue 3 years ago • 24 comments

Running on FreeBSD 13.0-RELEASE. 1.4.1 and 1.4.2 work flawlessly. 1.4.3 appears to log in successfully but then hangs with "Connecting..." on the main window.

Tail of terminal output starting with successful login:

1.4.2:

2022-05-10 07:52:51.058 INFO  [192908] [gpclient::helper::parseGatewayResponse@53] The gateway response is: <?xml version="1.0" encoding="utf-8"?><jnlp><application-desc><argument>(null)</argument><argument>c06b537e007a51b0a0b2f61ddb4789f8</argument><argument>08560b25e4528feebb1585eb24f0a0bd48229c0a</argument><argument>gp-test-gw-N</argument><argument>[email protected]</argument><argument>SAML-MFA</argument><argument>vsys1</argument><argument>%28empty_domain%29</argument><argument>(null)</argument><argument></argument><argument></argument><argument></argument><argument>tunnel</argument><argument>-1</argument><argument>4100</argument><argument></argument><argument>e6wp0k/Zq+RiEMJPQuljRW8HKdzBRYwuOnaFzDuSiOb+VsYsWjCxSCFpUHTylI7Og5wFO6zYxlJFwSioU5ifmrebG1KvFpWaD1f0Xg1725VNhRAPuQdBAitwmzyiXV4qzq5g/4u0nOXt7FK8CSsznm+SThnIlxQAGbY01nYJOEREx83vCOa+VfxeBjIUUfwr/cQrfth7jK6SpmO0lJjReXfWk7AP7f0IJXymdOarMAKup6KOR8rnHB8HUcNvdD4K0Wv1jliLyxRkOeG1eFJfMsZLU2akjeVaa/nUvKwUs6m31AomJMZQ2Vy7DcycF2M5XHayzwIVuBW/JIc//tXvhQ==</argument><argument>bm+b+P6Ic2z/fctV5Rwt5PeZsX/rQvu8j25aicAogsM42FqKrdOzgkx8P0UraIG1Wjab41h7OLrmZrUsoeH5W/mrGCKugtY4dKfC6kXdzT2tcolecarDQL1mC9j2JHPdeShhuJ4wuDE5IRUSdwPlbSKk/n8rUsmOE0ynC9pIfCMm95jYvgcAW1fCDhjeG+Ot1hqAtGbKorjyZYfqGgpjs32E91CY70xtGtQcQy2VIQXhcmSepoEDPLol3uisDuMIVYawB481iLcOZefwJM2SWYNIFuy8jQ9AVi0coOzcyTNxbWVqplqeC8TPVZruvLF1zqSPeHpsyju3RbQUNvMLSA==</argument><argument></argument><argument>4</argument><argument>unknown</argument><argument></argument></application-desc></jnlp>
2022-05-10 07:52:51.058 INFO  [192908] [GPClient::onGatewaySuccess@374] Gateway login succeeded, got the cookie authcookie=c06b537e007a51b0a0b2f61ddb4789f8&portal=gp-test-gw-N&user=joe%40joe.com&domain=%2528empty_domain%2529&preferred-ip=&computer=coral.acadix.biz
2022-05-10 07:52:51.064 INFO  [192908] [GPClient::onVPNLogAvailable@499] Output of `openconnect --version`: OpenConnect version v8.20
Using OpenSSL 1.1.1k-freebsd  24 Aug . Features present: TPM (OpenSSL ENGINE not present), HOTP software token, TOTP software token, DTLS, ESP
Supported protocols: anyconnect (default), nc, gp, pulse, f5, fortinet, array
Default vpnc-script (override with --script): /usr/local/sbin/vpnc-script

2022-05-10 07:52:51.064 INFO  [192908] [GPClient::onVPNLogAvailable@499] Start process with arugments: --protocol=gp -u  --cookie-on-stdin gp-gateway.joe.com
2022-05-10 07:52:51.065 INFO  [192908] [GPClient::onVPNLogAvailable@499] Openconnect started successfully, PID=65138
2022-05-10 07:52:51.068 INFO  [192908] [GPClient::onVPNLogAvailable@499] POST https://gp-gateway.joe.com/ssl-vpn/getconfig.esp

2022-05-10 07:52:51.109 INFO  [192908] [GPClient::onVPNLogAvailable@499] Attempting to connect to server 129.89.251.2:443

2022-05-10 07:52:51.125 INFO  [192908] [GPClient::onVPNLogAvailable@499] Connected to 129.89.251.2:443

2022-05-10 07:52:51.134 INFO  [192908] [GPClient::onVPNLogAvailable@499] SSL negotiation with gp-gateway.joe.com

2022-05-10 07:52:51.156 INFO  [192908] [GPClient::onVPNLogAvailable@499] Matched peer certificate subject name 'gp-gateway.joe.com'

2022-05-10 07:52:51.171 INFO  [192908] [GPClient::onVPNLogAvailable@499] Connected to HTTPS on gp-gateway.joe.com with ciphersuite TLSv1.2-ECDHE-RSA-AES256-GCM-SHA384

2022-05-10 07:52:51.214 INFO  [192908] [GPClient::onVPNLogAvailable@499] Got HTTP response: HTTP/1.1 200 OK
Date: Tue, 10 May 2022 12:52:51 GMT
Content-Type: application/xml; charset=UTF-8
Content-Length: 1324
Connection: keep-alive
Pragma: no-cache

2022-05-10 07:52:51.214 INFO  [192908] [GPClient::onVPNLogAvailable@499] Cache-Control: no-store, no-cache, must-revalidate, post-check=0, pre-check=0
Expires: Thu, 19 Nov 1981 08:52:00 GMT
X-FRAME-OPTIONS: DENY
Set-Cookie: PHPSESSID=e1ef502568df8c7284edeb691c8882d5; secure; HttpOnly
Strict-Transport-Security: max-age=31536000;
X-XSS-Protection: 1; mode=block
X-Content-Type-Options: nosniff

2022-05-10 07:52:51.214 INFO  [192908] [GPClient::onVPNLogAvailable@499] Content-Security-Policy: default-src 'self'; script-src 'self' 'unsafe-inline'; img-src * data:; style-src 'self' 'unsafe-inline';
HTTP body length:  (1324)

2022-05-10 07:52:51.214 INFO  [192908] [GPClient::onVPNLogAvailable@499] Tunnel timeout (rekey interval) is 180 minutes.

2022-05-10 07:52:51.214 INFO  [192908] [GPClient::onVPNLogAvailable@499] Idle timeout is 180 minutes.

2022-05-10 07:52:51.214 INFO  [192908] [GPClient::onVPNLogAvailable@499] Did not receive ESP keys and matching gateway in GlobalProtect config; tunnel will be TLS only.

2022-05-10 07:52:51.214 INFO  [192908] [GPClient::onVPNLogAvailable@499] Using base_mtu of 1406

2022-05-10 07:52:51.215 INFO  [192908] [GPClient::onVPNLogAvailable@499] After removing TCP/IPv4 headers, MTU of 1366
After removing protocol specific overhead (5 unpadded, 0 padded, 1 blocksize), MTU of 1361

2022-05-10 07:52:51.215 INFO  [192908] [GPClient::onVPNLogAvailable@499] No MTU received. Calculated 1361 for SSL tunnel. No ESP keys received

2022-05-10 07:52:51.215 INFO  [192908] [GPClient::onVPNLogAvailable@499] POST https://gp-gateway.joe.com/ssl-vpn/hipreportcheck.esp

2022-05-10 07:52:51.252 INFO  [192908] [GPClient::onVPNLogAvailable@499] Got HTTP response: HTTP/1.1 200 OK
Date: Tue, 10 May 2022 12:52:51 GMT
Content-Type: application/xml; charset=UTF-8
Content-Length: 137

2022-05-10 07:52:51.253 INFO  [192908] [GPClient::onVPNLogAvailable@499] Connection: keep-alive
X-Content-Type-Options: nosniff
Pragma: no-cache
Cache-Control: no-store, no-cache, must-revalidate, post-check=0, pre-check=0
Content-Security-Policy: default-src 'self'
Expires: Thu, 19 Nov 1981 08:52:00 GMT
X-FRAME-OPTIONS: DENY
Strict-Transport-Security: max-age=31536000;
X-XSS-Protection: 1; mode=block

2022-05-10 07:52:51.253 INFO  [192908] [GPClient::onVPNLogAvailable@499] X-Content-Type-Options: nosniff
Content-Security-Policy: default-src 'self'; script-src 'self' 'unsafe-inline'; img-src * data:; style-src 'self' 'unsafe-inline';

2022-05-10 07:52:51.253 INFO  [192908] [GPClient::onVPNLogAvailable@499] HTTP body length:  (137)

2022-05-10 07:52:51.253 INFO  [192908] [GPClient::onVPNLogAvailable@499] Gateway says HIP report submission is needed.
Connecting to HTTPS tunnel endpoint ...

2022-05-10 07:52:51.253 INFO  [192908] [GPClient::onVPNLogAvailable@499] WARNING: Server asked us to submit HIP report with md5sum 8838a0215e325a9ea7107f8e00c00dd4.
    VPN connectivity may be disabled or limited without HIP report submission.
    You need to provide a --csd-wrapper argument with the HIP report submission script.

2022-05-10 07:52:51.270 INFO  [192908] [GPClient::onVPNLogAvailable@499] Set up UDP failed; using SSL instead

2022-05-10 07:52:51.270 INFO  [192908] [GPClient::onVPNLogAvailable@499] Configured as 10.254.18.38, with SSL connected and ESP disabled

2022-05-10 07:52:51.272 INFO  [192908] [GPClient::onVPNLogAvailable@499] Session authentication will expire at Tue May 17 07:52:51 2022


2022-05-10 07:52:51.290 INFO  [192908] [GPClient::onVPNLogAvailable@499] add host 129.89.251.2: gateway 192.168.0.1

2022-05-10 07:52:51.292 INFO  [192908] [GPClient::onVPNLogAvailable@499] add net 10.254.18.38: gateway 10.254.18.38 fib 0: route already in table

2022-05-10 07:52:51.293 INFO  [192908] [GPClient::onVPNLogAvailable@499] add net 129.89.10.2: gateway 10.254.18.38

2022-05-10 07:52:51.294 INFO  [192908] [GPClient::onVPNLogAvailable@499] add net 129.89.10.1: gateway 10.254.18.38

2022-05-10 07:52:51.295 INFO  [192908] [GPClient::onVPNLogAvailable@499] add net 128.104.0.0: gateway 10.254.18.38

2022-05-10 07:52:51.297 INFO  [192908] [GPClient::onVPNLogAvailable@499] add net 144.92.0.0: gateway 10.254.18.38

2022-05-10 07:52:51.298 INFO  [192908] [GPClient::onVPNLogAvailable@499] add net 172.16.0.0: gateway 10.254.18.38

2022-05-10 07:52:51.299 INFO  [192908] [GPClient::onVPNLogAvailable@499] add net 129.89.0.0: gateway 10.254.18.38

2022-05-10 07:52:51.300 INFO  [192908] [GPClient::onVPNLogAvailable@499] add net 10.0.0.0: gateway 10.254.18.38

2022-05-10 07:52:51.302 INFO  [192908] [GPClient::onVPNLogAvailable@499] add net 143.235.8.50: gateway 10.254.18.38

2022-05-10 07:52:51.304 INFO  [192908] [GPClient::onVPNLogAvailable@499] add net 129.89.10.1: gateway 10.254.18.38 fib 0: route already in table

2022-05-10 07:52:51.306 INFO  [192908] [GPClient::onVPNLogAvailable@499] add net 129.89.10.2: gateway 10.254.18.38 fib 0: route already in table

2022-05-10 07:52:54.509 INFO  [192908] [GPClient::doConnect@246] Start connecting...
2022-05-10 07:52:54.509 INFO  [192908] [GPClient::doConnect@271] Start disconnecting the VPN...
2022-05-10 07:52:54.513 INFO  [192908] [GPClient::onVPNLogAvailable@499] POST https://gp-gateway.joe.com/ssl-vpn/logout.esp

2022-05-10 07:52:54.525 INFO  [192908] [GPClient::onVPNLogAvailable@499] SSL negotiation with gp-gateway.joe.com

2022-05-10 07:52:54.563 INFO  [192908] [GPClient::onVPNLogAvailable@499] Connected to HTTPS on gp-gateway.joe.com with ciphersuite TLSv1.2-ECDHE-RSA-AES256-GCM-SHA384

2022-05-10 07:52:54.599 INFO  [192908] [GPClient::onVPNLogAvailable@499] Invalid user name
Logout failed.

2022-05-10 07:52:54.607 INFO  [192908] [GPClient::onVPNLogAvailable@499] delete net 129.89.10.2: gateway 10.254.18.38

2022-05-10 07:52:54.609 INFO  [192908] [GPClient::onVPNLogAvailable@499] delete net 129.89.10.1: gateway 10.254.18.38

2022-05-10 07:52:54.610 INFO  [192908] [GPClient::onVPNLogAvailable@499] delete net 128.104.0.0: gateway 10.254.18.38

2022-05-10 07:52:54.611 INFO  [192908] [GPClient::onVPNLogAvailable@499] delete net 144.92.0.0: gateway 10.254.18.38

2022-05-10 07:52:54.612 INFO  [192908] [GPClient::onVPNLogAvailable@499] delete net 172.16.0.0: gateway 10.254.18.38

2022-05-10 07:52:54.613 INFO  [192908] [GPClient::onVPNLogAvailable@499] delete net 129.89.0.0: gateway 10.254.18.38

2022-05-10 07:52:54.614 INFO  [192908] [GPClient::onVPNLogAvailable@499] delete net 10.0.0.0: gateway 10.254.18.38

2022-05-10 07:52:54.615 INFO  [192908] [GPClient::onVPNLogAvailable@499] delete net 143.235.8.50: gateway 10.254.18.38

2022-05-10 07:52:54.616 INFO  [192908] [GPClient::onVPNLogAvailable@499] route: route has not been found

2022-05-10 07:52:54.616 INFO  [192908] [GPClient::onVPNLogAvailable@499] delete net 129.89.10.1: gateway 10.254.18.38 fib 0: not in table

2022-05-10 07:52:54.617 INFO  [192908] [GPClient::onVPNLogAvailable@499] route: route has not been found

2022-05-10 07:52:54.617 INFO  [192908] [GPClient::onVPNLogAvailable@499] delete net 129.89.10.2: gateway 10.254.18.38 fib 0: not in table

2022-05-10 07:52:54.619 INFO  [192908] [GPClient::onVPNLogAvailable@499] delete host 129.89.251.2: gateway 192.168.0.1

2022-05-10 07:52:54.647 INFO  [192908] [GPClient::onVPNLogAvailable@499] User cancelled (SIGINT/SIGTERM); exiting.

2022-05-10 07:52:54.650 INFO  [192908] [GPClient::onVPNLogAvailable@499] Openconnect process exited with code 0 and exit status NormalExit
Release of profile requested but WebEnginePage still not deleted. Expect troubles !

1.4.3:

2022-05-10 07:54:01.784 INFO  [193615] [gpclient::helper::parseGatewayResponse@53] The gateway response is: <?xml version="1.0" encoding="utf-8"?><jnlp><application-desc><argument>(null)</argument><argument>483c52679ecaf299fab166e5531dbb62</argument><argument>08560b25e4528feebb1585eb24f0a0bd48229c0a</argument><argument>gp-test-gw-N</argument><argument>[email protected]</argument><argument>SAML-MFA</argument><argument>vsys1</argument><argument>%28empty_domain%29</argument><argument>(null)</argument><argument></argument><argument></argument><argument></argument><argument>tunnel</argument><argument>-1</argument><argument>4100</argument><argument></argument><argument>Mt1Uz0afFFpA6KWGNhG0pRaawOJU/2AKVTrQovyIkQui9MdmTd9LnhzYAOhk85zPXWSx+txvrjCsJRO7G69L2XnZsbPosTUg2/gHHQrVApbgj1ZkDFHufFs3id7LrSiQdOp6tQ3fCccU/wZEvpJlE37paPRGeeLLNbJQrGDNjJrSsgkvYAEZqRAk0qB9xRaMdzEnk7tZKsevni/GcUUPP+EWPRKjtC315pOZWoE+aDCk5CUQPkPSTqqqAJ9dG5KIBntwg7cxPCs0fo00m+EisCwmtUOVNz8ducQNx02jcHM2yf6hsd68fqVSSgQwpV2wGl36nMzQMFvFqcRAV1frMA==</argument><argument>TGY2FBO8Qgl7aTHPNACN8U7TT/ELKR/VqY/S6mZWLfWFebKPf39RlGLwVq0+e5ckxiCCYoCw/o5NwdrzKjaN3WBuSCNWByXj842xcHm0IHX5LnznFlEjn+XNFDk7Vh4e9Oc1i6c217fleitoiZOs/Oz+8pzEz4EnaEreF2DKUKCCZv6tQhxttzk3O3mFyFxvistiEO4RVhhyhDMeNZsBSbvKpE8zvy7+Y/XzOjCT/FjspskXW7gcUx2+BWeKiavCQFbeZRLcrocvYfFLC+UkqYwFI2OaLm6Jgi6UCxi2ZFVlHjqIRKzXbEv3pfayxMAhquRMNtBTAktvKhet+CSBgQ==</argument><argument></argument><argument>4</argument><argument>unknown</argument><argument></argument></application-desc></jnlp>
2022-05-10 07:54:01.784 INFO  [193615] [GPClient::onGatewaySuccess@372] Gateway login succeeded, got the cookie authcookie=483c52679ecaf299fab166e5531dbb62&portal=gp-test-gw-N&user=joe%40joe.com&domain=%2528empty_domain%2529&preferred-ip=&computer=coral.acadix.biz
Release of profile requested but WebEnginePage still not deleted. Expect troubles !

outpaddling avatar May 10 '22 13:05 outpaddling

@outpaddling Can you try the old version to see if it still works?

yuezk avatar May 10 '22 14:05 yuezk

Which old version? As I mentioned, 1.4.1 and 1.4.2 both work fine. Thanks...

outpaddling avatar May 10 '22 14:05 outpaddling

If 1.4.2 still works, then please use it for now. I will check what the code changes in 1.4.3 could lead this problem.

BTW, how did you install the software? Is there a package for FreeBSD.

yuezk avatar May 10 '22 15:05 yuezk

Yes, I am the FreeBSD port maintainer: https://github.com/yuezk/GlobalProtect-openconnect/issues/127 Currently the committed port is on 1.4.1 and I'll leave it alone until we figure out the 1.4.3 issue. The only obvious difference I saw was the new config file. I patched /etc/gpservice to ${PREFIX}/etc/gpservice in all files before build, but I'm not seeing how that could cause this issue. Thanks...

outpaddling avatar May 10 '22 15:05 outpaddling

What's the absolute path of the configuration file after the installation? Is it /etc/gpservice/gp.conf?

yuezk avatar May 10 '22 15:05 yuezk

The ports system has a configurable prefix, but usually /usr/local. So /usr/local/etc/gpservice/gp.conf.

Post-patch:

<<<[email protected]>>> /usr/ports/wip/globalprotect-openconnect-1.4.3 1011 # fgrep -r /etc/ work/GlobalProtect-openconnect-1.4.3/ | egrep -v .'bak|orig'
work/GlobalProtect-openconnect-1.4.3/GPClient/settingsdialog.ui:      <string>The configuration has been moved to &quot;/usr/local/etc/gpservice/gp.conf&quot;</string>
work/GlobalProtect-openconnect-1.4.3/GPService/CMakeLists.txt:install(FILES "gp.conf" DESTINATION /usr/local/etc/gpservice)
work/GlobalProtect-openconnect-1.4.3/GPService/gpservice.cpp:    INIReader reader("/usr/local/etc/gpservice/gp.conf");

outpaddling avatar May 10 '22 16:05 outpaddling

Have you tried a sudo killall gpservice after upgrading?

You'll get this behavior if you're still running the old gpservice and start the new gpclient

murph avatar May 25 '22 20:05 murph

Have you tried a sudo killall gpservice after upgrading?

You'll get this behavior if you're still running the old gpservice and start the new gpclient

Looks like you called it, thanks.

Maybe we could add a check for a compatible daemon process to flag this situation for other unsuspecting users. I could probably help with the coding if necessary.

outpaddling avatar May 25 '22 22:05 outpaddling

I recently added the hooks for debian/aur/rpm packaging to restart the service after upgrading. Is there a similar way in FreeBSD?

yuezk avatar May 26 '22 02:05 yuezk

Yes, I could add a deinstall hook for that purpose. But I think an upstream solution would be cleaner than maintaining hooks in every package manager.

I haven't looked at the code yet, but I would guess the client initiates a socket connection with gpservice? One could simply embed the software version in the initial response message and then take action if it doesn't match the client.

outpaddling avatar May 26 '22 11:05 outpaddling

Will try it.

yuezk avatar May 29 '22 13:05 yuezk

Hi @yuezk I'm having the same issue with the latest 1.4.8 version on Ubuntu 22.04 image

I've also tried with v1.4.2 building from the source and have the same problem.

The connection with the VPN is good, but the app hangs on "connecting.."

joeesteves avatar Jun 14 '22 13:06 joeesteves

What your language are you using?

yuezk avatar Jun 14 '22 14:06 yuezk

@ponyesteves The reason for your case is that the gpservice didn't capture the keyword of Connected as or Configured as. So it won't update the status. The check logic is not so reliable and needs to be improved.

https://github.com/yuezk/GlobalProtect-openconnect/blob/5788474d7e7e00665699970f6f87864892e480c4/GPService/gpservice.cpp#L202

yuezk avatar Jun 17 '22 02:06 yuezk

Thanks for your reply @yuezk. I'm using have my OS in Spanish. So that's why it don't match the words.

Happy to make a PR to add support for Spanish

In Spanish a Configured as is translated as Configurado como

joeesteves avatar Jun 17 '22 03:06 joeesteves

Configurado como will also take care of Portuguese, 2 birds in one shot :)

OTOH I don't think this solution would scale if more languages are going to be supported.

Maybe launching openconnect overriding the environment variables may be a simpler way to cover all the cases.

telegrapher avatar Jun 17 '22 20:06 telegrapher

@yuezk https://github.com/yuezk/GlobalProtect-openconnect/pull/162 here is the PR to add support to es and pt

cc/ @telegrapher

If you want to make a deeper improvement, I may help with some guidance

joeesteves avatar Jun 19 '22 23:06 joeesteves

If you want to make a deeper improvement, I may help with some guidance

@ponyesteves I would like to hear more about it.

yuezk avatar Jun 20 '22 02:06 yuezk

@yuezk I'm still improving my English. What I meant was that I was willing to help , if you give me some guidance/ideas or less to follow .

Sorry about the confusion!

joeesteves avatar Jun 20 '22 13:06 joeesteves

Hello everyone, I'm encountering this issue in Fedora 36, is this related or I need to open a new issue. Thank you!

monnoval avatar Jun 21 '22 03:06 monnoval

@monnoval Has it connected, while the UI still displays as Connecting...? If yes, it could be the same issue, the fix in #162 hasn't been released yet.

yuezk avatar Jun 21 '22 09:06 yuezk

@ponyesteves I see. Thanks for your willingness to help.

I think the current solution for checking the connection status is not reliable. It could be better if we could unify the locale of the background OpenConnect command line.

I tried to unify the locale to en_US through the environment, looks like it doesn't work for your case.

https://github.com/yuezk/GlobalProtect-openconnect/blob/15a73b7dba73a7877c3611718557a53fcf0a52ab/GPService/systemd/gpservice.service.in#L5

yuezk avatar Jun 21 '22 10:06 yuezk

I tried to unify the locale to en_US through the environment, looks like it doesn't work for your case.

I'll try this locally and see if I can find a workaround @yuezk

joeesteves avatar Jun 21 '22 12:06 joeesteves

@monnoval Has it connected, while the UI still displays as Connecting...? If yes, it could be the same issue, the fix in #162 hasn't been released yet.

Yes it did connect, thanks for reply :)

monnoval avatar Jun 23 '22 00:06 monnoval