Guest User!

You are not Sophos Staff.

Thread Info
  • State Not Answered
  • Locked Locked
  • Replies 9 replies
  • Subscribers 26 subscribers
  • Views 2155 views
  • Users 0 members are here
Options
Suggested
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

frequent vpn SSL disconnection

RaphaelleB

Hello,

First of all, I'm sorry for my English.

Secondly, we are currently facing a problem that I can't solve.

Our customer has the following firewall:
- SOPHOS XG125
- The firewall was in SFOS 17.5.9 MR-9 but we changed it to SFOS 17.5.15 MR-15
- 1 remote access SSL VPN built on the basis of Sophos documentation for 3 years
- 3 VPN Ipsec for other sites
- Several firewall rules

For about 1 month it has been experiencing frequent and random disconnections from users in VPNSSL.
I have done the following:
- Looked at reports and diagnostics -> Nothing abnormal was found (hardware, ISP link...)
- Reinstall VPN on client computers -> Same problem
- Checked the certificates -> They are not expired
- Upgrade SFOS 17.5.9 MR-9 to SFOS 17.5.15 MR-15 -> Same issue
- Multiple restarts of the firewall -> Same problem

I can't think of any other solution, has anyone encountered this problem before?

I send my entire logs to Sophos in their ftp server for french support.

Here, you can see logs:

User log (same for each users):

Thu Mar 04 14:11:12 2021 MANAGEMENT: >STATE:1614863472,CONNECTED,SUCCESS,10.81.234.9,X.X.X.X,8443,192.168.1.67,61741

Thu Mar 04 14:16:07 2021 read TCPv4_CLIENT: Connection timed out (WSAETIMEDOUT) (code=10060)

Thu Mar 04 14:16:07 2021 Connection reset, restarting [-1] Thu Mar 04 14:16:07 2021 SIGUSR1[soft,connection-reset] received, process restarting

Thu Mar 04 14:16:07 2021 MANAGEMENT: >STATE:1614863767,RECONNECTING,connection-reset,,,,,

Thu Mar 04 14:16:07 2021 Restart pause, 5 second(s) Thu Mar 04 14:16:12 2021 Socket Buffers: R=[65536->65536] S=[65536->65536]

Thu Mar 04 14:16:12 2021 Attempting to establish TCP connection with [AF_INET]X.X.X.X:8443 [nonblock]

Thu Mar 04 14:16:12 2021 MANAGEMENT: >STATE:1614863772,TCP_CONNECT,,,,,,

Thu Mar 04 14:16:13 2021 TCP connection established with [AF_INET]X.X.X.X:8443

Thu Mar 04 14:16:13 2021 TCPv4_CLIENT link local: [undef] Thu Mar 04 14:16:13 2021 TCPv4_CLIENT link remote: [AF_INET]X.X.X.X:8443

Thu Mar 04 14:16:13 2021 MANAGEMENT: >STATE:1614863773,WAIT,,,,,,

Thu Mar 04 14:16:13 2021 MANAGEMENT: >STATE:1614863773,AUTH,,,,,,

Firewall log in sslvpn.log:

Wed Mar 10 15:32:33 2021 [4692] USER1/::ffff:X.X.X.X Connection reset, restarting [-1]
Wed Mar 10 15:32:33 2021 [4692] USER1/::ffff:X.X.X.X SIGUSR1[soft,connection-reset] received, client-instance restarting
Authentication server 127.0.0.1 gave login response code 2
GARNER: log disconnect event: username=X.X.X.X
Wed Mar 10 15:32:33 2021 [4692] PLUGIN_CALL: POST /lib/openvpn-plugin-utm.so/PLUGIN_CLIENT_DISCONNECT status=0
DELETE 1
COMMIT
ipset v6.14: Element cannot be deleted from the set: it's not added
ipset v6.14: Element cannot be deleted from the set: it's not added
ipset v6.14: Element cannot be deleted from the set: it's not added
Wed Mar 10 15:32:34 2021 [4692] WARNING: Failed running command (--client-disconnect): external program exited with error status: 1

ERROR in csr.log before disconnections:

DEBUG Mar 10 15:32:30 [u2d_dr_installer:1390]: init_db_handle_pl: Initializing DBI DB handle
INFO Mar 10 15:32:30 [u2d_dr_installer:1390]: TRYLOCK: 50
INFO Mar 10 15:32:30 [u2d_dr_installer:1390]: do_get: g_ha_mode
ERROR Mar 10 15:32:30 [u2d_pt_installer:1385]: csc_execve: Child exited with status 244
ERROR Mar 10 15:32:30 [u2d_pt_installer:1385]: log_exec: Failed Command: /bin/nvram qget is_eula
INFO Mar 10 15:32:30 [u2d_pt_installer:1385]: create_act_out_perl_obj: varname=is_eula
INFO Mar 10 15:32:30 [u2d_pt_installer:1385]: create_act_out_perl_obj: is_eula.status=16777204
WARNING Mar 10 15:32:30 [u2d_pt_installer:1385]: action with nofail failed
ERROR Mar 10 15:32:30 [u2d_dr_installer:1390]: csc_execve: Child exited with status 244
ERROR Mar 10 15:32:30 [u2d_dr_installer:1390]: log_exec: Failed Command: /bin/nvram qget is_eula
INFO Mar 10 15:32:30 [u2d_dr_installer:1390]: create_act_out_perl_obj: varname=is_eula
INFO Mar 10 15:32:30 [u2d_dr_installer:1390]: create_act_out_perl_obj: is_eula.status=16777204
WARNING Mar 10 15:32:30 [u2d_dr_installer:1390]: action with nofail failed
DEBUG Mar 10 15:32:30 [listener:1373]: ln_recvfrom: fd '5.UDP.INET.server': 37 bytes are read by listener
DEBUG Mar 10 15:32:30 [listener:1373]: register_request_inet: request from port '46168'



This thread was automatically locked due to age.
Parents
  • 0

    Hi, 

    Thank you for your reply.

    Can you share your Case ID:

    The case ID is this one: 03717044.

    How many users use SSL VPN and do they disconnect at the same time?

    All of users in VPN are disconnected at the same time (in sslvpn logs) But on-site users do not lose the internet connection and Sophos does not detect any disconnection either.

    Can you provide the output of # ls -lh /var/cores.

    Sure:

    There is just one file.

    -rw------- 1 root 0 19.9M Sep 21 2018 core.sandbox_reportd

    Thank you so much for your help.

    Your faithfully,

    Raphaelle

  • 0 in reply to RaphaelleB

    Hello Raphaelle,

    Thank you for the Case ID and the output of the command.

    Can you confirm if you’re now running 18 MR4?

    And how many users use the SSL VPN?

    Regards,

Reply Children
  • 0 in reply to emmosophos

    Hello,

    Yes, My colleague did the update a while ago to see if it would fix the problem but it only made the problem worse.

    My client has about 5 simultaneous VPN users.

    And my case was escalated to Engineer support.

    I hope they will find a solution.

    Best regards,

    Raphaelle

  • 0 in reply to RaphaelleB

    Hello there,

    Thank you for the follow-up.

    Can you share the Case ID with me so I can follow.

    Regards,

  • 0 in reply to emmosophos

    Hello,

    You can't see my case if i transmitted only Case ID ?

    This is this one: 03717044.

    Regards,

    Raphaelle

  • 0 in reply to RaphaelleB

    Hello Raphaelle,

    Thank you again for the Case ID.

    Sorry, I might have missed when you first shared. 

    Checking on the case I can see your case is with our GES team, you should be hearing from them by Monday 29.

    Regards,

  • 0 in reply to emmosophos

    Hello,

    Small update of the issue:
    The sophos technicians tested with an account of their own and were unable to solve the problem.

    On my side, I created a new user who did not log out during the day while the other users logged out. I recreated the account of a user who however had disconnections.

    We have found that those who log out seem to be connected to the remote desktop on the site's TSE server.
    We do not administer their servers but on the firewall I see nothing significant that could be the source of the problem. Even on the log files.

    Do you have any suggestions for me?

    Here, you can see:

    access_server log at the time of disconnections :

    MESSAGE Apr 28 12:13:17.551013 [CAA]: (CA_keep_alive): Next CA batch in 45 seconds
    ERROR Apr 28 12:13:33.095088 [access_server]: pg_db_handle_check_crt_fingerprint: row count: 1 value 1
    ERROR Apr 28 12:13:33.096171 [POSTGRES_DB]: pg_db_handle_sslvpn_max_allowed: row count: 0
    ERROR Apr 28 12:13:36.726745 [access_server]: pg_db_handle_check_crt_fingerprint: row count: 1 value 1
    ERROR Apr 28 12:13:36.727825 [POSTGRES_DB]: pg_db_handle_sslvpn_max_allowed: row count: 0
    ERROR Apr 28 12:13:39.928384 [access_server]: pg_db_handle_check_crt_fingerprint: row count: 1 value 1
    ERROR Apr 28 12:13:39.929419 [POSTGRES_DB]: pg_db_handle_sslvpn_max_allowed: row count: 0

    MESSAGE Apr 28 12:14:02.594952 [CAA]: (CA_keep_alive): access_server heartbeat
    MESSAGE Apr 28 12:14:02.595002 [CAA]: (CA_keep_alive): Next CA batch in 45 seconds
    MESSAGE Apr 28 12:14:04.261138 [access_server]: tlvserver_process_request: GOT ALERT.EXECUTE_HEARTBEAT
    MESSAGE Apr 28 12:14:47.638942 [CAA]: (CA_keep_alive): access_server heartbeat
    MESSAGE Apr 28 12:14:47.638990 [CAA]: (CA_keep_alive): Next CA batch in 45 seconds
    MESSAGE Apr 28 12:15:03.849040 [access_server]: tlvserver_process_request: GOT ALERT.EXECUTE_HEARTBEAT

    sslvpn log file:

    Wed Apr 28 12:13:12 2021 [11765] CID is :4136
    Wed Apr 28 12:13:12 2021 [11765] CID is :4138
    Wed Apr 28 12:13:16 2021 [11765] user1@xxxx.fr/::ffff:X.X.X.X Connection reset, restarting [-1]
    Wed Apr 28 12:13:16 2021 [11765] user1@xxxx.fr/::ffff:X.X.X.X SIGUSR1[soft,connection-reset] received, client-instance restarting
    Authentication server 127.0.0.1 gave login response code 2
    GARNER: log disconnect event: username=user1@xxxx.fr
    Wed Apr 28 12:13:16 2021 [11765] PLUGIN_CALL: POST /lib/openvpn-plugin-utm.so/PLUGIN_CLIENT_DISCONNECT status=0
    grep: /tmp/openvpn/serverusers.conf: No such file or directory
    DELETE 1
    COMMIT
    ipset v6.38: Element cannot be deleted from the set: it's not added
    ipset v6.38: Element cannot be deleted from the set: it's not added
    ipset v6.38: Element cannot be deleted from the set: it's not added
    Wed Apr 28 12:13:16 2021 [11765] WARNING: Failed running command (--client-disconnect): external program exited with error status: 1
    Wed Apr 28 12:13:16 2021 [11765] user2@xxxx.fr/::ffff:X.X.X.X Connection reset, restarting [-1]
    Wed Apr 28 12:13:16 2021 [11765] user2@xxxx.fr/::ffff:X.X.X.X SIGUSR1[soft,connection-reset] received, client-instance restarting
    Authentication server 127.0.0.1 gave login response code 2
    GARNER: log disconnect event: username=user2@xxxx.fr
    Wed Apr 28 12:13:16 2021 [11765] PLUGIN_CALL: POST /lib/openvpn-plugin-utm.so/PLUGIN_CLIENT_DISCONNECT status=0
    grep: /tmp/openvpn/serverusers.conf: No such file or directory
    DELETE 1
    COMMIT
    ipset v6.38: Element cannot be deleted from the set: it's not added
    ipset v6.38: Element cannot be deleted from the set: it's not added
    ipset v6.38: Element cannot be deleted from the set: it's not added
    Wed Apr 28 12:13:16 2021 [11765] WARNING: Failed running command (--client-disconnect): external program exited with error status: 1
    Wed Apr 28 12:13:16 2021 [11765] user3@xxxx.fr/::ffff:X.X.X.X Connection reset, restarting [-1]
    Wed Apr 28 12:13:16 2021 [11765] user3@xxxx.fr/::ffff:X.X.X.X SIGUSR1[soft,connection-reset] received, client-instance restarting
    Authentication server 127.0.0.1 gave login response code 2
    GARNER: log disconnect event: username=user3@xxxx.fr
    Wed Apr 28 12:13:17 2021 [11765] PLUGIN_CALL: POST /lib/openvpn-plugin-utm.so/PLUGIN_CLIENT_DISCONNECT status=0
    grep: /tmp/openvpn/serverusers.conf: No such file or directory
    DELETE 1
    COMMIT
    ipset v6.38: Element cannot be deleted from the set: it's not added
    ipset v6.38: Element cannot be deleted from the set: it's not added
    ipset v6.38: Element cannot be deleted from the set: it's not added
    Wed Apr 28 12:13:17 2021 [11765] WARNING: Failed running command (--client-disconnect): external program exited with error status: 1
    Wed Apr 28 12:13:24 2021 [11765] CID is :4136
    Wed Apr 28 12:13:30 2021 [11765] TCP connection established with [AF_INET6]::ffff:X.X.X.X:45563
    Wed Apr 28 12:13:30 2021 [11765] ::ffff:X.X.X.X TLS: Initial packet from [AF_INET6]::ffff:X.X.X.X:45563, sid=558d7dde e953a7f5
    Wed Apr 28 12:13:32 2021 [11765] ::ffff:X.X.X.X VERIFY OK: depth=1, C=FR, ST=NA, L=NA, O=XXXXX, OU=OU, CN=Sophos_CA_XXXXXX, emailAddress=user1@XXXX.fr
    Wed Apr 28 12:13:32 2021 [11765] ::ffff:X.X.X.X VERIFY OK: depth=0, C=FR, ST=NA, L=NA, O=MONETIK, OU=OU, CN=user1@XXXX.fr_167D0157D10, emailAddress=user5@XXXX.fr
    Wed Apr 28 12:13:33 2021 [11765] Error: cannot open /tmp/openvpn/serverusers.conf to verify user
    Wed Apr 28 12:13:33 2021 [11765] ::ffff:X.X.X.X PLUGIN_CALL: POST /lib/openvpn-plugin-utm.so/PLUGIN_AUTH_USER_PASS_VERIFY status=2
    Wed Apr 28 12:13:33 2021 [11765] ::ffff:X.X.X.X TLS: Username/Password authentication deferred for username 'user1@XXXX.Fr' [CN SET]
    Wed Apr 28 12:13:33 2021 [11765] ::ffff:X.X.X.X Data Channel Encrypt: Cipher 'AES-128-CBC' initialized with 128 bit key
    Wed Apr 28 12:13:33 2021 [11765] ::ffff:X.X.X.X Data Channel Encrypt: Using 256 bit message hash 'SHA256' for HMAC authentication
    Wed Apr 28 12:13:33 2021 [11765] ::ffff:X.X.X.X Data Channel Decrypt: Cipher 'AES-128-CBC' initialized with 128 bit key
    Wed Apr 28 12:13:33 2021 [11765] ::ffff:X.X.X.X Data Channel Decrypt: Using 256 bit message hash 'SHA256' for HMAC authentication
    Wed Apr 28 12:13:33 2021 [11765] ::ffff:X.X.X.X Control Channel: TLSv1.2, cipher TLSv1/SSLv3 DHE-RSA-AES256-GCM-SHA384, 2048 bit RSA
    Wed Apr 28 12:13:33 2021 [11765] ::ffff:X.X.X.X [user1@XXXX.Fr] Peer Connection Initiated with [AF_INET6]::ffff:X.X.X.X:45563
    Wed Apr 28 12:13:34 2021 [11765] user1@XXXX.fr/::ffff:X.X.X.X OPTIONS IMPORT: reading client specific options from: /cfs/system/openvpn/conf.d/user1@XXXXX.fr
    Wed Apr 28 12:13:35 2021 [11765] user1@XXXX.fr/::ffff:X.X.X.X MULTI_sva: pool returned IPv4=privateIP.X.X.X, IPv6=2001:db8::1:1
    Wed Apr 28 12:13:35 2021 [11765] user1@XXXX.fr/::ffff:X.X.X.X ifconfig_pool_remote_ipv6:XXXXX
    Wed Apr 28 12:13:35 2021 [11765] user1@XXXX.fr/::ffff:X.X.X.X ifconfig_remote_ip: X.X.X.X, isipv4c: 1
    Authentication server 127.0.0.1 gave login response code 2
    Wed Apr 28 12:13:35 2021 [11765] user1@XXXX.fr/::ffff:X.X.X.X PLUGIN_CALL: POST /lib/openvpn-plugin-utm.so/PLUGIN_CLIENT_CONNECT status=0
    Wed Apr 28 12:13:35 2021 [11765] user1@XXXX.fr/::ffff:X.X.X.X OPTIONS IMPORT: reading client specific options from: /tmp/openvpn_cc_52a92cc7263378c23917824d4f72a094.tmp
    Wed Apr 28 12:13:35 2021 [11765] user1@XXXX.fr/::ffff:X.X.X.X ifconfig_pool_remote_ipv6:XXXXX
    Wed Apr 28 12:13:35 2021 [11765] user1@XXXX.fr/::ffff:X.X.X.X ifconfig_remote_ip: X.X.X.X, isipv4c: 1
    grep: /tmp/openvpn/serverusers.conf: No such file or directory
    INSERT 0 1
    COMMIT
    script ipv4 -->
    ipset v6.38: Element cannot be deleted from the set: it's not added
    ipset v6.38: Element cannot be deleted from the set: it's not added
    ipset v6.38: Element cannot be deleted from the set: it's not added
    script ipv4 <--
    Wed Apr 28 12:13:35 2021 [11765] user1@XXXX.fr/::ffff:X.X.X.X OPTIONS IMPORT: reading client specific options from: /tmp/openvpn_cc_0483a11c1382e430ce520f43b0a8f45b.tmp
    Wed Apr 28 12:13:35 2021 [11765] user1@XXXX.fr/::ffff:X.X.X.X ifconfig_pool_remote_ipv6:X.X.X.X
    Wed Apr 28 12:13:35 2021 [11765] user1@XXXX.fr/::ffff:X.X.X.X ifconfig_remote_ip: X.X.X.X, isipv4c: 1
    Wed Apr 28 12:13:35 2021 [11765] user1@XXXX.fr/::ffff:X.X.X.X MULTI: Learn: X.X.X.X -> user1@XXXX.fr/::ffff:X.X.X.X
    Wed Apr 28 12:13:35 2021 [11765]user1@XXXX.fr/::ffff:X.X.X.X MULTI: primary virtual IP for user1@XXXX.fr/::ffff:X.X.X.X: X.X.X.X
    Wed Apr 28 12:13:35 2021 [11765] user1@XXXX.fr/::ffff:X.X.X.X MULTI: Learn: X.X.X.X -> user1@XXXX.fr/::ffff:X.X.X.X
    Wed Apr 28 12:13:35 2021 [11765] user1@XXXX.fr/::ffff:X.X.X.X MULTI: primary virtual IPv6 for user1@XXXX.fr/::ffff:X.X.X.X: X.X.X.X
    Wed Apr 28 12:13:35 2021 [11765] CID is :4140
    Wed Apr 28 12:13:35 2021 [11765] CID is :4136
    Wed Apr 28 12:13:35 2021 [11765] user1@XXXX.fr/::ffff:X.X.X.X PUSH: Received control message: 'PUSH_REQUEST'
    Wed Apr 28 12:13:35 2021 [11765] user1@XXXX.fr/::ffff:X.X.X.X send_push_reply(): safe_cap=940
    Wed Apr 28 12:13:35 2021 [11765] user1@XXXX.fr/::ffff:X.X.X.X Host:::ffff:X.X.X.X Port:45563
    Wed Apr 28 12:13:35 2021 [11765] user1@XXXX.fr/::ffff:X.X.X.X Is IPv4 :1
    Wed Apr 28 12:13:35 2021 [11765] user1@XXXX.fr/::ffff:X.X.X.X send_push_reply(): suppress sending 'tun-ipv6'
    Wed Apr 28 12:13:35 2021 [11765] user1@XXXX.fr/::ffff:X.X.X.X SENT CONTROL [olivier.cornec@monetik.fr]: 'PUSH_REPLY,route-gateway X.X.X.X,sndbuf 0,rcvbuf 0,sndbuf 0,rcvbuf 0,ping 450,ping-restart 1800,route 1X.X.X.X X.X.X.X,topology subnet,route remote_host X.X.X.X net_gateway,dhcp-option DNS X.X.X.X,dhcp-option DNS X.X.X.X,ifconfig X.X.X.X X.X.X.X' (status=1)

    (Same messages for other users)

  • 0 in reply to RaphaelleB

    Hello,

    For the user that is constantly failing, (I am not sure if GES has already suggested) If you change to use Sophos Connect (IPsec) does the issue is the same, can you test this way?

    Regards,