streisand icon indicating copy to clipboard operation
streisand copied to clipboard

Published 20 hours ago • verified publisher icon StreisandEffect

Fail to connect via OpenVPN and OpenConnect on the fresh localhost install

Open morte-rictusgrin opened this issue 5 years ago • 7 comments

I've installed Streisand from the git to Amazon us-west-a2. As I couldn't make it work via remote installation (selinux issues, etc.), I've used localhost installation and it was successful. I can access gateway, but can't connect neither with OpenVPN nor with OpenConnect windows clients.

OpenVPN returns following: Mon Apr 08 15:03:06 2019 OpenVPN 2.4.7 x86_64-w64-mingw32 [SSL (OpenSSL)] [LZO] [LZ4] [PKCS11] [AEAD] built on Feb 21 2019 Mon Apr 08 15:03:06 2019 Windows version 6.2 (Windows 8 or greater) 64bit Mon Apr 08 15:03:06 2019 library versions: OpenSSL 1.1.0j 20 Nov 2018, LZO 2.10 Enter Management Password: Mon Apr 08 15:03:06 2019 MANAGEMENT: TCP Socket listening on [AF_INET]127.0.0.1:25341 Mon Apr 08 15:03:06 2019 Need hold release from management interface, waiting... Mon Apr 08 15:03:07 2019 MANAGEMENT: Client connected from [AF_INET]127.0.0.1:25341 Mon Apr 08 15:03:07 2019 MANAGEMENT: CMD 'state on' Mon Apr 08 15:03:07 2019 MANAGEMENT: CMD 'log all on' Mon Apr 08 15:03:07 2019 MANAGEMENT: CMD 'echo all on' Mon Apr 08 15:03:07 2019 MANAGEMENT: CMD 'bytecount 5' Mon Apr 08 15:03:07 2019 MANAGEMENT: CMD 'hold off' Mon Apr 08 15:03:07 2019 MANAGEMENT: CMD 'hold release' Mon Apr 08 15:03:07 2019 Outgoing Control Channel Encryption: Cipher 'AES-256-CTR' initialized with 256 bit key Mon Apr 08 15:03:07 2019 Outgoing Control Channel Encryption: Using 256 bit message hash 'SHA256' for HMAC authentication Mon Apr 08 15:03:07 2019 Incoming Control Channel Encryption: Cipher 'AES-256-CTR' initialized with 256 bit key Mon Apr 08 15:03:07 2019 Incoming Control Channel Encryption: Using 256 bit message hash 'SHA256' for HMAC authentication Mon Apr 08 15:03:07 2019 TCP/UDP: Preserving recently used remote address: [AF_INET]<streisand IP address>:636 Mon Apr 08 15:03:07 2019 Socket Buffers: R=[65536->65536] S=[65536->65536] Mon Apr 08 15:03:07 2019 Attempting to establish TCP connection with [AF_INET]<streisand IP address>:636 [nonblock] Mon Apr 08 15:03:07 2019 MANAGEMENT: >STATE:1554724987,TCP_CONNECT,,,,,, Mon Apr 08 15:03:08 2019 TCP connection established with [AF_INET]<streisand IP address>:636 Mon Apr 08 15:03:08 2019 TCP_CLIENT link local: (not bound) Mon Apr 08 15:03:08 2019 TCP_CLIENT link remote: [AF_INET]<streisand IP address>:636 Mon Apr 08 15:03:08 2019 MANAGEMENT: >STATE:1554724988,WAIT,,,,,, Mon Apr 08 15:03:08 2019 MANAGEMENT: >STATE:1554724988,AUTH,,,,,, Mon Apr 08 15:03:08 2019 TLS: Initial packet from [AF_INET]<streisand IP address>:636, sid=81fe5826 08c73382 Mon Apr 08 15:03:09 2019 VERIFY OK: depth=1, C=US, ST=California, L=Beverly Hills, O=ACME CORPORATION, OU=Anvil Department, CN=ca-certificate Mon Apr 08 15:03:09 2019 VERIFY KU OK Mon Apr 08 15:03:09 2019 Validating certificate extended key usage Mon Apr 08 15:03:09 2019 ++ Certificate has EKU (str) TLS Web Server Authentication, expects TLS Web Server Authentication Mon Apr 08 15:03:09 2019 VERIFY EKU OK Mon Apr 08 15:03:09 2019 VERIFY X509NAME OK: C=US, ST=California, L=Beverly Hills, O=ACME CORPORATION, OU=Anvil Department, CN=host-alone-weekend Mon Apr 08 15:03:09 2019 VERIFY OK: depth=0, C=US, ST=California, L=Beverly Hills, O=ACME CORPORATION, OU=Anvil Department, CN=host-alone-weekend Mon Apr 08 15:03:10 2019 Connection reset, restarting [0] Mon Apr 08 15:03:10 2019 SIGUSR1[soft,connection-reset] received, process restarting Mon Apr 08 15:03:10 2019 MANAGEMENT: >STATE:1554724990,RECONNECTING,connection-reset,,,,, Mon Apr 08 15:03:10 2019 Restart pause, 5 second(s) Mon Apr 08 15:03:15 2019 TCP/UDP: Preserving recently used remote address: [AF_INET]<streisand IP address>:636 Mon Apr 08 15:03:15 2019 Socket Buffers: R=[65536->65536] S=[65536->65536] Mon Apr 08 15:03:15 2019 Attempting to establish TCP connection with [AF_INET]<streisand IP address>:636 [nonblock] Mon Apr 08 15:03:15 2019 MANAGEMENT: >STATE:1554724995,TCP_CONNECT,,,,,, Mon Apr 08 15:03:16 2019 TCP connection established with [AF_INET]<streisand IP address>:636 Mon Apr 08 15:03:16 2019 TCP_CLIENT link local: (not bound) Mon Apr 08 15:03:16 2019 TCP_CLIENT link remote: [AF_INET]<streisand IP address>:636 Mon Apr 08 15:03:16 2019 MANAGEMENT: >STATE:1554724996,WAIT,,,,,, Mon Apr 08 15:03:16 2019 MANAGEMENT: >STATE:1554724996,AUTH,,,,,, Mon Apr 08 15:03:16 2019 TLS: Initial packet from [AF_INET]<streisand IP address>:636, sid=1534827b 426f879e Mon Apr 08 15:03:17 2019 VERIFY OK: depth=1, C=US, ST=California, L=Beverly Hills, O=ACME CORPORATION, OU=Anvil Department, CN=ca-certificate Mon Apr 08 15:03:17 2019 VERIFY KU OK Mon Apr 08 15:03:17 2019 Validating certificate extended key usage Mon Apr 08 15:03:17 2019 ++ Certificate has EKU (str) TLS Web Server Authentication, expects TLS Web Server Authentication Mon Apr 08 15:03:17 2019 VERIFY EKU OK Mon Apr 08 15:03:17 2019 VERIFY X509NAME OK: C=US, ST=California, L=Beverly Hills, O=ACME CORPORATION, OU=Anvil Department, CN=host-alone-weekend Mon Apr 08 15:03:17 2019 VERIFY OK: depth=0, C=US, ST=California, L=Beverly Hills, O=ACME CORPORATION, OU=Anvil Department, CN=host-alone-weekend Mon Apr 08 15:03:17 2019 Connection reset, restarting [0] Mon Apr 08 15:03:17 2019 SIGUSR1[soft,connection-reset] received, process restarting Mon Apr 08 15:03:17 2019 MANAGEMENT: >STATE:1554724997,RECONNECTING,connection-reset,,,,, Mon Apr 08 15:03:17 2019 Restart pause, 5 second(s) Mon Apr 08 15:03:18 2019 SIGTERM[hard,init_instance] received, process exiting Mon Apr 08 15:03:18 2019 MANAGEMENT: >STATE:1554724998,EXITING,init_instance,,,,,

OpenVPN (advanced option using CA certificate downloaded from gateway and client cert from gateway as well) returns following:

2019-04-08 15:38:14 | 474 | OpenConnect-GUI VPN client (1.5.3) logging started... 2019-04-08 15:38:23 | 3574 | POST https://<streisand IP address>:4443/ 2019-04-08 15:38:23 | 3574 | Attempting to connect to server <streisand IP address>:4443 2019-04-08 15:38:23 | 3574 | Connected to <streisand IP address>:4443 2019-04-08 15:38:23 | 3574 | Using certificate file C:/Program Files (x86)/OpenConnect-GUI/tmp-certvbYXgz 2019-04-08 15:38:23 | 3574 | Using system key system:win:id=f54a74138c02c82ed341200cfe347d90b890ed27;type=privkey;name=cloth-side 2019-04-08 15:38:23 | 3574 | Using client certificate 'cloth-side' 2019-04-08 15:38:23 | 3574 | SSL negotiation with <streisand IP address> 2019-04-08 15:38:25 | 3574 | SSL connection failure: Error in the pull function. 2019-04-08 15:38:25 | 3574 | Failed to open HTTPS connection to <streisand IP address> 2019-04-08 15:38:25 | 3574 | Authentication error; cannot obtain cookie 2019-04-08 15:38:25 | 474 | Disconnected

From Streisand server:

ubuntu@ip-172-31-20-139:~$ journalctl -b --no-pager | grep -i ocserv | tail -n100 Apr 08 12:13:09 ip-172-31-20-139 systemd[1]: Starting Set the firewall rules required for ocserv... Apr 08 12:13:09 ip-172-31-20-139 systemd[1]: Started Set the firewall rules required for ocserv. Apr 08 12:13:38 ip-172-31-20-139 ocserv[1510]: Setting 'plain' as primary authentication method Apr 08 12:13:38 ip-172-31-20-139 ocserv[1510]: Enabling 'certificate' as authentication method Apr 08 12:13:38 ip-172-31-20-139 ocserv[1510]: Setting 'pam' as accounting method Apr 08 12:13:38 ip-172-31-20-139 ocserv[1510]: listening (TCP) on 0.0.0.0:4443... Apr 08 12:13:38 ip-172-31-20-139 ocserv[1510]: listening (TCP) on [::]:4443... Apr 08 12:13:38 ip-172-31-20-139 ocserv[1510]: listening (UDP) on 0.0.0.0:4443... Apr 08 12:13:38 ip-172-31-20-139 ocserv[1510]: listening (UDP) on [::]:4443... Apr 08 12:13:38 ip-172-31-20-139 ocserv[1510]: main: initialized ocserv 0.10.11 Apr 08 12:13:38 ip-172-31-20-139 ocserv[1552]: sec-mod: reading supplemental config from files Apr 08 12:13:38 ip-172-31-20-139 ocserv[1552]: sec-mod: sec-mod initialized (socket: /var/run/ocserv-socket.1510) Apr 08 12:13:38 ip-172-31-20-139 ocserv[1510]: main: processed 1 CA certificate(s) Apr 08 12:14:30 ip-172-31-20-139 ocserv[2837]: worker: tlslib.c:379: no certificate was found Apr 08 12:15:10 ip-172-31-20-139 ocserv[1510]: main: <client IP address>:47804 user disconnected (rx: 0, tx: 0) Apr 08 12:22:17 ip-172-31-20-139 ocserv[3398]: worker: client certificate verification succeeded Apr 08 12:22:17 ip-172-31-20-139 ocserv[3398]: GnuTLS error (at worker-vpn.c:466): The signature algorithm is not supported. Apr 08 12:22:17 ip-172-31-20-139 ocserv[1510]: main: <client IP address>:26412 user disconnected (rx: 0, tx: 0) Apr 08 12:38:25 ip-172-31-20-139 ocserv[3717]: worker: client certificate verification succeeded Apr 08 12:38:25 ip-172-31-20-139 ocserv[3717]: GnuTLS error (at worker-vpn.c:466): The signature algorithm is not supported. Apr 08 12:38:25 ip-172-31-20-139 ocserv[1510]: main: <client IP address>:52895 user disconnected (rx: 0, tx: 0) ubuntu@ip-172-31-20-139:~$

While trying to use simple authentication with login and password:

log from client: 2019-04-08 15:43:52 | 34dc | POST https://<streisand IP address>:4443/ 2019-04-08 15:43:52 | 34dc | Attempting to connect to server <streisand IP address>:4443 2019-04-08 15:43:53 | 34dc | Connected to <streisand IP address>:4443 2019-04-08 15:43:53 | 34dc | There was a non-CA certificate in the trusted list: CN=T430. 2019-04-08 15:43:53 | 34dc | There was a non-CA certificate in the trusted list: OU=Copyright (c) 1997 Microsoft Corp.,OU=Microsoft Corporation,CN=Microsoft Root Authority. 2019-04-08 15:43:53 | 34dc | There was a non-CA certificate in the trusted list: C=US,O=MSFT,CN=Microsoft Authenticode(tm) Root Authority. 2019-04-08 15:43:53 | 34dc | There was a non-CA certificate in the trusted list: CN=T430. 2019-04-08 15:43:53 | 34dc | There was a non-CA certificate in the trusted list: CN=T430. 2019-04-08 15:43:53 | 34dc | There was a non-CA certificate in the trusted list: CN=Root Agency. 2019-04-08 15:43:53 | 34dc | SSL negotiation with <streisand IP address> 2019-04-08 15:43:54 | 34dc | Server certificate verify failed: signer not found 2019-04-08 15:43:54 | 34dc | peer is unknown 2019-04-08 15:44:00 | 34dc | saving peer's public key 2019-04-08 15:44:00 | 34dc | Connected to HTTPS on <streisand IP address> 2019-04-08 15:44:01 | 34dc | Got HTTP response: HTTP/1.1 200 OK 2019-04-08 15:44:01 | 34dc | Set-Cookie: webvpncontext=; expires=Thu, 01 Jan 1970 22:00:00 GMT; path=/; Secure 2019-04-08 15:44:01 | 34dc | Content-Type: text/xml 2019-04-08 15:44:01 | 34dc | Content-Length: 306 2019-04-08 15:44:01 | 34dc | X-Transcend-Version: 1 2019-04-08 15:44:01 | 34dc | HTTP body length: (306) 2019-04-08 15:44:01 | 34dc | XML POST enabled 2019-04-08 15:44:01 | 34dc | Please enter your username. 2019-04-08 15:44:01 | 34dc | Text form: username 2019-04-08 15:44:12 | 34dc | POST https://<streisand IP address>:4443/auth 2019-04-08 15:44:13 | 34dc | Got HTTP response: HTTP/1.1 200 OK 2019-04-08 15:44:13 | 34dc | Set-Cookie: webvpncontext=L+qE36WQpal7cYYNZBfHuA==; Max-Age=300; Secure 2019-04-08 15:44:13 | 34dc | Content-Type: text/xml 2019-04-08 15:44:13 | 34dc | Content-Length: 310 2019-04-08 15:44:13 | 34dc | X-Transcend-Version: 1 2019-04-08 15:44:13 | 34dc | HTTP body length: (310) 2019-04-08 15:44:13 | 34dc | Please enter your password. 2019-04-08 15:44:13 | 34dc | Password form: password 2019-04-08 15:44:23 | 34dc | POST https://<streisand IP address>:4443/auth 2019-04-08 15:44:24 | 34dc | Got HTTP response: HTTP/1.1 200 OK 2019-04-08 15:44:24 | 34dc | Connection: Keep-Alive 2019-04-08 15:44:24 | 34dc | Content-Type: text/xml 2019-04-08 15:44:24 | 34dc | Content-Length: 189 2019-04-08 15:44:24 | 34dc | X-Transcend-Version: 1 2019-04-08 15:44:24 | 34dc | Set-Cookie: webvpncontext=L+qE36WQpal7cYYNZBfHuA==; Secure 2019-04-08 15:44:24 | 34dc | Set-Cookie: webvpn=; Secure 2019-04-08 15:44:24 | 34dc | Set-Cookie: webvpnc=; expires=Thu, 01 Jan 1970 22:00:00 GMT; path=/; Secure 2019-04-08 15:44:24 | 34dc | Set-Cookie: webvpnc=bu:/&p:t&iu:1/&sh:DCDBBFF782A9AA81B019A6EB8B5BAAF46E8C6196; path=/; Secure 2019-04-08 15:44:24 | 34dc | HTTP body length: (189) 2019-04-08 15:44:24 | 34dc | Got inappropriate HTTP CONNECT response: HTTP/1.1 401 Unauthorized 2019-04-08 15:44:24 | 34dc | Error establishing the CSTP channel 2019-04-08 15:44:24 | 474 | Disconnected

log from server:

Apr 08 12:44:01 ip-172-31-20-139 ocserv[3840]: worker: tlslib.c:379: no certificate was found Apr 08 12:44:13 ip-172-31-20-139 ocserv[1552]: sec-mod: using 'plain' authentication to authenticate user (session: L+qE3) Apr 08 12:44:24 ip-172-31-20-139 ocserv[1552]: PAM (ocserv) illegal module type: other Apr 08 12:44:24 ip-172-31-20-139 ocserv[1552]: pam_listfile(ocserv:account): Refused user streisand for service ocserv Apr 08 12:44:24 ip-172-31-20-139 ocserv[1552]: PAM-acct account error: Authentication failure Apr 08 12:44:24 ip-172-31-20-139 ocserv[1552]: sec-mod: denied session for user 'streisand' (session: L+qE3) Apr 08 12:44:24 ip-172-31-20-139 ocserv[1510]: main[streisand]: 213.87.146.119:60623 could not initiate session for 'streisand' Apr 08 12:44:24 ip-172-31-20-139 ocserv[1510]: main[streisand]: 213.87.146.119:60623 could not open session Apr 08 12:44:24 ip-172-31-20-139 ocserv[1510]: main[streisand]: 213.87.146.119:60623 failed authentication attempt for user 'streisand' Apr 08 12:44:24 ip-172-31-20-139 ocserv[1510]: main[streisand]: 213.87.146.119:60623 user logged in Apr 08 12:44:24 ip-172-31-20-139 ocserv[3840]: worker[streisand]: 213.87.146.119 error receiving cookie authentication reply Apr 08 12:44:24 ip-172-31-20-139 ocserv[3840]: worker[streisand]: 213.87.146.119 failed cookie authentication attempt Apr 08 12:44:24 ip-172-31-20-139 ocserv[1510]: main[streisand]: 213.87.146.119:60623 user disconnected (rx: 0, tx: 0) ubuntu@ip-172-31-20-139:~$ journalctl -b --no-pager | grep -i ocserv | tail -n100

I assume, it could be the issue with certs, used during installation (I've generated it with ssh-keygen prior Streisand install), but I'm not a certificate guru, so can't figure this out myself. Anyway, how it could affect anyways?

morte-rictusgrin avatar Apr 08 '19 12:04 morte-rictusgrin

I'm having the same issue on OSX / OpenConnect-GUI. A few things I noticed:

  • If I type a wrong password, the password dialog will keep asking me another one
  • If I type the correct password, the password dialog does not show up again (looks like the password is correct), but in the log window I get this messages:
2019-04-09 11:24:24 | 7000017ee000 | Got HTTP response: HTTP/1.1 200 OK
2019-04-09 11:24:24 | 7000017ee000 | Connection: Keep-Alive
2019-04-09 11:24:24 | 7000017ee000 | Content-Type: text/xml
2019-04-09 11:24:24 | 7000017ee000 | Content-Length: 189
2019-04-09 11:24:24 | 7000017ee000 | X-Transcend-Version: 1
2019-04-09 11:24:24 | 7000017ee000 | Set-Cookie: webvpncontext= Gwge9Ve17qXBluUszxfvyPA==; Secure
2019-04-09 11:24:24 | 7000017ee000 | Set-Cookie: webvpn=<elided>; Secure
2019-04-09 11:24:24 | 7000017ee000 | Set-Cookie: webvpnc=; expires=Thu, 01 Jan 1970 22:00:00 GMT; path=/; Secure
2019-04-09 11:24:24 | 7000017ee000 | Set-Cookie: webvpnc=bu:/&p:t&iu:1/&sh:DFF0F7859E49319B5B977CB41B7C4B8BCB5B725B; path=/; Secure
2019-04-09 11:24:24 | 7000017ee000 | HTTP body length:  (189)
2019-04-09 11:24:24 | 7000017ee000 | Got inappropriate HTTP CONNECT response: HTTP/1.1 401 Unauthorized
2019-04-09 11:24:24 | 7000017ee000 | Error establishing the CSTP channel

In comparison, this is the log for when I type in an incorrect password on purpose:

2019-04-09 11:24:20 | 7000017ee000 | Login failed.
Please enter your password.
2019-04-09 11:24:20 | 7000017ee000 | Got HTTP response: HTTP/1.1 200 OK
2019-04-09 11:24:20 | 7000017ee000 | Set-Cookie: webvpncontext=Gwge9Ve17qXBluUszxfvyPA==; Max-Age=300; Secure
2019-04-09 11:24:20 | 7000017ee000 | Content-Type: text/xml
2019-04-09 11:24:20 | 7000017ee000 | Content-Length: 324
2019-04-09 11:24:20 | 7000017ee000 | X-Transcend-Version: 1
2019-04-09 11:24:20 | 7000017ee000 | HTTP body length:  (324)

caioariede avatar Apr 09 '19 14:04 caioariede

@morte-rictusgrin this solved the problem to me: #1546

caioariede avatar Apr 09 '19 18:04 caioariede

@caioariede, yeah, that's a solution for OpenConnect, I've just checked it and it works, thanks. But what about OpenVPN and other services? This is definitelly installation issue, so I'll try to dig deeper to find out what's the root cause, but any help is much appreciated.

morte-rictusgrin avatar Apr 17 '19 09:04 morte-rictusgrin

Here is the solution for OpenVPN https://github.com/StreisandEffect/streisand/issues/1563#issuecomment-484270946

akha666 avatar Apr 20 '19 21:04 akha666

@akha666, thanks, but I'd like to get to the core of the issue, as I've installed yet another instance (this time remotely with ansible disabling purging unneeded packages), but it still has the same issue with connection both with OpenConnect and OpenVPN right out of the box.

morte-rictusgrin avatar Apr 22 '19 22:04 morte-rictusgrin

Hello,

I'm still unable to connect via openconnect by commenting this line "acct=pam". following solution #1546 Please can someone assist? what am i doing wrong? Thanking in advance.

EDIT: rebooting the server, was able to connect

zee-shany avatar Jul 21 '19 10:07 zee-shany

@zee-shany I used the same solution: commented acct = pam and restarted the service with sudo systemctl restart ocserv; it works now!

matteoipri avatar Feb 12 '20 11:02 matteoipri