Hello,
I have a problem with one user in Dubai that is not able to login via ssl-vpn with the 2 factor authentication. He was able to login sucessfully last Thursday.
I already checked that the number generator is in sync.
I checked his account. It is not locked.
We tried a connection via cellphone and regular internet connection. Both failed.
There are several people logged in right now and there are no known problems from other persons.
The connection seems to fail in one of the last stages. Below you find the entries of the livelog of one try going through the internet connection and the other try going to the cellphone hotspot. Furtermore the end of the local log of the client.
Do you have any idea what's going wrong?
2018:01:09-12:16:46 vpn2-1 openvpn[12594]: 80.227.140.50:59113 TLS: Initial packet from [AF_INET]80.227.140.50:59113 (via [AF_INET] xx.xx.xx.xx:443), sid=891b68f6 95c2b67e
2018:01:09-12:16:49 vpn2-1 openvpn[12594]: 80.227.140.50:59113 VERIFY OK: depth=0, C=de, L=Wuppertal, O=RIEDEL Communications GmbH & Co. KG, CN=Mohamed Hammad (Riedel), emailAddress=Mohamed.Hammad@riedel.net
2018:01:09-12:16:49 vpn2-1 openvpn[12594]: 80.227.140.50:59113 VERIFY OK: depth=1, C=de, L=Wuppertal, O=RIEDEL Communications GmbH & Co. KG, CN=RIEDEL Communications GmbH & Co. KG VPN CA, emailAddress=bernd.feist@riedel.net
2018:01:09-12:16:49 vpn2-1 openvpn[12594]: 80.227.140.50:59113 VERIFY OK: depth=1, C=de, L=Wuppertal, O=RIEDEL Communications GmbH & Co. KG, CN=RIEDEL Communications GmbH & Co. KG VPN CA, emailAddress=bernd.feist@riedel.net
2018:01:09-12:16:49 vpn2-1 openvpn[12594]: 80.227.140.50:59113 VERIFY OK: depth=0, C=de, L=Wuppertal, O=RIEDEL Communications GmbH & Co. KG, CN=Mohamed Hammad (Riedel), emailAddress=Mohamed.Hammad@riedel.net
2018:01:09-12:16:51 vpn2-1 openvpn[12594]: 80.227.140.50:59113 PLUGIN_CALL: POST /usr/lib/openvpn/plugins/openvpn-plugin-utm.so/PLUGIN_AUTH_USER_PASS_VERIFY status=2
2018:01:09-12:16:51 vpn2-1 openvpn[12594]: 80.227.140.50:59113 TLS: Username/Password authentication deferred for username 'Hammad' [CN SET]
2018:01:09-12:16:51 vpn2-1 openvpn[12594]: 80.227.140.50:59113 Data Channel Encrypt: Cipher 'AES-256-CBC' initialized with 256 bit key
2018:01:09-12:16:51 vpn2-1 openvpn[12594]: 80.227.140.50:59113 Data Channel Encrypt: Using 256 bit message hash 'SHA256' for HMAC authentication
2018:01:09-12:16:51 vpn2-1 openvpn[12594]: 80.227.140.50:59113 Data Channel Decrypt: Cipher 'AES-256-CBC' initialized with 256 bit key
2018:01:09-12:16:51 vpn2-1 openvpn[12594]: 80.227.140.50:59113 Data Channel Decrypt: Using 256 bit message hash 'SHA256' for HMAC authentication
2018:01:09-12:16:52 vpn2-1 openvpn[12594]: 80.227.140.50:59113 Control Channel: TLSv1.2, cipher TLSv1/SSLv3 DHE-RSA-AES256-GCM-SHA384, 2048 bit RSA
2018:01:09-12:16:52 vpn2-1 openvpn[12594]: 80.227.140.50:59113 [Hammad] Peer Connection Initiated with [AF_INET]80.227.140.50:59113 (via [AF_INET]84.246.251.196:443)
2018:01:09-12:16:53 vpn2-1 openvpn[12594]: hammad/80.227.140.50:59113 OPTIONS IMPORT: reading client specific options from: /etc/openvpn/conf.d/hammad
2018:01:09-12:16:53 vpn2-1 openvpn[12594]: hammad/80.227.140.50:59113 MULTI_sva: pool returned IPv4=10.22.192.10, IPv6=(Not enabled)
2018:01:09-12:16:53 vpn2-1 openvpn[12594]: id="2201" severity="info" sys="SecureNet" sub="vpn" event="Connection started" username="Hammad" variant="ssl" srcip="80.227.140.50" virtual_ip="10.22.192.10"
2018:01:09-12:16:53 vpn2-1 openvpn[12594]: hammad/80.227.140.50:59113 PLUGIN_CALL: POST /usr/lib/openvpn/plugins/openvpn-plugin-utm.so/PLUGIN_CLIENT_CONNECT status=0
2018:01:09-12:16:53 vpn2-1 openvpn[12594]: hammad/80.227.140.50:59113 OPTIONS IMPORT: reading client specific options from: /tmp/openvpn_cc_0e274b5ec405f67f6d33c80a76777d0b.tmp
2018:01:09-12:16:53 vpn2-1 openvpn[12594]: hammad/80.227.140.50:59113 MULTI: Learn: 10.22.192.10 -> hammad/80.227.140.50:59113
2018:01:09-12:16:53 vpn2-1 openvpn[12594]: hammad/80.227.140.50:59113 MULTI: primary virtual IP for hammad/80.227.140.50:59113: 10.22.192.10
2018:01:09-12:16:55 vpn2-1 openvpn[12594]: hammad/80.227.140.50:59113 PUSH: Received control message: 'PUSH_REQUEST'
2018:01:09-12:16:55 vpn2-1 openvpn[12594]: hammad/80.227.140.50:59113 send_push_reply(): safe_cap=940
2018:01:09-12:16:55 vpn2-1 openvpn[12594]: hammad/80.227.140.50:59113 SENT CONTROL [hammad]: 'PUSH_REPLY,route-gateway 10.22.192.1,route-gateway 10.22.192.1,topology subnet,ping 10,ping-restart 120,route 10.22.208.0 255.255.240.0,route 192.168.6.0 255.255.255.0,route 10.20.40.0 255.255.255.0,route 192.168.78.0 255.255.255.0,route 192.168.123.0 255.255.255.0,route 10.30.0.0 255.255.0.0,route 84.246.251.192 255.255.255.224,route 84.246.251.64 255.255.255.224,route 172.21.8.0 255.255.255.0,route 10.22.1.248 255.255.255.248,route 192.168.5.0 255.255.255.0,route 192.168.1.0 255.255.255.0,route 172.21.9.0 255.255.255.0,route 172.21.12.0 255.255.255.0,route 10.22.192.0 255.255.255.0,route 10.23.0.0 255.255.0.0,dhcp-option DNS 172.21.9.5,dhcp-option DNS 192.168.1.212,dhcp-option DOMAIN riedel.net,ifconfig 10.22.192.10 255.255.255.0' (status=1)
2018:01:09-12:17:16 vpn2-1 openvpn[12594]: hammad/80.227.140.50:59113 Connection reset, restarting [-1]
2018:01:09-12:17:16 vpn2-1 openvpn[12594]: hammad/80.227.140.50:59113 SIGUSR1[soft,connection-reset] received, client-instance restarting
2018:01:09-12:17:16 vpn2-1 openvpn[12594]: id="2202" severity="info" sys="SecureNet" sub="vpn" event="Connection terminated" username="Hammad" variant="ssl" srcip="80.227.140.50" virtual_ip="10.22.192.10" rx="4338" tx="10318"
2018:01:09-12:17:16 vpn2-1 openvpn[12594]: PLUGIN_CALL: POST /usr/lib/openvpn/plugins/openvpn-plugin-utm.so/PLUGIN_CLIENT_DISCONNECT status=0
2018:01:09-12:27:58 vpn2-1 openvpn[12594]: TCP connection established with [AF_INET]176.204.148.253:56087 (via [AF_INET] xx.xx.xx.xx:443)
2018:01:09-12:27:59 vpn2-1 openvpn[12594]: 176.204.148.253:56087 TLS: Initial packet from [AF_INET]176.204.148.253:56087 (via [AF_INET]84.246.251.196:443), sid=78cca1ec 369a0bef
2018:01:09-12:28:05 vpn2-1 openvpn[12594]: 176.204.148.253:56087 VERIFY OK: depth=0, C=de, L=Wuppertal, O=RIEDEL Communications GmbH & Co. KG, CN=Mohamed Hammad (Riedel), emailAddress=Mohamed.Hammad@riedel.net
2018:01:09-12:28:05 vpn2-1 openvpn[12594]: 176.204.148.253:56087 VERIFY OK: depth=1, C=de, L=Wuppertal, O=RIEDEL Communications GmbH & Co. KG, CN=RIEDEL Communications GmbH & Co. KG VPN CA, emailAddress=bernd.feist@riedel.net
2018:01:09-12:28:05 vpn2-1 openvpn[12594]: 176.204.148.253:56087 VERIFY OK: depth=1, C=de, L=Wuppertal, O=RIEDEL Communications GmbH & Co. KG, CN=RIEDEL Communications GmbH & Co. KG VPN CA, emailAddress=bernd.feist@riedel.net
2018:01:09-12:28:05 vpn2-1 openvpn[12594]: 176.204.148.253:56087 VERIFY OK: depth=0, C=de, L=Wuppertal, O=RIEDEL Communications GmbH & Co. KG, CN=Mohamed Hammad (Riedel), emailAddress=Mohamed.Hammad@riedel.net
2018:01:09-12:28:08 vpn2-1 openvpn[12594]: 176.204.148.253:56087 PLUGIN_CALL: POST /usr/lib/openvpn/plugins/openvpn-plugin-utm.so/PLUGIN_AUTH_USER_PASS_VERIFY status=2
2018:01:09-12:28:08 vpn2-1 openvpn[12594]: 176.204.148.253:56087 TLS: Username/Password authentication deferred for username 'Hammad' [CN SET]
2018:01:09-12:28:08 vpn2-1 openvpn[12594]: 176.204.148.253:56087 Data Channel Encrypt: Cipher 'AES-256-CBC' initialized with 256 bit key
2018:01:09-12:28:08 vpn2-1 openvpn[12594]: 176.204.148.253:56087 Data Channel Encrypt: Using 256 bit message hash 'SHA256' for HMAC authentication
2018:01:09-12:28:08 vpn2-1 openvpn[12594]: 176.204.148.253:56087 Data Channel Decrypt: Cipher 'AES-256-CBC' initialized with 256 bit key
2018:01:09-12:28:08 vpn2-1 openvpn[12594]: 176.204.148.253:56087 Data Channel Decrypt: Using 256 bit message hash 'SHA256' for HMAC authentication
2018:01:09-12:28:09 vpn2-1 openvpn[12594]: 176.204.148.253:56087 Control Channel: TLSv1.2, cipher TLSv1/SSLv3 DHE-RSA-AES256-GCM-SHA384, 2048 bit RSA
2018:01:09-12:28:09 vpn2-1 openvpn[12594]: 176.204.148.253:56087 [Hammad] Peer Connection Initiated with [AF_INET]176.204.148.253:56087 (via [AF_INET]84.246.251.196:443)
2018:01:09-12:28:11 vpn2-1 openvpn[12594]: hammad/176.204.148.253:56087 OPTIONS IMPORT: reading client specific options from: /etc/openvpn/conf.d/hammad
2018:01:09-12:28:11 vpn2-1 openvpn[12594]: hammad/176.204.148.253:56087 MULTI_sva: pool returned IPv4=10.22.192.10, IPv6=(Not enabled)
2018:01:09-12:28:11 vpn2-1 openvpn[12594]: id="2201" severity="info" sys="SecureNet" sub="vpn" event="Connection started" username="Hammad" variant="ssl" srcip="176.204.148.253" virtual_ip="10.22.192.10"
2018:01:09-12:28:11 vpn2-1 openvpn[12594]: hammad/176.204.148.253:56087 PLUGIN_CALL: POST /usr/lib/openvpn/plugins/openvpn-plugin-utm.so/PLUGIN_CLIENT_CONNECT status=0
2018:01:09-12:28:11 vpn2-1 openvpn[12594]: hammad/176.204.148.253:56087 OPTIONS IMPORT: reading client specific options from: /tmp/openvpn_cc_2808f900d58c1fd5fddafd82e6ad73ce.tmp
2018:01:09-12:28:11 vpn2-1 openvpn[12594]: hammad/176.204.148.253:56087 MULTI: Learn: 10.22.192.10 -> hammad/176.204.148.253:56087
2018:01:09-12:28:11 vpn2-1 openvpn[12594]: hammad/176.204.148.253:56087 MULTI: primary virtual IP for hammad/176.204.148.253:56087: 10.22.192.10
2018:01:09-12:28:11 vpn2-1 openvpn[12594]: hammad/176.204.148.253:56087 PUSH: Received control message: 'PUSH_REQUEST'
2018:01:09-12:28:11 vpn2-1 openvpn[12594]: hammad/176.204.148.253:56087 send_push_reply(): safe_cap=940
2018:01:09-12:28:11 vpn2-1 openvpn[12594]: hammad/176.204.148.253:56087 SENT CONTROL [hammad]: 'PUSH_REPLY,route-gateway 10.22.192.1,route-gateway 10.22.192.1,topology subnet,ping 10,ping-restart 120,route 10.22.208.0 255.255.240.0,route 192.168.6.0 255.255.255.0,route 10.20.40.0 255.255.255.0,route 192.168.78.0 255.255.255.0,route 192.168.123.0 255.255.255.0,route 10.30.0.0 255.255.0.0,route 84.246.251.192 255.255.255.224,route 84.246.251.64 255.255.255.224,route 172.21.8.0 255.255.255.0,route 10.22.1.248 255.255.255.248,route 192.168.5.0 255.255.255.0,route 192.168.1.0 255.255.255.0,route 172.21.9.0 255.255.255.0,route 172.21.12.0 255.255.255.0,route 10.22.192.0 255.255.255.0,route 10.23.0.0 255.255.0.0,dhcp-option DNS 172.21.9.5,dhcp-option DNS 192.168.1.212,dhcp-option DOMAIN riedel.net,ifconfig 10.22.192.10 255.255.255.0' (status=1)
2018:01:09-12:28:33 vpn2-1 openvpn[12594]: hammad/176.204.148.253:56087 Connection reset, restarting [-1]
2018:01:09-12:28:33 vpn2-1 openvpn[12594]: hammad/176.204.148.253:56087 SIGUSR1[soft,connection-reset] received, client-instance restarting
2018:01:09-12:28:33 vpn2-1 openvpn[12594]: id="2202" severity="info" sys="SecureNet" sub="vpn" event="Connection terminated" username="Hammad" variant="ssl" srcip="176.204.148.253" virtual_ip="10.22.192.10" rx="4452" tx="7728"
2018:01:09-12:28:33 vpn2-1 openvpn[12594]: PLUGIN_CALL: POST /usr/lib/openvpn/plugins/openvpn-plugin-utm.so/PLUGIN_CLIENT_DISCONNECT status=0
Local Client log (different try):
....
Tue Jan 09 15:32:33 2018 SENT CONTROL [vpn2.riedel.net]: 'PUSH_REQUEST' (status=1)
Tue Jan 09 15:32:33 2018 PUSH: Received control message: 'PUSH_REPLY,route-gateway 10.22.192.1,route-gateway 10.22.192.1,topology subnet,ping 10,ping-restart 120,route 10.22.208.0 255.255.240.0,route 192.168.6.0 255.255.255.0,route 10.20.40.0 255.255.255.0,route 192.168.78.0 255.255.255.0,route 192.168.123.0 255.255.255.0,route 10.30.0.0 255.255.0.0,route 84.246.251.192 255.255.255.224,route 84.246.251.64 255.255.255.224,route 172.21.8.0 255.255.255.0,route 10.22.1.248 255.255.255.248,route 192.168.5.0 255.255.255.0,route 192.168.1.0 255.255.255.0,route 172.21.9.0 255.255.255.0,route 172.21.12.0 255.255.255.0,route 10.22.192.0 255.255.255.0,route 10.23.0.0 255.255.0.0,dhcp-option DNS 172.21.9.5,dhcp-option DNS 192.168.1.212,dhcp-option DOMAIN riedel.net,ifconfig 10.22.192.10 255.255.255.0'
Tue Jan 09 15:32:33 2018 OPTIONS IMPORT: timers and/or timeouts modified
Tue Jan 09 15:32:33 2018 OPTIONS IMPORT: --ifconfig/up options modified
Tue Jan 09 15:32:33 2018 OPTIONS IMPORT: route options modified
Tue Jan 09 15:32:33 2018 OPTIONS IMPORT: route-related options modified
Tue Jan 09 15:32:33 2018 OPTIONS IMPORT: --ip-win32 and/or --dhcp-option options modified
Tue Jan 09 15:32:33 2018 ROUTE_GATEWAY 192.168.0.1/255.255.255.0 I=14 HWADDR=80:00:0b:6b:2d:08
Tue Jan 09 15:32:33 2018 open_tun, tt->ipv6=0
Tue Jan 09 15:32:33 2018 TAP-WIN32 device [Local Area Connection 11] opened: \\.\Global\{206AF939-7574-44AE-861E-338CBFC10A4B}.tap
Tue Jan 09 15:32:33 2018 TAP-Windows Driver Version 9.21
Tue Jan 09 15:32:34 2018 NETSH: C:\Windows\system32\netsh.exe interface ip set address Local Area Connection 11 dhcp
Tue Jan 09 15:32:35 2018 ERROR: netsh command failed: returned error code 1
Tue Jan 09 15:32:40 2018 NETSH: C:\Windows\system32\netsh.exe interface ip set address Local Area Connection 11 dhcp
Tue Jan 09 15:32:40 2018 ERROR: netsh command failed: returned error code 1
Tue Jan 09 15:32:45 2018 NETSH: C:\Windows\system32\netsh.exe interface ip set address Local Area Connection 11 dhcp
Tue Jan 09 15:32:45 2018 ERROR: netsh command failed: returned error code 1
Tue Jan 09 15:32:50 2018 NETSH: C:\Windows\system32\netsh.exe interface ip set address Local Area Connection 11 dhcp
Tue Jan 09 15:32:50 2018 ERROR: netsh command failed: returned error code 1
Tue Jan 09 15:32:54 2018 MANAGEMENT: Client disconnected
Tue Jan 09 15:32:54 2018 NETSH: command failed
Tue Jan 09 15:32:54 2018 Exiting due to fatal error
Best regards,
Bernd Feist
This thread was automatically locked due to age.
