VPN: Remote Access set-up (UTM side) using local authentication - Getting "recv_line: TCP port read failed on recv()"

Hi, I'm trying to set-up VPN to my UTM 9 so I can connect from "Open" networks back to a (more) secure position.

Here's what I've done thus far, any advice/guidance/pointers would be very much appreciated.

UTM: 9.510-5
Pattern version: 153278

Steps taken:

Issue:

  • When connecting with OpenVPN (2.4.6) from Windows 10 I'm getting "recv_line: TCP port read failed on recv()" and the VPN connection just continues to retry
  • Also tried the UTM User Portal version of VPN client & Windows 10 "built in" VPN client - same error
  • Have checked Dr. GOOGLE and Sophos communities however there doesn't seem to be a definitive explanation/root cause/resolution.
  • I've also updated the TAP driver although not sure that's the issue here (from a non-expert standpoint).

 

  1. First, what does "recv_line: TCP port read failed on recv()" actually (really) mean?
  2. Second, as I've tried 3 different (Windows 10) clients and get the same "error" my presumption is that my UTM 9 configurtion is at fault however I'm struggling to see where based upon following the .pdf link above

    === OpenVPN log start
    Sat Nov 03 17:55:04 2018 OpenVPN 2.4.6 x86_64-w64-mingw32 [SSL (OpenSSL)] [LZO] [LZ4] [PKCS11] [AEAD] built on Apr 26 2018
    Sat Nov 03 17:55:04 2018 Windows version 6.2 (Windows 8 or greater) 64bit
    Sat Nov 03 17:55:04 2018 library versions: OpenSSL 1.1.0h  27 Mar 2018, LZO 2.10
    Enter Management Password:
    Sat Nov 03 17:55:04 2018 MANAGEMENT: TCP Socket listening on [AF_INET]127.0.0.1:25340
    Sat Nov 03 17:55:04 2018 Need hold release from management interface, waiting...
    Sat Nov 03 17:55:04 2018 MANAGEMENT: Client connected from [AF_INET]127.0.0.1:25340
    Sat Nov 03 17:55:04 2018 MANAGEMENT: CMD 'state on'
    Sat Nov 03 17:55:04 2018 MANAGEMENT: CMD 'log all on'
    Sat Nov 03 17:55:04 2018 MANAGEMENT: CMD 'echo all on'
    Sat Nov 03 17:55:04 2018 MANAGEMENT: CMD 'bytecount 5'
    Sat Nov 03 17:55:04 2018 MANAGEMENT: CMD 'hold off'
    Sat Nov 03 17:55:04 2018 MANAGEMENT: CMD 'hold release'
    Sat Nov 03 17:55:13 2018 MANAGEMENT: CMD 'username "Auth" "<name>"'
    Sat Nov 03 17:55:13 2018 MANAGEMENT: CMD 'password [...]'
    Sat Nov 03 17:55:13 2018 MANAGEMENT: CMD 'proxy HTTP aaa.bbb.ccc 443'
    Sat Nov 03 17:55:14 2018 MANAGEMENT: >STATE:1541267714,RESOLVE,,,,,,
    Sat Nov 03 17:55:14 2018 TCP/UDP: Preserving recently used remote address: [AF_INET]1.2.3.4:443
    Sat Nov 03 17:55:14 2018 Socket Buffers: R=[65536->65536] S=[65536->65536]
    Sat Nov 03 17:55:14 2018 Attempting to establish TCP connection with [AF_INET]1.2.3.4:443 [nonblock]
    Sat Nov 03 17:55:14 2018 MANAGEMENT: >STATE:1541267714,TCP_CONNECT,,,,,,
    Sat Nov 03 17:55:15 2018 TCP connection established with [AF_INET]1.2.3.4:443
    Sat Nov 03 17:55:15 2018 Send to HTTP proxy: 'CONNECT aaa.bbb.ccc:443 HTTP/1.0'
    Sat Nov 03 17:55:15 2018 Send to HTTP proxy: 'Host: aaa.bbb.ccc'
    Sat Nov 03 17:55:15 2018 recv_line: TCP port read failed on recv()
    Sat Nov 03 17:55:15 2018 SIGUSR1[soft,init_instance] received, process restarting
    Sat Nov 03 17:55:15 2018 MANAGEMENT: >STATE:1541267715,RECONNECTING,init_instance,,,,,
    Sat Nov 03 17:55:15 2018 Restart pause, 5 second(s)
    Sat Nov 03 17:55:19 2018 SIGTERM[hard,init_instance] received, process exiting
    Sat Nov 03 17:55:19 2018 MANAGEMENT: >STATE:1541267719,EXITING,init_instance,,,,,
    === OpenVPN log end

Here's an "example" of what I see in the SSL VPN log:

2018:11:03-23:58:39 firewall openvpn[27856]: 195.171.237.220:59662 Non-OpenVPN client protocol detected
2018:11:03-23:58:39 firewall openvpn[27856]: 195.171.237.220:59662 SIGTERM[soft,port-share-redirect] received, client-instance exiting


  • Steve, try a Google on:

    site:community.sophos.com/products/unified-threat-management/f ssl vpn win 10 "Non-OpenVPN client protocol detected"

    Please let us know what you found that helped.  If you want to pursue this here, open the SSL VPN Live Log and then sign into the VPN.

    Cheers - Bob

  • In reply to BAlfson:

    Bob,

    Hi and thanks for the suggestion which I'm currently working through.

    Can you tidy up a misunderstanding I have please?

    I've seen loads of Posts about the UTM client NOT working within Windows 10 and then I saw

    https://community.sophos.com/products/unified-threat-management/f/vpn-site-to-site-and-remote-access/55252/ssl-vpn-without-client

    ... implying that my SSL approach won't work and that only PPTP and L2TP/IPsec "will" work.

    Have I understood things correctly in that there's no point me going down the SSL path and that PPTP and L2TP/IPsec is my route to salvation?

  • In reply to Steve Munday:

    I think it does work, Steve, but that there were several issues.  I prefer SSL VPN over PPTP and L2TP/IPsec if you don't want all traffic to go through the tunnel.

    You might try downloading the OpenVPN client from their site.  I won't have a chance to test this with the Sophos client under Win10 until Thursday evening or Friday morning.

    Cheers - Bob

  • In reply to BAlfson:

    Bob,

    Here's the Firewall (SSL VPN) and OpenVPN logs for a failed session using OpenVPN client.  I see the same "Non-OpenVPN client protocol detected" message for the Windows 10 (built in) and Sophos UTM clients.

     

    Firewall log (Remote Access SSL VPN)

    2018:11:06-19:09:42 firewall openvpn[27856]: TCP connection established with [AF_INET]1.2.3.4:39745 (via [AF_INET]10.20.30.40:443)
    2018:11:06-19:09:42 firewall openvpn[27856]: 1.2.3.4:39745 Non-OpenVPN client protocol detected
    2018:11:06-19:09:42 firewall openvpn[27856]: 1.2.3.4:39745 SIGTERM[soft,port-share-redirect] received, client-instance exiting
    2018:11:06-20:50:24 firewall openvpn[27856]: TCP connection established with [AF_INET]1.2.3.4:15411 (via [AF_INET]10.20.30.40:443)
    2018:11:06-20:50:25 firewall openvpn[27856]: 1.2.3.4:15411 Non-OpenVPN client protocol detected
    2018:11:06-20:50:25 firewall openvpn[27856]: 1.2.3.4:15411 SIGTERM[soft,port-share-redirect] received, client-instance exiting
    2018:11:06-20:50:32 firewall openvpn[27856]: TCP connection established with [AF_INET]1.2.3.4:15686 (via [AF_INET]10.20.30.40:443)
    2018:11:06-20:50:33 firewall openvpn[27856]: 1.2.3.4:15686 Non-OpenVPN client protocol detected
    2018:11:06-20:50:33 firewall openvpn[27856]: 1.2.3.4:15686 SIGTERM[soft,port-share-redirect] received, client-instance exiting
    2018:11:06-20:50:40 firewall openvpn[27856]: TCP connection established with [AF_INET]1.2.3.4:60672 (via [AF_INET]10.20.30.40:443)
    2018:11:06-20:50:41 firewall openvpn[27856]: 1.2.3.4:60672 Non-OpenVPN client protocol detected
    2018:11:06-20:50:41 firewall openvpn[27856]: 1.2.3.4:60672 SIGTERM[soft,port-share-redirect] received, client-instance exiting

    OpenVPN "log"
    Tue Nov 06 20:50:17 2018 OpenVPN 2.4.6 x86_64-w64-mingw32 [SSL (OpenSSL)] [LZO] [LZ4] [PKCS11] [AEAD] built on Apr 26 2018
    Tue Nov 06 20:50:17 2018 Windows version 6.2 (Windows 8 or greater) 64bit
    Tue Nov 06 20:50:17 2018 library versions: OpenSSL 1.1.0h  27 Mar 2018, LZO 2.10
    Enter Management Password:
    Tue Nov 06 20:50:17 2018 MANAGEMENT: TCP Socket listening on [AF_INET]127.0.0.1:25340
    Tue Nov 06 20:50:17 2018 Need hold release from management interface, waiting...
    Tue Nov 06 20:50:18 2018 MANAGEMENT: Client connected from [AF_INET]127.0.0.1:25340
    Tue Nov 06 20:50:18 2018 MANAGEMENT: CMD 'state on'
    Tue Nov 06 20:50:18 2018 MANAGEMENT: CMD 'log all on'
    Tue Nov 06 20:50:18 2018 MANAGEMENT: CMD 'echo all on'
    Tue Nov 06 20:50:18 2018 MANAGEMENT: CMD 'bytecount 5'
    Tue Nov 06 20:50:18 2018 MANAGEMENT: CMD 'hold off'
    Tue Nov 06 20:50:18 2018 MANAGEMENT: CMD 'hold release'
    Tue Nov 06 20:50:25 2018 MANAGEMENT: CMD 'username "Auth" "<name>"'
    Tue Nov 06 20:50:25 2018 MANAGEMENT: CMD 'password [...]'
    Tue Nov 06 20:50:25 2018 MANAGEMENT: CMD 'proxy HTTP x.y.z 443'
    Tue Nov 06 20:50:26 2018 MANAGEMENT: >STATE:1541537426,RESOLVE,,,,,,
    Tue Nov 06 20:50:26 2018 TCP/UDP: Preserving recently used remote address: [AF_INET]10.20.30.40:443
    Tue Nov 06 20:50:26 2018 Socket Buffers: R=[65536->65536] S=[65536->65536]
    Tue Nov 06 20:50:26 2018 Attempting to establish TCP connection with [AF_INET]10.20.30.40:443 [nonblock]
    Tue Nov 06 20:50:26 2018 MANAGEMENT: >STATE:1541537426,TCP_CONNECT,,,,,,
    Tue Nov 06 20:50:27 2018 TCP connection established with [AF_INET]10.20.30.40:443
    Tue Nov 06 20:50:27 2018 Send to HTTP proxy: 'CONNECT x.y.z:443 HTTP/1.0'
    Tue Nov 06 20:50:27 2018 Send to HTTP proxy: 'Host: x.y.z'
    Tue Nov 06 20:50:28 2018 recv_line: TCP port read failed on recv()
    Tue Nov 06 20:50:28 2018 SIGUSR1[soft,init_instance] received, process restarting
    Tue Nov 06 20:50:28 2018 MANAGEMENT: >STATE:1541537428,RECONNECTING,init_instance,,,,,
    Tue Nov 06 20:50:28 2018 Restart pause, 5 second(s)
    Tue Nov 06 20:50:33 2018 MANAGEMENT: CMD 'proxy HTTP x.y.z 443'
    Tue Nov 06 20:50:34 2018 MANAGEMENT: >STATE:1541537434,RESOLVE,,,,,,
    Tue Nov 06 20:50:34 2018 TCP/UDP: Preserving recently used remote address: [AF_INET]10.20.30.40:443
    Tue Nov 06 20:50:34 2018 Socket Buffers: R=[65536->65536] S=[65536->65536]
    Tue Nov 06 20:50:34 2018 Attempting to establish TCP connection with [AF_INET]10.20.30.40:443 [nonblock]
    Tue Nov 06 20:50:34 2018 MANAGEMENT: >STATE:1541537434,TCP_CONNECT,,,,,,
    Tue Nov 06 20:50:35 2018 TCP connection established with [AF_INET]10.20.30.40:443
    Tue Nov 06 20:50:35 2018 Send to HTTP proxy: 'CONNECT x.y.z:443 HTTP/1.0'
    Tue Nov 06 20:50:35 2018 Send to HTTP proxy: 'Host: x.y.z'
    Tue Nov 06 20:50:36 2018 recv_line: TCP port read failed on recv()
    Tue Nov 06 20:50:36 2018 SIGUSR1[soft,init_instance] received, process restarting
    Tue Nov 06 20:50:36 2018 MANAGEMENT: >STATE:1541537436,RECONNECTING,init_instance,,,,,
    Tue Nov 06 20:50:36 2018 Restart pause, 5 second(s)
    Tue Nov 06 20:50:41 2018 MANAGEMENT: CMD 'proxy HTTP x.y.z 443'
    Tue Nov 06 20:50:42 2018 MANAGEMENT: >STATE:1541537442,RESOLVE,,,,,,
    Tue Nov 06 20:50:42 2018 TCP/UDP: Preserving recently used remote address: [AF_INET]10.20.30.40:443
    Tue Nov 06 20:50:42 2018 Socket Buffers: R=[65536->65536] S=[65536->65536]
    Tue Nov 06 20:50:42 2018 Attempting to establish TCP connection with [AF_INET]10.20.30.40:443 [nonblock]
    Tue Nov 06 20:50:42 2018 MANAGEMENT: >STATE:1541537442,TCP_CONNECT,,,,,,
    Tue Nov 06 20:50:43 2018 TCP connection established with [AF_INET]10.20.30.40:443
    Tue Nov 06 20:50:43 2018 Send to HTTP proxy: 'CONNECT x.y.z:443 HTTP/1.0'
    Tue Nov 06 20:50:43 2018 Send to HTTP proxy: 'Host: x.y.z'
    Tue Nov 06 20:50:44 2018 recv_line: TCP port read failed on recv()
    Tue Nov 06 20:50:44 2018 SIGUSR1[soft,init_instance] received, process restarting
    Tue Nov 06 20:50:44 2018 MANAGEMENT: >STATE:1541537444,RECONNECTING,init_instance,,,,,
    Tue Nov 06 20:50:44 2018 Restart pause, 5 second(s)
    Tue Nov 06 20:50:47 2018 SIGTERM[hard,init_instance] received, process exiting
    Tue Nov 06 20:50:47 2018 MANAGEMENT: >STATE:1541537447,EXITING,init_instance,,,,,

  • In reply to Steve Munday:

    Steve, are you sure that your client isn't behind a firewall that knows how to block traffic by application and that OpenVPN is blocked?

    Cheers - Bob

  • In reply to BAlfson:

    Bob,

    Hi, when I do my "testing" I am using my iPhone's "Hot spot" and connect my Laptop through that to mimic being "outside" the home network.

  • In reply to Steve Munday:

    Steve, can you connect directly from the iPhone with the OpenVPN app?  How about from the laptop through a public hotspot?

    Cheers - Bob

  • In reply to BAlfson:

    Bob,

    Hi, good morning.

    I downloaded the OpenVPN app and pointed it at the UTM however it didn't succeed, SSL VPN excerpt below:

    2018:11:09-10:33:04 firewall openvpn[27856]: 185.69.145.154:46382 SIGTERM[soft,port-share-redirect] received, client-instance exiting
    2018:11:09-10:33:37 firewall openvpn[27856]: TCP connection established with [AF_INET]185.69.145.154:7680 (via [AF_INET]1.2.3.4:443)
    2018:11:09-10:33:37 firewall openvpn[27856]: 185.69.145.154:7680 Non-OpenVPN client protocol detected
    2018:11:09-10:33:37 firewall openvpn[27856]: 185.69.145.154:7680 SIGTERM[soft,port-share-redirect] received, client-instance exiting
    2018:11:09-10:36:40 firewall openvpn[27856]: TCP connection established with [AF_INET]185.69.145.154:58369 (via [AF_INET]1.2.3.4:443)
    2018:11:09-10:36:40 firewall openvpn[27856]: 185.69.145.154:58369 Non-OpenVPN client protocol detected
    2018:11:09-10:36:40 firewall openvpn[27856]: 185.69.145.154:58369 SIGTERM[soft,port-share-redirect] received, client-instance exiting
    2018:11:09-10:37:12 firewall openvpn[27856]: TCP connection established with [AF_INET]185.69.145.154:43988 (via [AF_INET]1.2.3.4:443)
    2018:11:09-10:37:12 firewall openvpn[27856]: 185.69.145.154:43988 Non-OpenVPN client protocol detected
    2018:11:09-10:37:12 firewall openvpn[27856]: 185.69.145.154:43988 SIGTERM[soft,port-share-redirect] received, client-instance exiting

    I've not had a chance to test via a "public" hotspot as yet.

  • In reply to Steve Munday:

    Is this you attempting to connect with your phone through the external interface when you're not on local WiFi, Steve?

    Cheers - Bob

  • In reply to BAlfson:

    Bob,

    Hi, sorry for the delay.

    Yes, I turn my WiFi "off", use my 4G and act as a "hot spot".  When connecting "through" the iPhone (using 4G) I (still) can't access the VPN target, logs previously provided.

  • In reply to Steve Munday:

    I'm out of questions, Steve.  If a reboot doesn't help, I'd get some backups off the UTM and re-image from ISO.  ANy better luck with that?

    Cheers - Bob