This discussion has been locked.
You can no longer post new replies to this discussion. If you have a question you can start a new discussion

SSL VPN keeps reconnecting

Hi,

it seems my troubles don't end... We're using SSL VPN and it used to work pretty well.
Now all users get disconnected every 30 minutes or so (time varies) but can reconnect immediatley. This is a problem because the IP adress changes whith the new login and remote connections get interrupted.
This happens to a lot (if not all) my VPN users since 7.5 (now using 7.501).

On the client side I see this:
Thu Oct 22 12:34:24 2009 Connection reset, restarting [-1]

Thu Oct 22 12:34:24 2009 TCP/UDP: Closing socket
Thu Oct 22 12:34:24 2009 SIGUSR1[soft,connection-reset] received, process restarting
Thu Oct 22 12:34:24 2009 Restart pause, 5 second(s)


Why does it do that?


This thread was automatically locked due to age.
  • Can you tell whether this is a client problem or a problem in the Astaro?  Have the users downloaded the new Remote Access package from their User Portal?

    Cheers - Bob
     
    Sophos UTM Community Moderator
    Sophos Certified Architect - UTM
    Sophos Certified Engineer - XG
    Gold Solution Partner since 2005
    MediaSoft, Inc. USA
  • I can't point my finger on it yet. I have a feeling that it's a client side timeout thing... But that's nothing I can prove.
    Most clients are using the old VPN package, but I for myself have downloaded the new one and it shows the exact same problems.

    This is the astaro's log when it happens:

    2009:10:22-14:24:45 pluto openvpn[7569]: Re-using SSL/TLS context 
    
    2009:10:22-14:24:45 pluto openvpn[7569]: LZO compression initialized 
    2009:10:22-14:24:45 pluto openvpn[7569]: Control Channel MTU parms [ L:1556 D:140 EF:40 EB:0 ET:0 EL:0 ] 
    2009:10:22-14:24:45 pluto openvpn[7569]: Data Channel MTU parms [ L:1556 D:1450 EF:56 EB:135 ET:0 EL:0 AF:3/1 ] 
    2009:10:22-14:24:45 pluto openvpn[7569]: Local Options hash (VER=V4): 'a4f12474' 
    2009:10:22-14:24:45 pluto openvpn[7569]: Expected Remote Options hash (VER=V4): '619088b2' 
    2009:10:22-14:24:45 pluto openvpn[7569]: TCP connection established with [client wan ip]:55592 
    2009:10:22-14:24:45 pluto openvpn[7569]: TCPv4_SERVER link local: [undef] 
    2009:10:22-14:24:45 pluto openvpn[7569]: TCPv4_SERVER link remote: [client wan ip]:55592 
    2009:10:22-14:24:45 pluto openvpn[7569]: [client wan ip]:55592 Non-OpenVPN client protocol detected 
    2009:10:22-14:24:45 pluto openvpn[7569]: TCP/UDP: Closing socket 
  • THat is a wierd error... have you started a support case with Astaro yet; it sounds like you have a commercial installation there.  FWIW, I've been running SSL VPN with 7.500 with no problems so far.

    CTO, Convergent Information Security Solutions, LLC

    https://www.convergesecurity.com

    Sophos Platinum Partner

    --------------------------------------

    Advice given as posted on this forum does not construe a support relationship or other relationship with Convergent Information Security Solutions, LLC or its subsidiaries.  Use the advice given at your own risk.

  • I hate doing that, because I can't contact astaro support directly and have to go through my reseller who's somewhat slow. So I asked here before. I will do that if no ideas pop up here.
  • Can you descibe the issue a bit more. It would be interesting whether...
    ...ALL connected SSL-VPN USers are thrown out at the same moment
    ...there is a per-user-timeout (e.g. user1 gets thrown out every 15 minutes, user2 every 20 minutes, ...)
    ...or are they complety randomly and also not at the same time (when user1 get thrown out then user2 still can work)

    What shows the log of the SSL VPN client before and after the reconnect?
  • It's pretty much random. ALL users get thrown out but not at the same time and in no particular order or repeating timeframe.
    One thing I noticed: It happens more often when more VPN users are logged in (I have never seen more than 8 at once - ASG320)

    Clientside:
    Thu Oct 22 15:09:49 2009 Connection reset, restarting [-1]
    
    Thu Oct 22 15:09:49 2009 TCP/UDP: Closing socket
    Thu Oct 22 15:09:49 2009 SIGUSR1[soft,connection-reset] received, process restarting
    Thu Oct 22 15:09:49 2009 Restart pause, 5 second(s)
    Thu Oct 22 15:09:54 2009 WARNING: Make sure you understand the semantics of --tls-remote before using it (see the man page).
    Thu Oct 22 15:09:54 2009 NOTE: OpenVPN 2.1 requires '--script-security 2' or higher to call user-defined scripts or executables
    Thu Oct 22 15:09:54 2009 Re-using SSL/TLS context
    Thu Oct 22 15:09:54 2009 LZO compression initialized
    Thu Oct 22 15:09:54 2009 Control Channel MTU parms [ L:1556 D:140 EF:40 EB:0 ET:0 EL:0 ]
    Thu Oct 22 15:09:56 2009 Data Channel MTU parms [ L:1556 D:1450 EF:56 EB:135 ET:0 EL:0 AF:3/1 ]
    Thu Oct 22 15:09:56 2009 Local Options hash (VER=V4): '619088b2'
    Thu Oct 22 15:09:56 2009 Expected Remote Options hash (VER=V4): 'a4f12474'
    Thu Oct 22 15:09:56 2009 Attempting to establish TCP connection with *.*.*.*:443
    Thu Oct 22 15:09:56 2009 TCP connection established with *.*.*.*:443
    Thu Oct 22 15:09:56 2009 Socket Buffers: R=[8192->8192] S=[8192->8192]
    Thu Oct 22 15:09:56 2009 TCPv4_CLIENT link local: [undef]
    Thu Oct 22 15:09:56 2009 TCPv4_CLIENT link remote: *.*.*.*:443
    Thu Oct 22 15:09:56 2009 TLS: Initial packet from *.*.*.*:443, sid=72958129 6fa8b092
    Thu Oct 22 15:09:56 2009 WARNING: this configuration may cache passwords in memory -- use the auth-nocache option to prevent this
    Thu Oct 22 15:09:58 2009 VERIFY OK: depth=1, /C=de/L=Bonn/O=[myemaildomain]/CN=[myemaildomain]_***/emailAddress=support@myemaildomain.de
    Thu Oct 22 15:09:58 2009 VERIFY X509NAME OK: /C=de/L=Bonn/O=[myemaildomain]/CN=[asg hostname]/emailAddress=support@myemaildomain.de
    Thu Oct 22 15:09:58 2009 VERIFY OK: depth=0, /C=de/L=Bonn/O=[myemaildomain]/CN=[asg hostname]/emailAddress=support@myemaildomain.de
    Thu Oct 22 15:10:00 2009 Data Channel Encrypt: Cipher 'AES-128-CBC' initialized with 128 bit key
    Thu Oct 22 15:10:00 2009 Data Channel Encrypt: Using 128 bit message hash 'MD5' for HMAC authentication
    Thu Oct 22 15:10:00 2009 Data Channel Decrypt: Cipher 'AES-128-CBC' initialized with 128 bit key
    Thu Oct 22 15:10:00 2009 Data Channel Decrypt: Using 128 bit message hash 'MD5' for HMAC authentication
    Thu Oct 22 15:10:00 2009 Control Channel: TLSv1, cipher TLSv1/SSLv3 DHE-RSA-AES256-SHA, 1024 bit RSA
    Thu Oct 22 15:10:00 2009 [[asg hostname]] Peer Connection Initiated with *.*.*.*:443
    Thu Oct 22 15:10:01 2009 SENT CONTROL [[asg hostname]]: 'PUSH_REQUEST' (status=1)
    Thu Oct 22 15:10:02 2009 PUSH: Received control message: 'PUSH_REPLY,ifconfig 192.168.111.6 192.168.111.5,ping-restart 120,ping 10,topology net30,route 192.168.111.1,dhcp-option DNS 10.10.200.10,dhcp-option DNS 192.168.111.1,route 10.1.1.0 255.255.255.0,route 10.10.0.0 255.255.0.0,route 192.168.0.0 255.255.0.0'
    Thu Oct 22 15:10:02 2009 OPTIONS IMPORT: timers and/or timeouts modified
    Thu Oct 22 15:10:02 2009 OPTIONS IMPORT: --ifconfig/up options modified
    Thu Oct 22 15:10:02 2009 OPTIONS IMPORT: route options modified
    Thu Oct 22 15:10:02 2009 OPTIONS IMPORT: --ip-win32 and/or --dhcp-option options modified
    Thu Oct 22 15:10:02 2009 Preserving previous TUN/TAP instance: VPN
    Thu Oct 22 15:10:02 2009 NOTE: Pulled options changed on restart, will need to close and reopen TUN/TAP device.
    Thu Oct 22 15:10:02 2009 C:\WINDOWS\system32\route.exe DELETE 192.168.111.1 MASK 255.255.255.255 192.168.111.29
    Thu Oct 22 15:10:02 2009 Route deletion via IPAPI succeeded [adaptive]
    Thu Oct 22 15:10:02 2009 C:\WINDOWS\system32\route.exe DELETE 10.1.1.0 MASK 255.255.255.0 192.168.111.29
    Thu Oct 22 15:10:02 2009 Route deletion via IPAPI succeeded [adaptive]
    Thu Oct 22 15:10:02 2009 C:\WINDOWS\system32\route.exe DELETE 10.10.0.0 MASK 255.255.0.0 192.168.111.29
    Thu Oct 22 15:10:02 2009 Route deletion via IPAPI succeeded [adaptive]
    Thu Oct 22 15:10:02 2009 C:\WINDOWS\system32\route.exe DELETE 192.168.0.0 MASK 255.255.0.0 192.168.111.29
    Thu Oct 22 15:10:02 2009 Route deletion via IPAPI succeeded [adaptive]
    Thu Oct 22 15:10:02 2009 Closing TUN/TAP interface
    Thu Oct 22 15:10:03 2009 ROUTE default_gateway=192.168.1.1
    Thu Oct 22 15:10:03 2009 TAP-WIN32 device [VPN] opened: \.\Global\{085287B5-B0C5-4021-B35E-3275D99501D5}.tap
    Thu Oct 22 15:10:03 2009 TAP-Win32 Driver Version 9.6 
    Thu Oct 22 15:10:03 2009 TAP-Win32 MTU=1500
    Thu Oct 22 15:10:03 2009 Notified TAP-Win32 driver to set a DHCP IP/netmask of 192.168.111.6/255.255.255.252 on interface {085287B5-B0C5-4021-B35E-3275D99501D5} [DHCP-serv: 192.168.111.5, lease-time: 31536000]
    Thu Oct 22 15:10:03 2009 Successful ARP Flush on interface [18] {085287B5-B0C5-4021-B35E-3275D99501D5}
    Thu Oct 22 15:10:08 2009 TEST ROUTES: 4/4 succeeded len=4 ret=1 a=0 u/d=up
    Thu Oct 22 15:10:08 2009 WARNING: potential route subnet conflict between local LAN [192.168.1.0/255.255.255.0] and remote VPN [192.168.0.0/255.255.0.0]
    Thu Oct 22 15:10:08 2009 C:\WINDOWS\system32\route.exe ADD 192.168.0.0 MASK 255.255.0.0 192.168.111.5
    Thu Oct 22 15:10:08 2009 ROUTE: CreateIpForwardEntry succeeded with dwForwardMetric1=30 and dwForwardType=4
    Thu Oct 22 15:10:08 2009 Route addition via IPAPI succeeded [adaptive]
    Thu Oct 22 15:10:08 2009 C:\WINDOWS\system32\route.exe ADD 10.10.0.0 MASK 255.255.0.0 192.168.111.5
    Thu Oct 22 15:10:08 2009 ROUTE: CreateIpForwardEntry succeeded with dwForwardMetric1=30 and dwForwardType=4
    Thu Oct 22 15:10:08 2009 Route addition via IPAPI succeeded [adaptive]
    Thu Oct 22 15:10:08 2009 C:\WINDOWS\system32\route.exe ADD 10.1.1.0 MASK 255.255.255.0 192.168.111.5
    Thu Oct 22 15:10:08 2009 ROUTE: CreateIpForwardEntry succeeded with dwForwardMetric1=30 and dwForwardType=4
    Thu Oct 22 15:10:08 2009 Route addition via IPAPI succeeded [adaptive]
    Thu Oct 22 15:10:08 2009 C:\WINDOWS\system32\route.exe ADD 192.168.111.1 MASK 255.255.255.255 192.168.111.5
    Thu Oct 22 15:10:08 2009 ROUTE: CreateIpForwardEntry succeeded with dwForwardMetric1=30 and dwForwardType=4
    Thu Oct 22 15:10:08 2009 Route addition via IPAPI succeeded [adaptive]
    Thu Oct 22 15:10:08 2009 Initialization Sequence Completed


    ASG320:

    2009:10:22-15:09:53 pluto openvpn[7569]: Re-using SSL/TLS context 
    
    2009:10:22-15:09:53 pluto openvpn[7569]: LZO compression initialized 
    2009:10:22-15:09:53 pluto openvpn[7569]: Control Channel MTU parms [ L:1556 D:140 EF:40 EB:0 ET:0 EL:0 ] 
    2009:10:22-15:09:53 pluto openvpn[7569]: Data Channel MTU parms [ L:1556 D:1450 EF:56 EB:135 ET:0 EL:0 AF:3/1 ] 
    2009:10:22-15:09:53 pluto openvpn[7569]: Local Options hash (VER=V4): 'a4f12474' 
    2009:10:22-15:09:53 pluto openvpn[7569]: Expected Remote Options hash (VER=V4): '619088b2' 
    2009:10:22-15:09:53 pluto openvpn[7569]: TCP connection established with [remote wan ip]:55533 
    2009:10:22-15:09:53 pluto openvpn[7569]: TCPv4_SERVER link local: [undef] 
    2009:10:22-15:09:53 pluto openvpn[7569]: TCPv4_SERVER link remote: [remote wan ip]:55533 
    2009:10:22-15:09:57 pluto openvpn[7569]: [remote wan ip]:55533 VERIFY OK: depth=1, /C=de/L=Bonn/O=[myemaildomain]/CN=[myemaildomain]_***/emailAddress=support@myemaildomain.de 
    2009:10:22-15:09:57 pluto openvpn[7569]: [remote wan ip]:55533 VERIFY OK: depth=0, /C=de/L=Bonn/O=[myemaildomain]/CN=***/emailAddress=***@myemaildomain.de 
    2009:10:22-15:09:58 pluto openvpn[7569]: [remote wan ip]:55533 TLS: Username/Password authentication succeeded for username '***' 
    2009:10:22-15:09:58 pluto openvpn[7569]: [remote wan ip]:55533 Data Channel Encrypt: Cipher 'AES-128-CBC' initialized with 128 bit key 
    2009:10:22-15:09:58 pluto openvpn[7569]: [remote wan ip]:55533 Data Channel Encrypt: Using 128 bit message hash 'MD5' for HMAC authentication 
    2009:10:22-15:09:58 pluto openvpn[7569]: [remote wan ip]:55533 Data Channel Decrypt: Cipher 'AES-128-CBC' initialized with 128 bit key 
    2009:10:22-15:09:58 pluto openvpn[7569]: [remote wan ip]:55533 Data Channel Decrypt: Using 128 bit message hash 'MD5' for HMAC authentication 
    2009:10:22-15:09:58 pluto openvpn[7569]: [remote wan ip]:55533 Control Channel: TLSv1, cipher TLSv1/SSLv3 DHE-RSA-AES256-SHA, 1024 bit RSA 
    2009:10:22-15:09:58 pluto openvpn[7569]: [remote wan ip]:55533 [***] Peer Connection Initiated with [remote wan ip]:55533


    Before and after that the same stuff is happening.
  • Hmm, looking at the client log I would assume, the server (the ASG) is closing/resetting the connection, so it´s not the "fault" of the client but of the server.

    Looking in the servers log doesn´t really clearify what happens. Before the firtt log line you postet - "re-using ssl/TLS context" - ist there anything interesting happening what could lead to a "reset" of the user? 
    I would really be interested in the openvpn log between 15:09:30 and 15:09:53...

    Have you enabled the Debugging mode in SSL VPN - Advanced ?
  • ther is no log before that. except from way before when another client reconnected.
    I'll activate debug logging tomorrow.
  • Krycek, I have an idea which could be the cause of the problem.

    Are you using the "any" network in the SSL VPN local networks definition, so you route ALL traffic on the SSL VPN client through the tunnel?
    And are your SSL VPN Client computers using DHCP to retrive their ethernet ip addresses from a DHCP server in their lokal LAN ?
  • Nope.

    As you can see from the client log I posted there is no "any" route pushed to the client.
    Also the astaro is doing the SSL-VPN-DHCP Job. See the picture.