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

Sophos UTM Client VPN Error (Authenticate/Decrypt packet error: packet HMAC authentication failed)

Hi we got the problem that all oure VPN-Client users get 3-6 Times a Day the following error:

Wed Mar 31 08:50:18 2021 Authenticate/Decrypt packet error: packet HMAC authentication failed
Wed Mar 31 08:50:18 2021 Fatal decryption error (process_incoming_link), restarting
Wed Mar 31 08:50:18 2021 SIGUSR1[soft,decryption-error] received, process restarting
Wed Mar 31 08:50:18 2021 MANAGEMENT: >STATE:1617173418,RECONNECTING,decryption-error,,,,,
Wed Mar 31 08:50:18 2021 Restart pause, 5 second(s)


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

    Hi ,

    Thank you for reaching out to Sophos Community.

    Wed Mar 31 08:50:18 2021 Authenticate/Decrypt packet error: packet HMAC authentication failed

    It seems this event is generated by the client itself. What does openvpn.log show at the time of instance?

    You may filter openvpn.log with date & time:

    ==> To check latest(present-day) events:

    utm:/root # cat /var/log/openvpn.log | grep -i "2021:04:21"          <== Date

    or 

    utm:/root # cat /var/log/openvpn.log | grep -i "2021:04:21-14:"          <== Date & time

    ==> To check archived events:

    utm:/root # zcat /var/log/openvpn/2021/04/openvpn-2021-04-20.log.gz | grep -i "2021:04:20"          <== Date

    or

    utm:/root # zcat /var/log/openvpn/2021/04/openvpn-2021-04-20.log.gz | grep -i "2021:04:20-16:"          <== Date & time

    There is also a ticket on OpenVPN: community.openvpn.net/.../543

  • Hello Yash Kothari,

    Thank you for your fast answer,

    UTM openvpn.log looks like:

    2021:03:31-08:50:18 sophos01-2 openvpn[12381]: adm_os/92.206.xxx.xxx:55323 Connection reset, restarting [-1]
    2021:03:31-08:50:18 sophos01-2 openvpn[12381]: adm_os/92.206.xxx.xxx:55323 SIGUSR1[soft,connection-reset] received, client-instance restarting
    2021:03:31-08:50:18 sophos01-2 openvpn[12381]: id="2202" severity="info" sys="SecureNet" sub="vpn" event="Connection terminated" username="adm_os" variant="ssl" srcip="92.206.xxx.xxx" virtual_ip="10.250.xxx.xxx" rx="16796009" tx="267233086"
    2021:03:31-08:50:18 sophos01-2 openvpn[12381]: PLUGIN_CALL: POST /usr/lib/openvpn/plugins/openvpn-plugin-utm.so/PLUGIN_CLIENT_DISCONNECT status=0
    2021:03:31-08:50:34 sophos01-2 openvpn[12381]: TCP connection established with [AF_INET]92.206.xxx.xxx:62032 (via [AF_INET]80.208.xxx.xxx:443)
    2021:03:31-08:50:35 sophos01-2 openvpn[12381]: 92.206.xxx.xx:62032 TLS: Initial packet from [AF_INET]92.296.xxx.xx:62032 (via [AF_INET]80.208.xxx.xxx:443), sid=c2a869bd 3a0aea57
    2021:03:31-08:50:36 sophos01-2 openvpn[12381]: 92.206.xxx.xx:62032 VERIFY OK: depth=0, C=de, L=, O=, CN=ADM
    2021:03:31-08:50:36 sophos01-2 openvpn[12381]: 92.206.xxx.xx:62032 VERIFY OK: depth=1, C=de, L=, O=
    2021:03:31-08:50:36 sophos01-2 openvpn[12381]: 92.206.xxx.xx:62032 VERIFY OK: depth=1, C=de, L=, O=
    2021:03:31-08:50:36 sophos01-2 openvpn[12381]: 92.206.xxx.xx:62032 VERIFY OK: depth=0, C=de, L=, O=
    2021:03:31-08:50:36 sophos01-2 openvpn[12381]: 92.206.xxx.xx:62032 PLUGIN_CALL: POST /usr/lib/openvpn/plugins/openvpn-plugin-utm.so/PLUGIN_AUTH_USER_PASS_VERIFY status=2
    2021:03:31-08:50:36 sophos01-2 openvpn[12381]: 92.206.xxx.xx:62032 TLS: Username/Password authentication deferred for username 'adm_os' [CN SET]
    2021:03:31-08:50:36 sophos01-2 openvpn[12381]: 92.206.xxx.xx:62032 Data Channel Encrypt: Cipher 'AES-128-CBC' initialized with 128 bit key
    2021:03:31-08:50:36 sophos01-2 openvpn[12381]: 92.206.xxx.xx:62032 Data Channel Encrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
    2021:03:31-08:50:36 sophos01-2 openvpn[12381]: 92.206.xxx.xx:62032 Data Channel Decrypt: Cipher 'AES-128-CBC' initialized with 128 bit key
    2021:03:31-08:50:36 sophos01-2 openvpn[12381]: 92.206.xxx.xx:62032 Data Channel Decrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
    2021:03:31-08:50:36 sophos01-2 openvpn[12381]: 92.206.xxx.xx:62032 Control Channel: TLSv1.2, cipher TLSv1/SSLv3 DHE-RSA-AES256-GCM-SHA384, 2048 bit RSA
    2021:03:31-08:50:36 sophos01-2 openvpn[12381]: 92.206.xxx.xx:62032 [adm_os] Peer Connection Initiated with [AF_INET]92.296.xxx.xx:62032 (via [AF_INET]80.208.xxx.xxx:443)
    2021:03:31-08:50:36 sophos01-2 openvpn[12381]: 92.206.xxx.xx:62032 TLS Error: local/remote TLS keys are out of sync: [AF_INET]92.206.xxx.xx:62032 (via [AF_INET]80.208.xxx.xxx:443) [0]
    2021:03:31-08:50:36 sophos01-2 openvpn[12381]: 92.206.xxx.xx:62032 TLS Error: local/remote TLS keys are out of sync: [AF_INET]92.206.xxx.xx:62032 (via [AF_INET]80.208.xxx.xxx:443) [0]
    2021:03:31-08:50:37 sophos01-2 openvpn[12381]: 92.206.xxx.xx:62032 TLS Error: local/remote TLS keys are out of sync: [AF_INET]92.206.xxx.xx:62032 (via [AF_INET]80.208.xxx.xxx:443) [0]
    2021:03:31-08:50:37 sophos01-2 openvpn[12381]: adm_os/92.206.xxx.xx:62032 OPTIONS IMPORT: reading client specific options from: /etc/openvpn/conf.d/adm_os
    2021:03:31-08:50:37 sophos01-2 openvpn[12381]: adm_os/92.206.xxx.xx:62032 MULTI_sva: pool returned IPv4=10.250.xxx.xxx, IPv6=(Not enabled)
    2021:03:31-08:50:37 sophos01-2 openvpn[12381]: id="2201" severity="info" sys="SecureNet" sub="vpn" event="Connection started" username="adm_os" variant="ssl" srcip="92.206.xxx.xx" virtual_ip="10.250.xxx.xxx"
    2021:03:31-08:50:37 sophos01-2 openvpn[12381]: adm_os/92.206.xxx.xx:62032 PLUGIN_CALL: POST /usr/lib/openvpn/plugins/openvpn-plugin-utm.so/PLUGIN_CLIENT_CONNECT status=0
    2021:03:31-08:50:37 sophos01-2 openvpn[12381]: adm_os/92.206.xxx.xx:62032 OPTIONS IMPORT: reading client specific options from: /tmp/openvpn_cc_00c2cb5f631d4fff21fa1ea4dc958e69.tmp
    2021:03:31-08:50:37 sophos01-2 openvpn[12381]: adm_os/92.206.xxx.xx:62032 MULTI: Learn: 10.250.xxx.xxx -> adm_os/92.206.xxx.xx:62032
    2021:03:31-08:50:37 sophos01-2 openvpn[12381]: adm_os/92.206.xxx.xx:62032 MULTI: primary virtual IP for adm_os/92.206.xxx.xx:62032: 10.250.xxx.xxx
    2021:03:31-08:50:38 sophos01-2 openvpn[12381]: adm_os/92.206.xxx.xx:62032 PUSH: Received control message: 'PUSH_REQUEST'
    2021:03:31-08:50:38 sophos01-2 openvpn[12381]: adm_os/92.206.xxx.xx:62032 send_push_reply(): safe_cap=940

Reply
  • Hello Yash Kothari,

    Thank you for your fast answer,

    UTM openvpn.log looks like:

    2021:03:31-08:50:18 sophos01-2 openvpn[12381]: adm_os/92.206.xxx.xxx:55323 Connection reset, restarting [-1]
    2021:03:31-08:50:18 sophos01-2 openvpn[12381]: adm_os/92.206.xxx.xxx:55323 SIGUSR1[soft,connection-reset] received, client-instance restarting
    2021:03:31-08:50:18 sophos01-2 openvpn[12381]: id="2202" severity="info" sys="SecureNet" sub="vpn" event="Connection terminated" username="adm_os" variant="ssl" srcip="92.206.xxx.xxx" virtual_ip="10.250.xxx.xxx" rx="16796009" tx="267233086"
    2021:03:31-08:50:18 sophos01-2 openvpn[12381]: PLUGIN_CALL: POST /usr/lib/openvpn/plugins/openvpn-plugin-utm.so/PLUGIN_CLIENT_DISCONNECT status=0
    2021:03:31-08:50:34 sophos01-2 openvpn[12381]: TCP connection established with [AF_INET]92.206.xxx.xxx:62032 (via [AF_INET]80.208.xxx.xxx:443)
    2021:03:31-08:50:35 sophos01-2 openvpn[12381]: 92.206.xxx.xx:62032 TLS: Initial packet from [AF_INET]92.296.xxx.xx:62032 (via [AF_INET]80.208.xxx.xxx:443), sid=c2a869bd 3a0aea57
    2021:03:31-08:50:36 sophos01-2 openvpn[12381]: 92.206.xxx.xx:62032 VERIFY OK: depth=0, C=de, L=, O=, CN=ADM
    2021:03:31-08:50:36 sophos01-2 openvpn[12381]: 92.206.xxx.xx:62032 VERIFY OK: depth=1, C=de, L=, O=
    2021:03:31-08:50:36 sophos01-2 openvpn[12381]: 92.206.xxx.xx:62032 VERIFY OK: depth=1, C=de, L=, O=
    2021:03:31-08:50:36 sophos01-2 openvpn[12381]: 92.206.xxx.xx:62032 VERIFY OK: depth=0, C=de, L=, O=
    2021:03:31-08:50:36 sophos01-2 openvpn[12381]: 92.206.xxx.xx:62032 PLUGIN_CALL: POST /usr/lib/openvpn/plugins/openvpn-plugin-utm.so/PLUGIN_AUTH_USER_PASS_VERIFY status=2
    2021:03:31-08:50:36 sophos01-2 openvpn[12381]: 92.206.xxx.xx:62032 TLS: Username/Password authentication deferred for username 'adm_os' [CN SET]
    2021:03:31-08:50:36 sophos01-2 openvpn[12381]: 92.206.xxx.xx:62032 Data Channel Encrypt: Cipher 'AES-128-CBC' initialized with 128 bit key
    2021:03:31-08:50:36 sophos01-2 openvpn[12381]: 92.206.xxx.xx:62032 Data Channel Encrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
    2021:03:31-08:50:36 sophos01-2 openvpn[12381]: 92.206.xxx.xx:62032 Data Channel Decrypt: Cipher 'AES-128-CBC' initialized with 128 bit key
    2021:03:31-08:50:36 sophos01-2 openvpn[12381]: 92.206.xxx.xx:62032 Data Channel Decrypt: Using 160 bit message hash 'SHA1' for HMAC authentication
    2021:03:31-08:50:36 sophos01-2 openvpn[12381]: 92.206.xxx.xx:62032 Control Channel: TLSv1.2, cipher TLSv1/SSLv3 DHE-RSA-AES256-GCM-SHA384, 2048 bit RSA
    2021:03:31-08:50:36 sophos01-2 openvpn[12381]: 92.206.xxx.xx:62032 [adm_os] Peer Connection Initiated with [AF_INET]92.296.xxx.xx:62032 (via [AF_INET]80.208.xxx.xxx:443)
    2021:03:31-08:50:36 sophos01-2 openvpn[12381]: 92.206.xxx.xx:62032 TLS Error: local/remote TLS keys are out of sync: [AF_INET]92.206.xxx.xx:62032 (via [AF_INET]80.208.xxx.xxx:443) [0]
    2021:03:31-08:50:36 sophos01-2 openvpn[12381]: 92.206.xxx.xx:62032 TLS Error: local/remote TLS keys are out of sync: [AF_INET]92.206.xxx.xx:62032 (via [AF_INET]80.208.xxx.xxx:443) [0]
    2021:03:31-08:50:37 sophos01-2 openvpn[12381]: 92.206.xxx.xx:62032 TLS Error: local/remote TLS keys are out of sync: [AF_INET]92.206.xxx.xx:62032 (via [AF_INET]80.208.xxx.xxx:443) [0]
    2021:03:31-08:50:37 sophos01-2 openvpn[12381]: adm_os/92.206.xxx.xx:62032 OPTIONS IMPORT: reading client specific options from: /etc/openvpn/conf.d/adm_os
    2021:03:31-08:50:37 sophos01-2 openvpn[12381]: adm_os/92.206.xxx.xx:62032 MULTI_sva: pool returned IPv4=10.250.xxx.xxx, IPv6=(Not enabled)
    2021:03:31-08:50:37 sophos01-2 openvpn[12381]: id="2201" severity="info" sys="SecureNet" sub="vpn" event="Connection started" username="adm_os" variant="ssl" srcip="92.206.xxx.xx" virtual_ip="10.250.xxx.xxx"
    2021:03:31-08:50:37 sophos01-2 openvpn[12381]: adm_os/92.206.xxx.xx:62032 PLUGIN_CALL: POST /usr/lib/openvpn/plugins/openvpn-plugin-utm.so/PLUGIN_CLIENT_CONNECT status=0
    2021:03:31-08:50:37 sophos01-2 openvpn[12381]: adm_os/92.206.xxx.xx:62032 OPTIONS IMPORT: reading client specific options from: /tmp/openvpn_cc_00c2cb5f631d4fff21fa1ea4dc958e69.tmp
    2021:03:31-08:50:37 sophos01-2 openvpn[12381]: adm_os/92.206.xxx.xx:62032 MULTI: Learn: 10.250.xxx.xxx -> adm_os/92.206.xxx.xx:62032
    2021:03:31-08:50:37 sophos01-2 openvpn[12381]: adm_os/92.206.xxx.xx:62032 MULTI: primary virtual IP for adm_os/92.206.xxx.xx:62032: 10.250.xxx.xxx
    2021:03:31-08:50:38 sophos01-2 openvpn[12381]: adm_os/92.206.xxx.xx:62032 PUSH: Received control message: 'PUSH_REQUEST'
    2021:03:31-08:50:38 sophos01-2 openvpn[12381]: adm_os/92.206.xxx.xx:62032 send_push_reply(): safe_cap=940

Children