Express VPN Received control message: AUTH_FAILED

Jegavelan

Hi ,

I am having a hard time in setting up the ExpressVPN , getting the below error message. Reachout to their support , they said its something wrong setting on the pfsense.

May 26 15:00:23	openvpn	75963	VERIFY WARNING: depth=0, unable to get certificate CRL: C=VG, ST=BVI, O=ExpressVPN, OU=ExpressVPN, CN=Server-1417-1a, emailAddress=support@expressvpn.com
May 26 15:00:23	openvpn	75963	VERIFY WARNING: depth=1, unable to get certificate CRL: C=VG, ST=BVI, O=ExpressVPN, OU=ExpressVPN, CN=ExpressVPN CA, emailAddress=support@expressvpn.com
May 26 15:00:23	openvpn	75963	VERIFY OK: depth=1, C=VG, ST=BVI, O=ExpressVPN, OU=ExpressVPN, CN=ExpressVPN CA, emailAddress=support@expressvpn.com
May 26 15:00:23	openvpn	75963	VERIFY OK: nsCertType=SERVER
May 26 15:00:23	openvpn	75963	VERIFY X509NAME OK: C=VG, ST=BVI, O=ExpressVPN, OU=ExpressVPN, CN=Server-1417-1a, emailAddress=support@expressvpn.com
May 26 15:00:23	openvpn	75963	VERIFY OK: depth=0, C=VG, ST=BVI, O=ExpressVPN, OU=ExpressVPN, CN=Server-1417-1a, emailAddress=support@expressvpn.com
May 26 15:00:23	openvpn	75963	Control Channel: TLSv1.3, cipher TLSv1.3 TLS_AES_256_GCM_SHA384, 2048 bit RSA
May 26 15:00:23	openvpn	75963	[Server-1417-1a] Peer Connection Initiated with [AF_INET]0.0.0.0:1195
May 26 15:00:25	openvpn	75963	SENT CONTROL [Server-1417-1a]: 'PUSH_REQUEST' (status=1)
May 26 15:00:25	openvpn	75963	AUTH: Received control message: AUTH_FAILED
May 26 15:00:25	openvpn	75963	SIGUSR1[soft,auth-failure] received, process restarting
May 26 15:00:25	openvpn	75963	Restart pause, 10 second(s)
May 26 15:00:35	openvpn	75963	WARNING: --ns-cert-type is DEP

KOM

@jegavelan I would get rid of all your custom options and try working with it with defaults. A lot of your custom options are controlled by elements in the GUI. Second, I would increase the verbosity level of the logs so that you might see more about this auth failure. Are you SURE you have the correct username and password? Have you grabbed a copy of an ExpressVPN OpenVPN config file and looked at it for its settings and compared them to what you have done on pfSense?

Jegavelan

@kom Yes verified that 100 time by now. Now removed the custom options and set the log to 10

May 26 16:02:17	openvpn	38366	ACK received for pid 3, deleting from send buffer
May 26 16:02:17	openvpn	38366	ACK read ID 3 (buf->len=158)
May 26 16:02:17	openvpn	38366	ACK RWBS rel->size=8 rel->packet_id=00000003 id=00000003 ret=1
May 26 16:02:17	openvpn	38366	ACK mark active incoming ID 3
May 26 16:02:17	openvpn	38366	ACK acknowledge ID 3 (ack->len=1)
May 26 16:02:17	openvpn	38366	TLS: tls_multi_process: i=0 state=S_SENT_KEY, mysid=60295c8b b0c44025, stored-sid=e33ee007 d0daae41, stored-ip=[AF_INET]45.137.126.2:1195
May 26 16:02:17	openvpn	38366	TLS: tls_process: chg=0 ks=S_SENT_KEY lame=S_UNDEF to_link->len=0 wakeup=604800
May 26 16:02:17	openvpn	38366	ACK reliable_can_send active=0 current=0 : [4]
May 26 16:02:17	openvpn	38366	BIO write tls_write_ciphertext 158 bytes
May 26 16:02:17	openvpn	38366	Incoming Ciphertext -> TLS
May 26 16:02:17	openvpn	38366	SSL state (connect): SSL negotiation finished successfully
May 26 16:02:17	openvpn	38366	SSL state (connect): SSL negotiation finished successfully
May 26 16:02:17	openvpn	38366	SSL state (connect): SSLv3/TLS read server session ticket
May 26 16:02:17	openvpn	38366	SSL state (connect): SSL negotiation finished successfully
May 26 16:02:17	openvpn	38366	SSL state (connect): SSL negotiation finished successfully
May 26 16:02:17	openvpn	38366	SSL state (connect): SSLv3/TLS read server session ticket
May 26 16:02:17	openvpn	38366	TLS: tls_process: chg=1 ks=S_SENT_KEY lame=S_UNDEF to_link->len=0 wakeup=604800
May 26 16:02:17	openvpn	38366	ACK reliable_can_send active=0 current=0 : [4]
May 26 16:02:17	openvpn	38366	ACK write ID 3 (ack->len=1, n=1)
May 26 16:02:17	openvpn	38366	write_control_auth(): P_ACK_V1
May 26 16:02:17	openvpn	38366	ENCRYPT HMAC: 44c22a00 3ec7478d 20f347fd c6709f94 a34b33a5 053cf98a f53735a3 2a3601c[more...]
May 26 16:02:17	openvpn	38366	ENCRYPT TO: 44c22a00 3ec7478d 20f347fd c6709f94 a34b33a5 053cf98a f53735a3 2a3601c[more...]
May 26 16:02:17	openvpn	38366	Dedicated ACK -> TCP/UDP
May 26 16:02:17	openvpn	38366	ACK reliable_send_timeout 604800 [4]
May 26 16:02:17	openvpn	38366	TLS: tls_process: timeout set to 59
May 26 16:02:17	openvpn	38366	TLS: tls_multi_process: i=1 state=S_INITIAL, mysid=b67a0613 328e6ad9, stored-sid=00000000 00000000, stored-ip=[AF_UNSPEC]
May 26 16:02:17	openvpn	38366	TLS: tls_multi_process: i=2 state=S_UNDEF, mysid=00000000 00000000, stored-sid=00000000 00000000, stored-ip=[AF_UNSPEC]
May 26 16:02:17	openvpn	38366	UDPv4 WRITE [94] to [AF_INET]45.137.126.2:1195: P_ACK_V1 kid=0 sid=60295c8b b0c44025 tls_hmac=44c22a00 3ec7478d 20f347fd c6709f94 a34b33a5 053cf98a f53735a3 2a3601ce e9bf5dff 68f1003e 00c52d78 31a33302 c78a7d14 1b69f3b2 44a86e8b c0c3b279 pid=[ #7 / time = (1622062936) 2021-05-26 16:02:16 ] [ 3 sid=e33e
May 26 16:02:17	openvpn	38366	UDPv4 write returned 94
May 26 16:02:17	openvpn	38366	TLS: tls_multi_process: i=0 state=S_SENT_KEY, mysid=60295c8b b0c44025, stored-sid=e33ee007 d0daae41, stored-ip=[AF_INET]45.137.126.2:1195
May 26 16:02:17	openvpn	38366	TLS: tls_process: chg=0 ks=S_SENT_KEY lame=S_UNDEF to_link->len=0 wakeup=604800
May 26 16:02:17	openvpn	38366	ACK reliable_can_send active=0 current=0 : [4]
May 26 16:02:17	openvpn	38366	ACK reliable_send_timeout 604800 [4]
May 26 16:02:17	openvpn	38366	TLS: tls_process: timeout set to 59
May 26 16:02:17	openvpn	38366	TLS: tls_multi_process: i=1 state=S_INITIAL, mysid=b67a0613 328e6ad9, stored-sid=00000000 00000000, stored-ip=[AF_UNSPEC]
May 26 16:02:17	openvpn	38366	TLS: tls_multi_process: i=2 state=S_UNDEF, mysid=00000000 00000000, stored-sid=00000000 00000000, stored-ip=[AF_UNSPEC]
May 26 16:02:17	openvpn	38366	PO_CTL rwflags=0x0001 ev=5 arg=0x002b6928
May 26 16:02:17	openvpn	38366	PO_CTL rwflags=0x0001 ev=3 arg=0x002b5c18
May 26 16:02:17	openvpn	38366	I/O WAIT T?|T?|SR|Sw [1/178614]
May 26 16:02:17	openvpn	38366	PO_WAIT[0,0] fd=5 rev=0x00000001 rwflags=0x0001 arg=0x002b6928
May 26 16:02:17	openvpn	38366	event_wait returned 1
May 26 16:02:17	openvpn	38366	I/O WAIT status=0x0001
May 26 16:02:17	openvpn	38366	UDPv4 read returned 346
May 26 16:02:17	openvpn	38366	UDPv4 READ [346] from [AF_INET]45.137.126.2:1195: P_CONTROL_V1 kid=0 sid=e33ee007 d0daae41 tls_hmac=2e1150e7 ceceb5b9 c07cee58 b4ad9c26 ac3f2f04 7160e08b 4ca8ac30 ae76b7cc 4720ed4a d9a4bf4a d9b3d092 bdcde1d5 eac88219 c29f69f6 75fa991b 8626d495 pid=[ #6 / time = (1622062937) 2021-05-26 16:02:17 ] [ ] pid=
May 26 16:02:17	openvpn	38366	TLS: control channel, op=P_CONTROL_V1, IP=[AF_INET]45.137.126.2:1195
May 26 16:02:17	openvpn	38366	TLS: initial packet test, i=0 state=S_SENT_KEY, mysid=60295c8b b0c44025, rec-sid=e33ee007 d0daae41, rec-ip=[AF_INET]45.137.126.2:1195, stored-sid=e33ee007 d0daae41, stored-ip=[AF_INET]45.137.126.2:1195
May 26 16:02:17	openvpn	38366	TLS: found match, session[0], sid=e33ee007 d0daae41
May 26 16:02:17	openvpn	38366	DECRYPT FROM: 2e1150e7 ceceb5b9 c07cee58 b4ad9c26 ac3f2f04 7160e08b 4ca8ac30 ae76b7c[more...]
May 26 16:02:17	openvpn	38366	PID_TEST [0] [TLS_WRAP-0] [00000] 1622062937:5 1622062937:6 t=1622062937[0] r=[0,64,15,0,1] sl=[59,5,64,528]
May 26 16:02:17	openvpn	38366	TLS: received control channel packet s#=0 sid=e33ee007 d0daae41
May 26 16:02:17	openvpn	38366	ACK read ID 4 (buf->len=260)
May 26 16:02:17	openvpn	38366	ACK RWBS rel->size=8 rel->packet_id=00000004 id=00000004 ret=1
May 26 16:02:17	openvpn	38366	ACK mark active incoming ID 4
May 26 16:02:17	openvpn	38366	ACK acknowledge ID 4 (ack->len=1)
May 26 16:02:17	openvpn	38366	TLS: tls_multi_process: i=0 state=S_SENT_KEY, mysid=60295c8b b0c44025, stored-sid=e33ee007 d0daae41, stored-ip=[AF_INET]45.137.126.2:1195
May 26 16:02:17	openvpn	38366	TLS: tls_process: chg=0 ks=S_SENT_KEY lame=S_UNDEF to_link->len=0 wakeup=604800
May 26 16:02:17	openvpn	38366	ACK reliable_can_send active=0 current=0 : [4]
May 26 16:02:17	openvpn	38366	BIO write tls_write_ciphertext 260 bytes
May 26 16:02:17	openvpn	38366	Incoming Ciphertext -> TLS
May 26 16:02:17	openvpn	38366	BIO read tls_read_plaintext 238 bytes
May 26 16:02:17	openvpn	38366	TLS -> Incoming Plaintext
May 26 16:02:17	openvpn	38366	WARNING: 'link-mtu' is used inconsistently, local='link-mtu 1602', remote='link-mtu 1606'
May 26 16:02:17	openvpn	38366	WARNING: 'mtu-dynamic' is present in remote config but missing in local config, remote='mtu-dynamic'
May 26 16:02:17	openvpn	38366	STATE S_GOT_KEY
May 26 16:02:17	openvpn	38366	TLS: tls_process: chg=1 ks=S_GOT_KEY lame=S_UNDEF to_link->len=0 wakeup=0
May 26 16:02:17	openvpn	38366	ACK reliable_can_send active=0 current=0 : [4]
May 26 16:02:17	openvpn	38366	ACK write ID 4 (ack->len=1, n=1)
May 26 16:02:17	openvpn	38366	write_control_auth(): P_ACK_V1
May 26 16:02:17	openvpn	38366	ENCRYPT HMAC: 3f3d105b fe11e907 ece2fef1 d283de42 20f9c6ad 625d3aa4 638030f4 c0142ba[more...]
May 26 16:02:17	openvpn	38366	ENCRYPT TO: 3f3d105b fe11e907 ece2fef1 d283de42 20f9c6ad 625d3aa4 638030f4 c0142ba[more...]
May 26 16:02:17	openvpn	38366	Dedicated ACK -> TCP/UDP
May 26 16:02:17	openvpn	38366	ACK reliable_send_timeout 604800 [4]
May 26 16:02:17	openvpn	38366	TLS: tls_process: timeout set to 1
May 26 16:02:17	openvpn	38366	TLS: tls_multi_process: i=1 state=S_INITIAL, mysid=b67a0613 328e6ad9, stored-sid=00000000 00000000, stored-ip=[AF_UNSPEC]
May 26 16:02:17	openvpn	38366	TLS: tls_multi_process: i=2 state=S_UNDEF, mysid=00000000 00000000, stored-sid=00000000 00000000, stored-ip=[AF_UNSPEC]
May 26 16:02:17	openvpn	38366	UDPv4 WRITE [94] to [AF_INET]45.137.126.2:1195: P_ACK_V1 kid=0 sid=60295c8b b0c44025 tls_hmac=3f3d105b fe11e907 ece2fef1 d283de42 20f9c6ad 625d3aa4 638030f4 c0142bad 5a6e9726 fc877ae0 92a7a4a9 dc65230c b54915db 97453ece d74085e1 71154d65 pid=[ #8 / time = (1622062936) 2021-05-26 16:02:16 ] [ 4 sid=e33e
May 26 16:02:17	openvpn	38366	UDPv4 write returned 94
May 26 16:02:17	openvpn	38366	TLS: tls_multi_process: i=0 state=S_GOT_KEY, mysid=60295c8b b0c44025, stored-sid=e33ee007 d0daae41, stored-ip=[AF_INET]45.137.126.2:1195
May 26 16:02:17	openvpn	38366	TLS: tls_process: chg=0 ks=S_GOT_KEY lame=S_UNDEF to_link->len=0 wakeup=604800
May 26 16:02:17	openvpn	38366	STATE S_ACTIVE
May 26 16:02:17	openvpn	38366	Control Channel: TLSv1.3, cipher TLSv1.3 TLS_AES_256_GCM_SHA384, 2048 bit RSA
May 26 16:02:17	openvpn	38366	[Server-1417-1a] Peer Connection Initiated with [AF_INET]45.137.126.2:1195
May 26 16:02:17	openvpn	38366	ACK reliable_can_send active=0 current=0 : [4]
May 26 16:02:17	openvpn	38366	TLS: tls_process: chg=1 ks=S_ACTIVE lame=S_UNDEF to_link->len=0 wakeup=604800
May 26 16:02:17	openvpn	38366	ACK reliable_can_send active=0 current=0 : [4]
May 26 16:02:17	openvpn	38366	ACK reliable_send_timeout 604800 [4]
May 26 16:02:17	openvpn	38366	TLS: tls_process: timeout set to 3600
May 26 16:02:17	openvpn	38366	TLS: tls_multi_process: i=1 state=S_INITIAL, mysid=b67a0613 328e6ad9, stored-sid=00000000 00000000, stored-ip=[AF_UNSPEC]
May 26 16:02:17	openvpn	38366	TLS: tls_multi_process: i=2 state=S_UNDEF, mysid=00000000 00000000, stored-sid=00000000 00000000, stored-ip=[AF_UNSPEC]
May 26 16:02:17	openvpn	38366	PO_CTL rwflags=0x0001 ev=5 arg=0x002b6928
May 26 16:02:17	openvpn	38366	PO_CTL rwflags=0x0001 ev=3 arg=0x002b5c18
May 26 16:02:17	openvpn	38366	I/O WAIT T?|T?|SR|Sw [1/178614]
May 26 16:02:18	openvpn	38366	event_wait returned 0
May 26 16:02:18	openvpn	38366	I/O WAIT status=0x0020
May 26 16:02:18	openvpn	38366	BIO write tls_write_plaintext_const 13 bytes
May 26 16:02:18	openvpn	38366	SENT CONTROL [Server-1417-1a]: 'PUSH_REQUEST' (status=1)
May 26 16:02:18	openvpn	38366	TIMER: coarse timer wakeup 0 seconds
May 26 16:02:18	openvpn	38366	TLS: tls_multi_process: i=0 state=S_ACTIVE, mysid=60295c8b b0c44025, stored-sid=e33ee007 d0daae41, stored-ip=[AF_INET]45.137.126.2:1195
May 26 16:02:18	openvpn	38366	TLS: tls_process: chg=0 ks=S_ACTIVE lame=S_UNDEF to_link->len=0 wakeup=604800
May 26 16:02:18	openvpn	38366	ACK reliable_can_send active=0 current=0 : [4]
May 26 16:02:18	openvpn	38366	BIO read tls_read_ciphertext 35 bytes
May 26 16:02:18	openvpn	38366	ACK mark active outgoing ID 4
May 26 16:02:18	openvpn	38366	Outgoing Ciphertext -> Reliable
May 26 16:02:18	openvpn	38366	TLS: tls_process: chg=1 ks=S_ACTIVE lame=S_UNDEF to_link->len=0 wakeup=604800
May 26 16:02:18	openvpn	38366	ACK reliable_can_send active=1 current=1 : [5] 4
May 26 16:02:18	openvpn	38366	ACK reliable_send ID 4 (size=39 to=2)
May 26 16:02:18	openvpn	38366	write_control_auth(): P_CONTROL_V1
May 26 16:02:18	openvpn	38366	ENCRYPT HMAC: 5bd4a1d0 3e261a7c 780c62e2 4b58e3b2 38d8a86a 7c647b89 eb0f1af7 439ba45[more...]
May 26 16:02:18	openvpn	38366	ENCRYPT TO: 5bd4a1d0 3e261a7c 780c62e2 4b58e3b2 38d8a86a 7c647b89 eb0f1af7 439ba45[more...]
May 26 16:02:18	openvpn	38366	Reliable -> TCP/UDP
May 26 16:02:18	openvpn	38366	ACK reliable_send_timeout 2 [5] 4
May 26 16:02:18	openvpn	38366	TLS: tls_process: timeout set to 2
May 26 16:02:18	openvpn	38366	TLS: tls_multi_process: i=1 state=S_INITIAL, mysid=b67a0613 328e6ad9, stored-sid=00000000 00000000, stored-ip=[AF_UNSPEC]
May 26 16:02:18	openvpn	38366	TLS: tls_multi_process: i=2 state=S_UNDEF, mysid=00000000 00000000, stored-sid=00000000 00000000, stored-ip=[AF_UNSPEC]
May 26 16:02:18	openvpn	38366	UDPv4 WRITE [121] to [AF_INET]45.137.126.2:1195: P_CONTROL_V1 kid=0 sid=60295c8b b0c44025 tls_hmac=5bd4a1d0 3e261a7c 780c62e2 4b58e3b2 38d8a86a 7c647b89 eb0f1af7 439ba45c a2645e0e f1ebccf6 abcd12ed 4d76c5a6 2e8dd8c1 031e9b7d dfeca8c7 63923136 pid=[ #9 / time = (1622062936) 2021-05-26 16:02:16 ] [ ] pid=
May 26 16:02:18	openvpn	38366	UDPv4 write returned 121
May 26 16:02:18	openvpn	38366	TIMER: coarse timer wakeup 5 seconds
May 26 16:02:18	openvpn	38366	TLS: tls_multi_process: i=0 state=S_ACTIVE, mysid=60295c8b b0c44025, stored-sid=e33ee007 d0daae41, stored-ip=[AF_INET]45.137.126.2:1195
May 26 16:02:18	openvpn	38366	TLS: tls_process: chg=0 ks=S_ACTIVE lame=S_UNDEF to_link->len=0 wakeup=604800
May 26 16:02:18	openvpn	38366	ACK reliable_can_send active=1 current=0 : [5] 4
May 26 16:02:18	openvpn	38366	ACK reliable_send_timeout 2 [5] 4
May 26 16:02:18	openvpn	38366	TLS: tls_process: timeout set to 2
May 26 16:02:18	openvpn	38366	TLS: tls_multi_process: i=1 state=S_INITIAL, mysid=b67a0613 328e6ad9, stored-sid=00000000 00000000, stored-ip=[AF_UNSPEC]
May 26 16:02:18	openvpn	38366	TLS: tls_multi_process: i=2 state=S_UNDEF, mysid=00000000 00000000, stored-sid=00000000 00000000, stored-ip=[AF_UNSPEC]
May 26 16:02:18	openvpn	38366	PO_CTL rwflags=0x0001 ev=5 arg=0x002b6928
May 26 16:02:18	openvpn	38366	PO_CTL rwflags=0x0001 ev=3 arg=0x002b5c18
May 26 16:02:18	openvpn	38366	I/O WAIT T?|T?|SR|Sw [2/178614]
May 26 16:02:19	openvpn	38366	PO_WAIT[0,0] fd=5 rev=0x00000001 rwflags=0x0001 arg=0x002b6928
May 26 16:02:19	openvpn	38366	event_wait returned 1
May 26 16:02:19	openvpn	38366	I/O WAIT status=0x0001
May 26 16:02:19	openvpn	38366	UDPv4 read returned 94
May 26 16:02:19	openvpn	38366	UDPv4 READ [94] from [AF_INET]45.137.126.2:1195: P_ACK_V1 kid=0 sid=e33ee007 d0daae41 tls_hmac=cd476d0f a47d36dc 1b96fed5 510078ad cecc7088 4c820d4a 7577b11b 4fde9829 644617dd 5a2286b4 f76fcf08 1e8ede29 7cff9fb0 ef001fd5 f219e6f7 8f3c4fed pid=[ #7 / time = (1622062937) 2021-05-26 16:02:17 ] [ 4 sid=6029
May 26 16:02:19	openvpn	38366	TLS: control channel, op=P_ACK_V1, IP=[AF_INET]45.137.126.2:1195
May 26 16:02:19	openvpn	38366	TLS: initial packet test, i=0 state=S_ACTIVE, mysid=60295c8b b0c44025, rec-sid=e33ee007 d0daae41, rec-ip=[AF_INET]45.137.126.2:1195, stored-sid=e33ee007 d0daae41, stored-ip=[AF_INET]45.137.126.2:1195
May 26 16:02:19	openvpn	38366	TLS: found match, session[0], sid=e33ee007 d0daae41
May 26 16:02:19	openvpn	38366	DECRYPT FROM: cd476d0f a47d36dc 1b96fed5 510078ad cecc7088 4c820d4a 7577b11b 4fde982[more...]
May 26 16:02:19	openvpn	38366	PID_TEST [0] [TLS_WRAP-0] [222222] 1622062937:6 1622062937:7 t=1622062939[0] r=[-2,64,15,0,1] sl=[58,6,64,528]
May 26 16:02:19	openvpn	38366	TLS: received control channel packet s#=0 sid=e33ee007 d0daae41
May 26 16:02:19	openvpn	38366	ACK received for pid 4, deleting from send buffer
May 26 16:02:19	openvpn	38366	TLS: tls_multi_process: i=0 state=S_ACTIVE, mysid=60295c8b b0c44025, stored-sid=e33ee007 d0daae41, stored-ip=[AF_INET]45.137.126.2:1195
May 26 16:02:19	openvpn	38366	TLS: tls_process: chg=0 ks=S_ACTIVE lame=S_UNDEF to_link->len=0 wakeup=604800
May 26 16:02:19	openvpn	38366	ACK reliable_can_send active=0 current=0 : [5]
May 26 16:02:19	openvpn	38366	ACK reliable_send_timeout 604800 [5]
May 26 16:02:19	openvpn	38366	TLS: tls_process: timeout set to 3598
May 26 16:02:19	openvpn	38366	TLS: tls_multi_process: i=1 state=S_INITIAL, mysid=b67a0613 328e6ad9, stored-sid=00000000 00000000, stored-ip=[AF_UNSPEC]
May 26 16:02:19	openvpn	38366	TLS: tls_multi_process: i=2 state=S_UNDEF, mysid=00000000 00000000, stored-sid=00000000 00000000, stored-ip=[AF_UNSPEC]
May 26 16:02:19	openvpn	38366	PO_CTL rwflags=0x0001 ev=5 arg=0x002b6928
May 26 16:02:19	openvpn	38366	PO_CTL rwflags=0x0001 ev=3 arg=0x002b5c18
May 26 16:02:19	openvpn	38366	I/O WAIT T?|T?|SR|Sw [4/178614]
May 26 16:02:19	openvpn	38366	PO_WAIT[0,0] fd=5 rev=0x00000001 rwflags=0x0001 arg=0x002b6928
May 26 16:02:19	openvpn	38366	event_wait returned 1
May 26 16:02:19	openvpn	38366	I/O WAIT status=0x0001
May 26 16:02:19	openvpn	38366	UDPv4 read returned 120
May 26 16:02:19	openvpn	38366	UDPv4 READ [120] from [AF_INET]45.137.126.2:1195: P_CONTROL_V1 kid=0 sid=e33ee007 d0daae41 tls_hmac=67ea2659 c5dcacd4 ed0edb91 22963ba5 024a3ca4 a27545e3 32596e50 cb61e8bc c4d84e11 35ab9aca c286206b d21fbc34 af537752 9d988e4c 5de3b7a2 8b9cf92e pid=[ #8 / time = (1622062937) 2021-05-26 16:02:17 ] [ ] pid=
May 26 16:02:19	openvpn	38366	TLS: control channel, op=P_CONTROL_V1, IP=[AF_INET]45.137.126.2:1195
May 26 16:02:19	openvpn	38366	TLS: initial packet test, i=0 state=S_ACTIVE, mysid=60295c8b b0c44025, rec-sid=e33ee007 d0daae41, rec-ip=[AF_INET]45.137.126.2:1195, stored-sid=e33ee007 d0daae41, stored-ip=[AF_INET]45.137.126.2:1195
May 26 16:02:19	openvpn	38366	TLS: found match, session[0], sid=e33ee007 d0daae41
May 26 16:02:19	openvpn	38366	DECRYPT FROM: 67ea2659 c5dcacd4 ed0edb91 22963ba5 024a3ca4 a27545e3 32596e50 cb61e8b[more...]
May 26 16:02:19	openvpn	38366	PID_TEST [0] [TLS_WRAP-0] [0222222] 1622062937:7 1622062937:8 t=1622062939[0] r=[-2,64,15,0,1] sl=[57,7,64,528]
May 26 16:02:19	openvpn	38366	TLS: received control channel packet s#=0 sid=e33ee007 d0daae41
May 26 16:02:19	openvpn	38366	ACK read ID 5 (buf->len=34)
May 26 16:02:19	openvpn	38366	ACK RWBS rel->size=8 rel->packet_id=00000005 id=00000005 ret=1
May 26 16:02:19	openvpn	38366	ACK mark active incoming ID 5
May 26 16:02:19	openvpn	38366	ACK acknowledge ID 5 (ack->len=1)
May 26 16:02:19	openvpn	38366	TLS: tls_multi_process: i=0 state=S_ACTIVE, mysid=60295c8b b0c44025, stored-sid=e33ee007 d0daae41, stored-ip=[AF_INET]45.137.126.2:1195
May 26 16:02:19	openvpn	38366	TLS: tls_process: chg=0 ks=S_ACTIVE lame=S_UNDEF to_link->len=0 wakeup=604800
May 26 16:02:19	openvpn	38366	ACK reliable_can_send active=0 current=0 : [5]
May 26 16:02:19	openvpn	38366	BIO write tls_write_ciphertext 34 bytes
May 26 16:02:19	openvpn	38366	Incoming Ciphertext -> TLS
May 26 16:02:19	openvpn	38366	BIO read tls_read_plaintext 12 bytes
May 26 16:02:19	openvpn	38366	TLS -> Incoming Plaintext
May 26 16:02:19	openvpn	38366	TLS: tls_process: chg=1 ks=S_ACTIVE lame=S_UNDEF to_link->len=0 wakeup=0
May 26 16:02:19	openvpn	38366	ACK reliable_can_send active=0 current=0 : [5]
May 26 16:02:19	openvpn	38366	ACK write ID 5 (ack->len=1, n=1)
May 26 16:02:19	openvpn	38366	write_control_auth(): P_ACK_V1
May 26 16:02:19	openvpn	38366	ENCRYPT HMAC: 22ca54c0 23345303 72f8e586 1ae4ca1b 428c1c6b 831756d0 f4d21513 2861281[more...]
May 26 16:02:19	openvpn	38366	ENCRYPT TO: 22ca54c0 23345303 72f8e586 1ae4ca1b 428c1c6b 831756d0 f4d21513 2861281[more...]
May 26 16:02:19	openvpn	38366	Dedicated ACK -> TCP/UDP
May 26 16:02:19	openvpn	38366	ACK reliable_send_timeout 604800 [5]
May 26 16:02:19	openvpn	38366	TLS: tls_process: timeout set to 1
May 26 16:02:19	openvpn	38366	TLS: tls_multi_process: i=1 state=S_INITIAL, mysid=b67a0613 328e6ad9, stored-sid=00000000 00000000, stored-ip=[AF_UNSPEC]
May 26 16:02:19	openvpn	38366	TLS: tls_multi_process: i=2 state=S_UNDEF, mysid=00000000 00000000, stored-sid=00000000 00000000, stored-ip=[AF_UNSPEC]
May 26 16:02:19	openvpn	38366	AUTH: Received control message: AUTH_FAILED
May 26 16:02:19	openvpn	38366	PID packet_id_free
May 26 16:02:19	openvpn	38366	SSL alert (write): warning: close notify
May 26 16:02:19	openvpn	38366	PID packet_id_free
May 26 16:02:19	openvpn	38366	PID packet_id_free
May 26 16:02:19	openvpn	38366	PID packet_id_free
May 26 16:02:19	openvpn	38366	PID packet_id_free
May 26 16:02:19	openvpn	38366	PID packet_id_free
May 26 16:02:19	openvpn	38366	PID packet_id_free
May 26 16:02:19	openvpn	38366	PID packet_id_free
May 26 16:02:19	openvpn	38366	TCP/UDP: Closing socket
May 26 16:02:19	openvpn	38366	PID packet_id_free
May 26 16:02:19	openvpn	38366	SIGUSR1[soft,auth-failure] received, process restarting
May 26 16:02:19	openvpn	38366	Restart pause, 10 second(s)
May 26 16:02:19	openvpn	38366	PO_CTL rwflags=0x0001 ev=3 arg=0x00000000
May 26 16:02:19	openvpn	38366	PO_CTL rwflags=0x0001 ev=3 arg=0x00000000
May 26 16:02:20	openvpn	38366	PO_CTL rwflags=0x0001 ev=3 arg=0x00000000
May 26 16:02:21	openvpn	38366	PO_CTL rwflags=0x0001 ev=3 arg=0x00000000

KOM

@jegavelan Nothing jumps out other than those two warnings. Do you have an ExpressVPN .ovpn file you could post the contents of here? If it's customized for you then please remove your username and password if present.

Edit: Some others here in the past had a similar issue and solved it by adding this to their custom options:

pull-filter ignore "auth-token"

Jegavelan

@kom said in Express VPN Received control message: AUTH_FAILED:

"

Tried that already no luck.

dev tun
fast-io
persist-key
persist-tun
nobind
remote usa-newyork-ca-version-2.expressnetw.com 1195
remote-random
pull
comp-lzo no
tls-client
verify-x509-name Server name-prefix

KOM

@jegavelan said in Express VPN Received control message: AUTH_FAILED:

comp-lzo no

Yours is set to Adaptive. I would try disabling compression entirely and see if that helps.

Edit: You might want to delete your key information from your .ovpn post. Remove all from <cert> down.

Jegavelan

@kom Disabled it , still same error message.

KOM

@jegavelan Which version of pfSense is this?

Jegavelan

@kom

KOM

@jegavelan Didn't your original .ovpn file have a key-direction entry in it? I'm sure I saw that but it's not in your post above anymore.

Jegavelan

@kom

remote-random
pull
comp-lzo no
tls-client
verify-x509-name Server name-prefix
ns-cert-type server
key-direction 1
route-method exe
route-delay 2
tun-mtu 1500
fragment 1300
mssfix 1200
verb 3
cipher AES-256-CBC
keysize 256
auth SHA512
sndbuf 524288
rcvbuf 524288
auth-user-pass

KOM

@jegavelan Try manually setting your TLS key-direction to 1 instead of Use default direction

I'm grasping at straws at this point.

Jegavelan

@kom still no luck

KOM

@jegavelan I don't have much else to add other than to contact ExpressVPN Support and ask them if they have more details from the server logs because the auth_fail is completely unexplained. Usually that error comes with extra details, and when it does not it's often a bad username or password.

Gertjan

These are my settings :

The created config file is :

dev ovpnc2
verb 3
dev-type tun
dev-node /dev/tun2
writepid /var/run/openvpn_client2.pid
#user nobody
#group nobody
script-security 3
daemon
keepalive 10 60
ping-timer-rem
persist-tun
persist-key
proto udp4
auth SHA512
up /usr/local/sbin/ovpn-linkup
down /usr/local/sbin/ovpn-linkdown
local 192.168.10.3
tls-client
client
lport 0
management /var/etc/openvpn/client2/sock unix
remote 45.91.22.2 1195 udp4
auth-user-pass /var/etc/openvpn/client2/up
capath /var/etc/openvpn/client2/ca
cert /var/etc/openvpn/client2/cert 
key /var/etc/openvpn/client2/key 
tls-auth /var/etc/openvpn/client2/tls-auth 1
data-ciphers AES-256-CBC
data-ciphers-fallback AES-256-CBC
allow-compression asym
comp-lzo yes
resolv-retry infinite
fast-io
sndbuf 524288
rcvbuf 524288

verify-x509-name Server name-prefix;
remote-cert-tls server;
route-delay 2;
tun-mtu 1500;
fragment 1300;
mssfix 1450;
auth-nocache;

Starting with "verify-x509-name Server name-prefix", these are the custom added commands.

Note : with the "qdqdqdqsdqsdqsdqsdqsdq" password (see image), I guess massive

AUTH: Received control message: AUTH_FAILED

failures.

These :

dev ovpnc2
local 192.168.10.3
remote 45.91.22.2 1195 udp4

are most surely different on your system.

The VPN client connected just fine :
Logs in reverse order :

2021-05-27 08:42:46.012571+02:00 	openvpn 	86900 	Initialization Sequence Completed
2021-05-27 08:42:44.586214+02:00 	openvpn 	86900 	/usr/local/sbin/ovpn-linkup ovpnc2 1500 1629 10.104.2.110 10.104.2.109 init
2021-05-27 08:42:44.581361+02:00 	openvpn 	86900 	/sbin/ifconfig ovpnc2 10.104.2.110 10.104.2.109 mtu 1500 netmask 255.255.255.255 up
2021-05-27 08:42:44.581222+02:00 	openvpn 	86900 	TUN/TAP device /dev/tun2 opened
2021-05-27 08:42:44.580968+02:00 	openvpn 	86900 	TUN/TAP device ovpnc2 exists previously, keep at program end
2021-05-27 08:42:44.580890+02:00 	openvpn 	86900 	Incoming Data Channel: Using 512 bit message hash 'SHA512' for HMAC authentication
2021-05-27 08:42:44.580831+02:00 	openvpn 	86900 	Incoming Data Channel: Cipher 'AES-256-CBC' initialized with 256 bit key
2021-05-27 08:42:44.580781+02:00 	openvpn 	86900 	Outgoing Data Channel: Using 512 bit message hash 'SHA512' for HMAC authentication
2021-05-27 08:42:44.580726+02:00 	openvpn 	86900 	Outgoing Data Channel: Cipher 'AES-256-CBC' initialized with 256 bit key
2021-05-27 08:42:44.580592+02:00 	openvpn 	86900 	Using peer cipher 'AES-256-CBC'
2021-05-27 08:42:44.580546+02:00 	openvpn 	86900 	OPTIONS IMPORT: adjusting link_mtu to 1629
2021-05-27 08:42:44.580496+02:00 	openvpn 	86900 	OPTIONS IMPORT: peer-id set
2021-05-27 08:42:44.580450+02:00 	openvpn 	86900 	OPTIONS IMPORT: --ifconfig/up options modified
2021-05-27 08:42:44.580390+02:00 	openvpn 	86900 	OPTIONS IMPORT: compression parms modified
2021-05-27 08:42:44.580338+02:00 	openvpn 	86900 	OPTIONS IMPORT: timers and/or timeouts modified
2021-05-27 08:42:44.580269+02:00 	openvpn 	86900 	Options error: option 'route' cannot be used in this context ([PUSH-OPTIONS])
2021-05-27 08:42:44.580214+02:00 	openvpn 	86900 	Options error: option 'dhcp-option' cannot be used in this context ([PUSH-OPTIONS])
2021-05-27 08:42:44.580158+02:00 	openvpn 	86900 	Options error: option 'redirect-gateway' cannot be used in this context ([PUSH-OPTIONS])
2021-05-27 08:42:44.580050+02:00 	openvpn 	86900 	PUSH: Received control message: 'PUSH_REPLY,redirect-gateway def1,dhcp-option DNS 10.104.0.1,comp-lzo no,route 10.104.0.1,topology net30,ping 10,ping-restart 60,ifconfig 10.104.2.110 10.104.2.109,peer-id 64'
2021-05-27 08:42:44.557481+02:00 	openvpn 	86900 	SENT CONTROL [Server-2776-4a]: 'PUSH_REQUEST' (status=1)
2021-05-27 08:42:43.536122+02:00 	openvpn 	86900 	[Server-2776-4a] Peer Connection Initiated with [AF_INET]45.91.22.2:1195
2021-05-27 08:42:43.536062+02:00 	openvpn 	86900 	Control Channel: TLSv1.3, cipher TLSv1.3 TLS_AES_256_GCM_SHA384, 2048 bit RSA
2021-05-27 08:42:43.499590+02:00 	openvpn 	86900 	VERIFY OK: depth=0, C=VG, ST=BVI, O=ExpressVPN, OU=ExpressVPN, CN=Server-2776-4a, emailAddress=support@expressvpn.com
2021-05-27 08:42:43.499537+02:00 	openvpn 	86900 	VERIFY X509NAME OK: C=VG, ST=BVI, O=ExpressVPN, OU=ExpressVPN, CN=Server-2776-4a, emailAddress=support@expressvpn.com
2021-05-27 08:42:43.499492+02:00 	openvpn 	86900 	VERIFY EKU OK
2021-05-27 08:42:43.499443+02:00 	openvpn 	86900 	++ Certificate has EKU (str) TLS Web Server Authentication, expects TLS Web Server Authentication
2021-05-27 08:42:43.499382+02:00 	openvpn 	86900 	Validating certificate extended key usage
2021-05-27 08:42:43.499330+02:00 	openvpn 	86900 	VERIFY KU OK
2021-05-27 08:42:43.498816+02:00 	openvpn 	86900 	VERIFY OK: depth=1, C=VG, ST=BVI, O=ExpressVPN, OU=ExpressVPN, CN=ExpressVPN CA, emailAddress=support@expressvpn.com
2021-05-27 08:42:43.498660+02:00 	openvpn 	86900 	VERIFY WARNING: depth=1, unable to get certificate CRL: C=VG, ST=BVI, O=ExpressVPN, OU=ExpressVPN, CN=ExpressVPN CA, emailAddress=support@expressvpn.com
2021-05-27 08:42:43.498568+02:00 	openvpn 	86900 	VERIFY WARNING: depth=0, unable to get certificate CRL: C=VG, ST=BVI, O=ExpressVPN, OU=ExpressVPN, CN=Server-2776-4a, emailAddress=support@expressvpn.com
2021-05-27 08:42:43.472192+02:00 	openvpn 	86900 	TLS: Initial packet from [AF_INET]45.91.22.2:1195, sid=741e1863 61e2292e
2021-05-27 08:42:43.448232+02:00 	openvpn 	86900 	UDPv4 link remote: [AF_INET]45.91.22.2:1195
2021-05-27 08:42:43.448220+02:00 	openvpn 	86900 	UDPv4 link local (bound): [AF_INET]192.168.10.3:0
2021-05-27 08:42:43.448194+02:00 	openvpn 	86900 	Socket Buffers: R=[42080->524288] S=[57344->524288]
2021-05-27 08:42:43.448130+02:00 	openvpn 	86900 	TCP/UDP: Preserving recently used remote address: [AF_INET]45.91.22.2:1195
2021-05-27 08:42:43.447802+02:00 	openvpn 	86900 	Incoming Control Channel Authentication: Using 512 bit message hash 'SHA512' for HMAC authentication
2021-05-27 08:42:43.447712+02:00 	openvpn 	86900 	Outgoing Control Channel Authentication: Using 512 bit message hash 'SHA512' for HMAC authentication
2021-05-27 08:42:43.447417+02:00 	openvpn 	86900 	WARNING: experimental option --capath /var/etc/openvpn/client2/ca
2021-05-27 08:42:43.446230+02:00 	openvpn 	86900 	NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
2021-05-27 08:42:43.446125+02:00 	openvpn 	86900 	MANAGEMENT: unix domain socket listening on /var/etc/openvpn/client2/sock
2021-05-27 08:42:43.445134+02:00 	openvpn 	86645 	library versions: OpenSSL 1.1.1k-freebsd 25 Mar 2021, LZO 2.10
2021-05-27 08:42:43.445121+02:00 	openvpn 	86645 	OpenVPN 2.5.1 amd64-portbld-freebsd12.2 [SSL (OpenSSL)] [LZO] [LZ4] [MH/RECVDA] [AEAD] built on Apr 5 2021
2021-05-27 08:42:43.445097+02:00 	openvpn 	86645 	WARNING: file '/var/etc/openvpn/client2/up' is group or others accessible

The OpenVPN client connected.
I did not test routing over it.

Jegavelan

@gertjan I removed all the existing certs and configuration and re-created everything like what you have now.

I got rid of the auth_failed error now , but VPN is not getting connected. Attached other configuration and logs.

May 27 10:16:53	openvpn	98617	MANAGEMENT: Client disconnected
May 27 10:16:53	openvpn	98617	PO_CTL rwflags=0x0001 ev=6 arg=0x002b6928
May 27 10:16:53	openvpn	98617	PO_CTL rwflags=0x0001 ev=3 arg=0x002b5c18
May 27 10:16:53	openvpn	98617	I/O WAIT T?|T?|SR|Sw [1/195856]
May 27 10:16:54	openvpn	98617	event_wait returned 0
May 27 10:16:54	openvpn	98617	I/O WAIT status=0x0020
May 27 10:16:54	openvpn	98617	TIMER: coarse timer wakeup 1 seconds
May 27 10:16:54	openvpn	98617	PO_CTL rwflags=0x0001 ev=6 arg=0x002b6928
May 27 10:16:54	openvpn	98617	PO_CTL rwflags=0x0001 ev=3 arg=0x002b5c18
May 27 10:16:54	openvpn	98617	I/O WAIT T?|T?|SR|Sw [1/195856]
May 27 10:16:55	openvpn	98617	event_wait returned 0
May 27 10:16:55	openvpn	98617	I/O WAIT status=0x0020
May 27 10:16:55	openvpn	98617	TIMER: coarse timer wakeup 1 seconds
May 27 10:16:55	openvpn	98617	PO_CTL rwflags=0x0001 ev=6 arg=0x002b6928
May 27 10:16:55	openvpn	98617	PO_CTL rwflags=0x0001 ev=3 arg=0x002b5c18
May 27 10:16:55	openvpn	98617	I/O WAIT T?|T?|SR|Sw [1/195856]
May 27 10:16:57	openvpn	98617	event_wait returned 0
May 27 10:16:57	openvpn	98617	I/O WAIT status=0x0020
May 27 10:16:57	openvpn	98617	TIMER: coarse timer wakeup 1 seconds
May 27 10:16:57	openvpn	98617	PO_CTL rwflags=0x0001 ev=6 arg=0x002b6928
May 27 10:16:57	openvpn	98617	PO_CTL rwflags=0x0001 ev=3 arg=0x002b5c18
May 27 10:16:57	openvpn	98617	I/O WAIT T?|T?|SR|Sw [1/195856]
May 27 10:16:58	openvpn	98617	event_wait returned 0
May 27 10:16:58	openvpn	98617	I/O WAIT status=0x0020
May 27 10:16:58	openvpn	98617	FRAG_OUT len=17 type=0 seq_id=0 frag_id=0 frag_size=0 flags=0x00000000
May 27 10:16:58	openvpn	98617	TLS Warning: no data channel send key available: [key#0 state=S_PRE_START id=0 sid=00000000 00000000] [key#1 state=S_UNDEF id=0 sid=00000000 00000000] [key#2 state=S_UNDEF id=0 sid=00000000 00000000]
May 27 10:16:58	openvpn	98617	SENT PING
May 27 10:16:58	openvpn	98617	TIMER: coarse timer wakeup 1 seconds
May 27 10:16:58	openvpn	98617	PO_CTL rwflags=0x0001 ev=6 arg=0x002b6928
May 27 10:16:58	openvpn	98617	PO_CTL rwflags=0x0001 ev=3 arg=0x002b5c18
May 27 10:16:58	openvpn	98617	I/O WAIT T?|T?|SR|Sw [1/195856]
May 27 10:16:59	openvpn	98617	event_wait returned 0
May 27 10:16:59	openvpn	98617	I/O WAIT status=0x0020
May 27 10:16:59	openvpn	98617	TIMER: coarse timer wakeup 1 seconds
May 27 10:16:59	openvpn	98617	PO_CTL rwflags=0x0001 ev=6 arg=0x002b6928
May 27 10:16:59	openvpn	98617	PO_CTL rwflags=0x0001 ev=3 arg=0x002b5c18
May 27 10:16:59	openvpn	98617	I/O WAIT T?|T?|SR|Sw [1/195856]
May 27 10:17:00	newsyslog	40369	logfile turned over due to size>500K
May 27 10:17:00	newsyslog	40369	logfile turned over due to size>500K
May 27 10:17:00	openvpn	98617	event_wait returned 0
May 27 10:17:00	openvpn	98617	I/O WAIT status=0x0020
May 27 10:17:00	openvpn	98617	TIMER: coarse timer wakeup 1 seconds
May 27 10:17:00	openvpn	98617	PO_CTL rwflags=0x0001 ev=6 arg=0x002b6928
May 27 10:17:00	openvpn	98617	PO_CTL rwflags=0x0001 ev=3 arg=0x002b5c18
May 27 10:17:00	openvpn	98617	I/O WAIT T?|T?|SR|Sw [1/195856]
May 27 10:17:01	openvpn	98617	event_wait returned 0
May 27 10:17:01	openvpn	98617	I/O WAIT status=0x0020
May 27 10:17:01	openvpn	98617	TIMER: coarse timer wakeup 1 seconds
May 27 10:17:01	openvpn	98617	PO_CTL rwflags=0x0001 ev=6 arg=0x002b6928
May 27 10:17:01	openvpn	98617	PO_CTL rwflags=0x0001 ev=3 arg=0x002b5c18
May 27 10:17:01	openvpn	98617	I/O WAIT T?|T?|SR|Sw [1/195856]
May 27 10:17:03	openvpn	98617	event_wait returned 0
May 27 10:17:03	openvpn	98617	I/O WAIT status=0x0020
May 27 10:17:03	openvpn	98617	TIMER: coarse timer wakeup 1 seconds
May 27 10:17:03	openvpn	98617	RANDOM USEC=201521
May 27 10:17:03	openvpn	98617	PO_CTL rwflags=0x0001 ev=6 arg=0x002b6928
May 27 10:17:03	openvpn	98617	PO_CTL rwflags=0x0001 ev=3 arg=0x002b5c18
May 27 10:17:03	openvpn	98617	I/O WAIT T?|T?|SR|Sw [1/201521]
May 27 10:17:04	openvpn	98617	event_wait returned 0
May 27 10:17:04	openvpn	98617	I/O WAIT status=0x0020
May 27 10:17:04	openvpn	98617	TIMER: coarse timer wakeup 1 seconds
May 27 10:17:04	openvpn	98617	TLS: tls_multi_process: i=0 state=S_PRE_START, mysid=6a6153d2 e65257b6, stored-sid=00000000 00000000, stored-ip=[AF_INET]191.101.42.152:1195
May 27 10:17:04	openvpn	98617	TLS: tls_process: chg=0 ks=S_PRE_START lame=S_UNDEF to_link->len=0 wakeup=604800
May 27 10:17:04	openvpn	98617	ACK reliable_can_send active=1 current=1 : [1] 0
May 27 10:17:04	openvpn	98617	ACK reliable_send ID 0 (size=4 to=32)
May 27 10:17:04	openvpn	98617	write_control_auth(): P_CONTROL_HARD_RESET_CLIENT_V2
May 27 10:17:04	openvpn	98617	ENCRYPT HMAC: 92bb1f18 cf2c8366 d7e8d2bf 9b56e3f7 02762ece ea7f8f39 2ff5e4b2 c507750b
May 27 10:17:04	openvpn	98617	ENCRYPT TO: 92bb1f18 cf2c8366 d7e8d2bf 9b56e3f7 02762ece ea7f8f39 2ff5e4b2 c507750[more...]
May 27 10:17:04	openvpn	98617	Reliable -> TCP/UDP
May 27 10:17:04	openvpn	98617	ACK reliable_send_timeout 32 [1] 0
May 27 10:17:04	openvpn	98617	TLS: tls_process: timeout set to 29
May 27 10:17:04	openvpn	98617	TLS: tls_multi_process: i=1 state=S_INITIAL, mysid=060639a3 0d491fb6, stored-sid=00000000 00000000, stored-ip=[AF_UNSPEC]
May 27 10:17:04	openvpn	98617	TLS: tls_multi_process: i=2 state=S_UNDEF, mysid=00000000 00000000, stored-sid=00000000 00000000, stored-ip=[AF_UNSPEC]
May 27 10:17:04	openvpn	98617	UDPv4 WRITE [54] to [AF_INET]191.101.42.152:1195: P_CONTROL_HARD_RESET_CLIENT_V2 kid=0 sid=6a6153d2 e65257b6 tls_hmac=92bb1f18 cf2c8366 d7e8d2bf 9b56e3f7 02762ece ea7f8f39 2ff5e4b2 c507750b pid=[ #5 / time = (1622128593) 2021-05-27 10:16:33 ] [ ] pid=0 DATA
May 27 10:17:04	openvpn	98617	UDPv4 write returned 54
May 27 10:17:04	openvpn	98617	TLS: tls_multi_process: i=0 state=S_PRE_START, mysid=6a6153d2 e65257b6, stored-sid=00000000 00000000, stored-ip=[AF_INET]191.101.42.152:1195
May 27 10:17:04	openvpn	98617	TLS: tls_process: chg=0 ks=S_PRE_START lame=S_UNDEF to_link->len=0 wakeup=604800
May 27 10:17:04	openvpn	98617	ACK reliable_can_send active=1 current=0 : [1] 0
May 27 10:17:04	openvpn	98617	ACK reliable_send_timeout 32 [1] 0
May 27 10:17:04	openvpn	98617	TLS: tls_process: timeout set to 29
May 27 10:17:04	openvpn	98617	TLS: tls_multi_process: i=1 state=S_INITIAL, mysid=060639a3 0d491fb6, stored-sid=00000000 00000000, stored-ip=[AF_UNSPEC]
May 27 10:17:04	openvpn	98617	TLS: tls_multi_process: i=2 state=S_UNDEF, mysid=00000000 00000000, stored-sid=00000000 00000000, stored-ip=[AF_UNSPEC]
May 27 10:17:04	openvpn	98617	PO_CTL rwflags=0x0001 ev=6 arg=0x002b6928
May 27 10:17:04	openvpn	98617	PO_CTL rwflags=0x0001 ev=3 arg=0x002b5c18
May 27 10:17:04	openvpn	98617	I/O WAIT T?|T?|SR|Sw [1/201521]
May 27 10:17:05	openvpn	98617	event_wait returned 0
May 27 10:17:05	openvpn	98617	I/O WAIT status=0x0020
May 27 10:17:05	openvpn	98617	TIMER: coarse timer wakeup 1 seconds
May 27 10:17:05	openvpn	98617	TLS: tls_multi_process: i=0 state=S_PRE_START, mysid=6a6153d2 e65257b6, stored-sid=00000000 00000000, stored-ip=[AF_INET]191.101.42.152:1195
May 27 10:17:05	openvpn	98617	TLS: tls_process: chg=0 ks=S_PRE_START lame=S_UNDEF to_link->len=0 wakeup=604800
May 27 10:17:05	openvpn	98617	ACK reliable_can_send active=1 current=0 : [1] 0
May 27 10:17:05	openvpn	98617	ACK reliable_send_timeout 31 [1] 0
May 27 10:17:05	openvpn	98617	TLS: tls_process: timeout set to 28
May 27 10:17:05	openvpn	98617	TLS: tls_multi_process: i=1 state=S_INITIAL, mysid=060639a3 0d491fb6, stored-sid=00000000 00000000, stored-ip=[AF_UNSPEC]
May 27 10:17:05	openvpn	98617	TLS: tls_multi_process: i=2 state=S_UNDEF, mysid=00000000 00000000, stored-sid=00000000 00000000, stored-ip=[AF_UNSPEC]
May 27 10:17:05	openvpn	98617	PO_CTL rwflags=0x0001 ev=6 arg=0x002b6928
May 27 10:17:05	openvpn	98617	PO_CTL rwflags=0x0001 ev=3 arg=0x002b5c18
May 27 10:17:05	openvpn	98617	I/O WAIT T?|T?|SR|Sw [1/201521]
May 27 10:17:06	openvpn	98617	event_wait returned 0
May 27 10:17:06	openvpn	98617	I/O WAIT status=0x0020
May 27 10:17:06	openvpn	98617	TIMER: coarse timer wakeup 1 seconds
May 27 10:17:06	openvpn	98617	PO_CTL rwflags=0x0001 ev=6 arg=0x002b6928
May 27 10:17:06	openvpn	98617	PO_CTL rwflags=0x0001 ev=3 arg=0x002b5c18
May 27 10:17:06	openvpn	98617	I/O WAIT T?|T?|SR|Sw [1/201521]
May 27 10:17:07	openvpn	98617	event_wait returned 0
May 27 10:17:07	openvpn	98617	I/O WAIT status=0x0020
May 27 10:17:07	openvpn	98617	TIMER: coarse timer wakeup 1 seconds
May 27 10:17:07	openvpn	98617	PO_CTL rwflags=0x0001 ev=6 arg=0x002b6928
May 27 10:17:07	openvpn	98617	PO_CTL rwflags=0x0001 ev=3 arg=0x002b5c18
May 27 10:17:07	openvpn	98617	I/O WAIT T?|T?|SR|Sw [1/201521]
May 27 10:17:09	openvpn	98617	event_wait returned 0
May 27 10:17:09	openvpn	98617	I/O WAIT status=0x0020
May 27 10:17:09	openvpn	98617	TIMER: coarse timer wakeup 1 seconds
May 27 10:17:09	openvpn	98617	PO_CTL rwflags=0x0001 ev=6 arg=0x002b6928
May 27 10:17:09	openvpn	98617	PO_CTL rwflags=0x0001 ev=3 arg=0x002b5c18
May 27 10:17:09	openvpn	98617	I/O WAIT T?|T?|SR|Sw [1/201521]
May 27 10:17:10	openvpn	98617	event_wait returned 0
May 27 10:17:10	openvpn	98617	I/O WAIT status=0x0020
May 27 10:17:10	openvpn	98617	TIMER: coarse timer wakeup 1 seconds
May 27 10:17:10	openvpn	98617	PO_CTL rwflags=0x0001 ev=6 arg=0x002b6928
May 27 10:17:10	openvpn	98617	PO_CTL rwflags=0x0001 ev=3 arg=0x002b5c18
May 27 10:17:10	openvpn	98617	I/O WAIT T?|T?|SR|Sw [1/201521]
May 27 10:17:11	openvpn	98617	event_wait returned 0
May 27 10:17:11	openvpn	98617	I/O WAIT status=0x0020
May 27 10:17:11	openvpn	98617	TIMER: coarse timer wakeup 1 seconds
May 27 10:17:11	openvpn	98617	PO_CTL rwflags=0x0001 ev=6 arg=0x002b6928
May 27 10:17:11	openvpn	98617	PO_CTL rwflags=0x0001 ev=3 arg=0x002b5c18
May 27 10:17:11	openvpn	98617	I/O WAIT T?|T?|SR|Sw [1/201521]
May 27 10:17:12	openvpn	98617	event_wait returned 0
May 27 10:17:12	openvpn	98617	I/O WAIT status=0x0020
May 27 10:17:12	openvpn	98617	TIMER: coarse timer wakeup 1 seconds
May 27 10:17:12	openvpn	98617	PO_CTL rwflags=0x0001 ev=6 arg=0x002b6928
May 27 10:17:12	openvpn	98617	PO_CTL rwflags=0x0001 ev=3 arg=0x002b5c18
May 27 10:17:12	openvpn	98617	I/O WAIT T?|T?|SR|Sw [1/201521]
May 27 10:17:13	openvpn	98617	PO_WAIT[1,0] fd=3 rev=0x00000001 rwflags=0x0001 arg=0x002b5c18
May 27 10:17:13	openvpn	98617	event_wait returned 1
May 27 10:17:13	openvpn	98617	I/O WAIT status=0x0040
May 27 10:17:13	openvpn	98617	MANAGEMENT: Client connected from /var/etc/openvpn/client1/sock
May 27 10:17:13	openvpn	98617	TIMER: coarse timer wakeup 1 seconds
May 27 10:17:13	openvpn	98617	RANDOM USEC=192571
May 27 10:17:13	openvpn	98617	PO_CTL rwflags=0x0001 ev=6 arg=0x002b6928
May 27 10:17:13	openvpn	98617	PO_CTL rwflags=0x0002 ev=5 arg=0x002b5c18
May 27 10:17:13	openvpn	98617	I/O WAIT T?|T?|SR|Sw [1/192571]
May 27 10:17:13	openvpn	98617	PO_WAIT[1,0] fd=5 rev=0x00000004 rwflags=0x0002 arg=0x002b5c18
May 27 10:17:13	openvpn	98617	event_wait returned 1
May 27 10:17:13	openvpn	98617	I/O WAIT status=0x0080
May 27 10:17:13	openvpn	98617	PO_CTL rwflags=0x0001 ev=6 arg=0x002b6928
May 27 10:17:13	openvpn	98617	PO_CTL rwflags=0x0001 ev=5 arg=0x002b5c18
May 27 10:17:13	openvpn	98617	I/O WAIT T?|T?|SR|Sw [1/192571]
May 27 10:17:13	openvpn	98617	PO_WAIT[1,0] fd=5 rev=0x00000001 rwflags=0x0001 arg=0x002b5c18
May 27 10:17:13	openvpn	98617	event_wait returned 1
May 27 10:17:13	openvpn	98617	I/O WAIT status=0x0040
May 27 10:17:13	openvpn	98617	MANAGEMENT: CMD 'state 1'
May 27 10:17:13	openvpn	98617	PO_CTL rwflags=0x0001 ev=6 arg=0x002b6928
May 27 10:17:13	openvpn	98617	PO_CTL rwflags=0x0002 ev=5 arg=0x002b5c18
May 27 10:17:13	openvpn	98617	I/O WAIT T?|T?|SR|Sw [1/192571]
May 27 10:17:13	openvpn	98617	PO_WAIT[1,0] fd=5 rev=0x00000004 rwflags=0x0002 arg=0x002b5c18
May 27 10:17:13	openvpn	98617	event_wait returned 1
May 27 10:17:13	openvpn	98617	I/O WAIT status=0x0080
May 27 10:17:13	openvpn	98617	PO_CTL rwflags=0x0001 ev=6 arg=0x002b6928
May 27 10:17:13	openvpn	98617	PO_CTL rwflags=0x0001 ev=5 arg=0x002b5c18
May 27 10:17:13	openvpn	98617	I/O WAIT T?|T?|SR|Sw [1/192571]
May 27 10:17:13	openvpn	98617	PO_WAIT[1,0] fd=5 rev=0x00000011 rwflags=0x0001 arg=0x002b5c18
May 27 10:17:13	openvpn	98617	event_wait returned 1
May 27 10:17:13	openvpn	98617	I/O WAIT status=0x0040
May 27 10:17:13	openvpn	98617	MANAGEMENT: Client disconnected

Firewall Rules.jpg Firewall Rules 01.jpg

Gertjan

@jegavelan

Your Manual NAT entries, and the second LAN firewall rule look fine to me.

These :

are Floating rules ?
if so, then that's not looking fine at all ..... Why did you create these rules ??

Same thing for DNS settings : not needed at all.

Make first a minimal Client VPN setup with https://www.youtube.com/watch?v=lp3mtR4j3Lw

Btw : when the VPN client is connected = working, drop the verbosity of the VPN log - reset it to 3. It's not needed to see enties for every byte that goes out. It tends to hide crusial information.

@jegavelan said in Express VPN Received control message: AUTH_FAILED:

re-created everything like what you have now

I used the info from my vpn's account page.
And this one : https://www.expressvpn.com/fr/support/vpn-setup/pfsense-with-expressvpn-openvpn/

Keep in mind that OpenVPN had a huge update a couple of month ago : the version used back then was 2.4.7 ( ? ) and now pfSens is using the version 2.5.1 - the future, upcoming version will be 2.5.2. This means that this ExprssVPN / pfSense help page should be double checked with the new and changed OpenVPN parameters. It's not a click here click there and go solution.
Also : I don't know what version of OpenVPN ExpessVN is using on their side. I do know that my setup worked last time I tested it, using pgSense 2.5.1 and OpenVPN .

4o4rh

@gertjan did you ever solve this?

Gertjan

@gwaitsi said in Express VPN Received control message: AUTH_FAILED:

@gertjan did you ever solve this?

Never had any issues while using 'pfSense' and 'ExpressVPN'. My connection is not actually used right now, but it's up for years now. Some maintenance is needed ones in a while, as Express can change things on their side, and pfSense also changes the OpenVPN version regularly. It's an on going read-learn-apply cycle.

Read again, I was trying to answer questions. Not asking them.

4o4rh

@gertjan yes it works, but i also have these messages in my logs for both expressvpn and protonvpn. i.e. certificate verify warning

ay 26 15:00:23	openvpn	75963	VERIFY WARNING: depth=0, unable to get certificate CRL: C=VG, ST=BVI, O=ExpressVPN, OU=ExpressVPN, CN=Server-1417-1a, emailAddress=support@expressvpn.com
May 26 15:00:23	openvpn	75963	VERIFY WARNING: depth=1, unable to get certificate CRL: C=VG, ST=BVI, O=ExpressVPN, OU=ExpressVPN, CN=ExpressVPN CA, emailAddress=support@expressvpn.com
May 26 15:00:23	openvpn	75963	VERIFY OK: depth=1, C=VG, ST=BVI, O=ExpressVPN, OU=ExpressVPN, CN=ExpressVPN CA, emailAddress=support@expressvpn.com
M