SSTP VPN via RRAS (doman joined) or AZURE using EAP-TLS using sstp-client rejects the SSTP_CALL_CONNECTED message

Question

Hello,

I have configured a DC + RRAS server (also replicated by using a Azure VNetGateway) and am trying to authenticate using EAP-TLS using sstp-client software found on sourceforge.net (https://sourceforge.net/projects/sstp-client/).

Following the PPP/SSTP packet exchange, one can observe that the EAP-TLS authentication succeeds, but the SSTP_CALL_CONNECTED is returned with a SSTP_CALL_ABORT.

sstpc[629981]: Waiting for sstp-plugin to connect on: /var/run/sstpc/sstpc-sstp-tls  
sstpc[629981]: Resolved 127.0.0.1 to 127.0.0.1  
sstpc[629981]: Connected to 127.0.0.1  
sstpc[629981]: Sending Connect-Request Message  
sstpc[629981]: SEND SSTP CRTL PKT(14)   
sstpc[629981]:   TYPE(1): CONNECT REQUEST, ATTR(1):  
sstpc[629981]:     ENCAP PROTO(1): 6  
sstpc[629981]: RECV SSTP CRTL PKT(48)   
sstpc[629981]:   TYPE(2): CONNECT ACK, ATTR(1):  
sstpc[629981]:     CRYPTO BIND REQ(4): 40  
sstpc[629981]: Started PPP Link Negotiation  
pppd[629978]: sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0xfcf9c319> <pcomp> <accomp>]  
pppd[629978]: rcvd [LCP ConfReq id=0x0 <mru 4091> <auth eap> <magic 0x2b7b65a0> <pcomp> <accomp> <callback CBCP> <mrru 1614> <endpoint [local:0c.3d.5a.e5.54.c9.4b.45.bd.96.26.d7.8e.19.91.6c.00.00.00.00]>]  
pppd[629978]: sent [LCP ConfRej id=0x0 <callback CBCP> <mrru 1614>]  
pppd[629978]: rcvd [LCP ConfAck id=0x1 <asyncmap 0x0> <magic 0xfcf9c319> <pcomp> <accomp>]  
pppd[629978]: rcvd [LCP ConfReq id=0x1 <mru 4091> <auth eap> <magic 0x2b7b65a0> <pcomp> <accomp> <endpoint [local:0c.3d.5a.e5.54.c9.4b.45.bd.96.26.d7.8e.19.91.6c.00.00.00.00]>]  
pppd[629978]: sent [LCP ConfAck id=0x1 <mru 4091> <auth eap> <magic 0x2b7b65a0> <pcomp> <accomp> <endpoint [local:0c.3d.5a.e5.54.c9.4b.45.bd.96.26.d7.8e.19.91.6c.00.00.00.00]>]  
pppd[629978]: sent [LCP EchoReq id=0x0 magic=0xfcf9c319]  
pppd[629978]: rcvd [EAP Request id=0x0 Identity <No message>]  
pppd[629978]: sent [EAP Response id=0x0 Identity <Name "******@sstp-test.com">]  
pppd[629978]: rcvd [LCP EchoRep id=0x0 magic=0x2b7b65a0]  
pppd[629978]: rcvd [EAP Request id=0x1 TLS --S]  
pppd[629978]: MTU = 1486  
pppd[629978]: calling get_eaptls_secret  
pppd[629978]: calling eaptls_init_ssl  
pppd[629978]: Loading OpenSSL config file  
pppd[629978]: EAP-TLS: Error in OpenSSL config file /etc/ppp/openssl.cnf at line 33  
pppd[629978]: Loading OpenSSL built-ins  
pppd[629978]: Loading OpenSSL configured modules  
pppd[629978]: EAP-TLS: Setting max protocol version to 0x303  
pppd[629978]: Initializing SSL BIOs  
pppd[629978]:  -> SSL/TLS Header: TLS 1.0  
pppd[629978]:  -> Handshake: Client Hello  
pppd[629978]: sent [EAP Response id=0x1 TLS --- ...]  
pppd[629978]: rcvd [EAP Request id=0x2 TLS LM- ...]  
pppd[629978]: sent [EAP Response id=0x2 TLS Ack]  
pppd[629978]: rcvd [EAP Request id=0x3 TLS --- ...]  
pppd[629978]:  <- SSL/TLS Header: TLS 1.2  
pppd[629978]:  <- Handshake: Server Hello  
pppd[629978]:  <- Handshake: Certificate  
pppd[629978]: certificate verify depth: 1  
pppd[629978]: certificate verify depth: 0  
pppd[629978]: Certificate CN: server.sstp-test.com , peer name server.sstp-test.com  
pppd[629978]:  <- Handshake: Server Key Exchange  
pppd[629978]:  <- Handshake: Certificate Request  
pppd[629978]:  <- Handshake: Server Hello Done  
pppd[629978]:  -> SSL/TLS Header: TLS 1.2  
pppd[629978]:  -> Handshake: Certificate  
pppd[629978]:  -> SSL/TLS Header: TLS 1.2  
pppd[629978]:  -> Handshake: Client Key Exchange  
pppd[629978]:  -> SSL/TLS Header: TLS 1.2  
pppd[629978]:  -> Handshake: Certificate Verify  
pppd[629978]:  -> SSL/TLS Header: TLS 1.2  
pppd[629978]:  -> ChangeCipherSpec  
pppd[629978]:  -> SSL/TLS Header: TLS 1.2  
pppd[629978]:  -> Handshake: Finished: TLS 1.2  
pppd[629978]: sent [EAP Response id=0x3 TLS LM- ...]  
pppd[629978]: rcvd [EAP Request id=0x4 TLS Ack]  
pppd[629978]: sent [EAP Response id=0x4 TLS --- ...]  
pppd[629978]: rcvd [EAP Request id=0x5 TLS L-- ...]  
pppd[629978]:  <- SSL/TLS Header: TLS 1.2  
pppd[629978]:  <- SSL/TLS Header: TLS 1.2  
pppd[629978]:  <- Handshake: Finished: TLS 1.2  
pppd[629978]: EAP-TLS: Post-Handshake New Session Ticket arrived:  
pppd[629978]: EAP-TLS generating MPPE keys  
pppd[629978]: EAP-TLS PRF label = client EAP encryption  
pppd[629978]: sent [EAP Response id=0x5 TLS Ack]  
pppd[629978]: rcvd [EAP Success id=0x5]  
pppd[629978]: EAP authentication succeeded  
pppd[629978]: MPPE Send Key:  bc cf 76 da 4a f1 3f 03 f7 9e 09 64 60 7c b4 8d  
pppd[629978]: MPPE Recv Key:  f9 1c 6f 2a d3 09 f5 33 4f b4 a0 4e 3f d0 ef 7d  
sstpc[629981]: Received callback from sstp-plugin  
sstpc[629981]: Sending Connected Message  
sstpc[629981]: SEND SSTP CRTL PKT(112)   
sstpc[629981]:   TYPE(4): CONNECTED, ATTR(1):  
sstpc[629981]:     CRYPTO BIND(3): 104  
sstpc[629981]: Connection Established  
pppd[629978]: sent [CCP ConfReq id=0x1 <mppe +H -M +S -L -D -C>]  
pppd[629978]: rcvd [CCP ConfReq id=0x8 <mppe +H -M -S -L -D +C>]  
pppd[629978]: sent [CCP ConfNak id=0x8 <mppe +H -M +S -L -D -C>]  
pppd[629978]: rcvd [IPCP ConfReq id=0x9 <addr 172.16.0.135>]  
pppd[629978]: sent [IPCP TermAck id=0x9]  
sstpc[629981]: RECV SSTP CRTL PKT(20)   
sstpc[629981]:   TYPE(5): ABORT, ATTR(1):  
sstpc[629981]:     STATUS INFO(2): 12  
sstpc[629981]: Connection was aborted, Value of attribute is incorrect  
pppd[629978]: Modem hangup  
pppd[629978]: Connection terminated.  
pppd[629978]: Script sstpc --ipparam sstp-tls --cert-warn --nolaunchpppd --log-level 4 127.0.0.1:4443 finished (pid 629979), status = 0xff  
pppd[629978]: Exit.  

Now, I move the callback to send the SSTP_CALL_CONNECTED message to after IP-UP has been called, and use all-0s for MPPE send/recv keys. And the connection authenticates.

sstpc[630378]: Waiting for sstp-plugin to connect on: /var/run/sstpc/sstpc-sstp-tls  
sstpc[630378]: Resolved 127.0.0.1 to 127.0.0.1  
sstpc[630378]: Connected to 127.0.0.1  
sstpc[630378]: Sending Connect-Request Message  
sstpc[630378]: SEND SSTP CRTL PKT(14)   
sstpc[630378]:   TYPE(1): CONNECT REQUEST, ATTR(1):  
sstpc[630378]:     ENCAP PROTO(1): 6  
sstpc[630378]: RECV SSTP CRTL PKT(48)   
sstpc[630378]:   TYPE(2): CONNECT ACK, ATTR(1):  
sstpc[630378]:     CRYPTO BIND REQ(4): 40  
sstpc[630378]: Started PPP Link Negotiation  
pppd[630376]: sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0x59c31204> <pcomp> <accomp>]  
pppd[630376]: rcvd [LCP ConfReq id=0x0 <mru 4091> <auth eap> <magic 0x159a4a8a> <pcomp> <accomp> <callback CBCP> <mrru 1614> <endpoint [local:0c.3d.5a.e5.54.c9.4b.45.bd.96.26.d7.8e.19.91.6c.00.00.00.00]>]  
pppd[630376]: sent [LCP ConfRej id=0x0 <callback CBCP> <mrru 1614>]  
pppd[630376]: rcvd [LCP ConfAck id=0x1 <asyncmap 0x0> <magic 0x59c31204> <pcomp> <accomp>]  
pppd[630376]: rcvd [LCP ConfReq id=0x1 <mru 4091> <auth eap> <magic 0x159a4a8a> <pcomp> <accomp> <endpoint [local:0c.3d.5a.e5.54.c9.4b.45.bd.96.26.d7.8e.19.91.6c.00.00.00.00]>]  
pppd[630376]: sent [LCP ConfAck id=0x1 <mru 4091> <auth eap> <magic 0x159a4a8a> <pcomp> <accomp> <endpoint [local:0c.3d.5a.e5.54.c9.4b.45.bd.96.26.d7.8e.19.91.6c.00.00.00.00]>]  
pppd[630376]: sent [LCP EchoReq id=0x0 magic=0x59c31204]  
pppd[630376]: rcvd [EAP Request id=0x0 Identity <No message>]  
pppd[630376]: sent [EAP Response id=0x0 Identity <Name "******@sstp-test.com">]  
pppd[630376]: rcvd [LCP EchoRep id=0x0 magic=0x159a4a8a]  
pppd[630376]: rcvd [EAP Request id=0x1 TLS --S]  
pppd[630376]: MTU = 1486  
pppd[630376]: calling get_eaptls_secret  
pppd[630376]: calling eaptls_init_ssl  
pppd[630376]: Loading OpenSSL config file  
pppd[630376]: EAP-TLS: Error in OpenSSL config file /etc/ppp/openssl.cnf at line 33  
pppd[630376]: Loading OpenSSL built-ins  
pppd[630376]: Loading OpenSSL configured modules  
pppd[630376]: EAP-TLS: Setting max protocol version to 0x303  
pppd[630376]: Initializing SSL BIOs  
pppd[630376]:  -> SSL/TLS Header: TLS 1.0  
pppd[630376]:  -> Handshake: Client Hello  
pppd[630376]: sent [EAP Response id=0x1 TLS --- ...]  
pppd[630376]: rcvd [EAP Request id=0x2 TLS LM- ...]  
pppd[630376]: sent [EAP Response id=0x2 TLS Ack]  
pppd[630376]: rcvd [EAP Request id=0x3 TLS --- ...]  
pppd[630376]:  <- SSL/TLS Header: TLS 1.2  
pppd[630376]:  <- Handshake: Server Hello  
pppd[630376]:  <- Handshake: Certificate  
pppd[630376]: certificate verify depth: 1  
pppd[630376]: certificate verify depth: 0  
pppd[630376]: Certificate CN: server.sstp-test.com , peer name server.sstp-test.com  
pppd[630376]:  <- Handshake: Server Key Exchange  
pppd[630376]:  <- Handshake: Certificate Request  
pppd[630376]:  <- Handshake: Server Hello Done  
pppd[630376]:  -> SSL/TLS Header: TLS 1.2  
pppd[630376]:  -> Handshake: Certificate  
pppd[630376]:  -> SSL/TLS Header: TLS 1.2  
pppd[630376]:  -> Handshake: Client Key Exchange  
pppd[630376]:  -> SSL/TLS Header: TLS 1.2  
pppd[630376]:  -> Handshake: Certificate Verify  
pppd[630376]:  -> SSL/TLS Header: TLS 1.2  
pppd[630376]:  -> ChangeCipherSpec  
pppd[630376]:  -> SSL/TLS Header: TLS 1.2  
pppd[630376]:  -> Handshake: Finished: TLS 1.2  
pppd[630376]: sent [EAP Response id=0x3 TLS LM- ...]  
pppd[630376]: rcvd [EAP Request id=0x4 TLS Ack]  
pppd[630376]: sent [EAP Response id=0x4 TLS --- ...]  
pppd[630376]: rcvd [EAP Request id=0x5 TLS L-- ...]  
pppd[630376]:  <- SSL/TLS Header: TLS 1.2  
pppd[630376]:  <- SSL/TLS Header: TLS 1.2  
pppd[630376]:  <- Handshake: Finished: TLS 1.2  
pppd[630376]: EAP-TLS: Post-Handshake New Session Ticket arrived:  
pppd[630376]: EAP-TLS generating MPPE keys  
pppd[630376]: EAP-TLS PRF label = client EAP encryption  
pppd[630376]: sent [EAP Response id=0x5 TLS Ack]  
pppd[630376]: rcvd [EAP Success id=0x5]  
pppd[630376]: EAP authentication succeeded  
pppd[630376]: sent [CCP ConfReq id=0x1 <mppe +H -M +S -L -D -C>]  
pppd[630376]: rcvd [CCP ConfReq id=0x8 <mppe +H -M -S -L -D +C>]  
pppd[630376]: sent [CCP ConfNak id=0x8 <mppe +H -M +S -L -D -C>]  
pppd[630376]: rcvd [IPCP ConfReq id=0x9 <addr 172.16.0.135>]  
pppd[630376]: sent [IPCP TermAck id=0x9]  
pppd[630376]: rcvd [CCP ConfAck id=0x1 <mppe +H -M +S -L -D -C>]  
pppd[630376]: rcvd [CCP ConfReq id=0xa <mppe +H -M +S -L -D -C>]  
pppd[630376]: sent [CCP ConfAck id=0xa <mppe +H -M +S -L -D -C>]  
pppd[630376]: MPPE 128-bit stateless compression enabled  
pppd[630376]: sent [IPCP ConfReq id=0x1 <addr 0.0.0.0>]  
pppd[630376]: sent [IPV6CP ConfReq id=0x1 <addr fe80::d9af:d1d2:9766:6e6b>]  
pppd[630376]: rcvd [IPCP ConfNak id=0x1 <addr 172.16.0.139>]  
pppd[630376]: sent [IPCP ConfReq id=0x2 <addr 172.16.0.139>]  
pppd[630376]: rcvd [LCP ProtRej id=0xb 80 57 01 01 00 0e 01 0a d9 af d1 d2 97 66 6e 6b]  
pppd[630376]: Protocol-Reject for 'IPv6 Control Protocol' (0x8057) received  
pppd[630376]: rcvd [IPCP ConfAck id=0x2 <addr 172.16.0.139>]  
pppd[630376]: rcvd [IPCP ConfReq id=0xc <addr 172.16.0.135>]  
pppd[630376]: sent [IPCP ConfAck id=0xc <addr 172.16.0.135>]  
pppd[630376]: local  IP address 172.16.0.139  
pppd[630376]: remote IP address 172.16.0.135  
pppd[630376]: MPPE Send Key:  00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00  
pppd[630376]: MPPE Recv Key:  00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00  
sstpc[630378]: Received callback from sstp-plugin  
sstpc[630378]: Sending Connected Message  
sstpc[630378]: SEND SSTP CRTL PKT(112)   
sstpc[630378]:   TYPE(4): CONNECTED, ATTR(1):  
sstpc[630378]:     CRYPTO BIND(3): 104  
sstpc[630378]: Connection Established  
pppd[630376]: Script /etc/ppp/ip-up started (pid 630386)  
pppd[630376]: Script /etc/ppp/ip-up finished (pid 630386), status = 0x0  

I am now able to ping the peer of the ppp connection, and the connection remains up for > 60s which implies the server did receive the "correct" value for the SSTP_CALL_CONNECTED message. With "correct" I mean, the server likely did a memset() on the MPPE keys during CCP UP and that it accepted the value of the CMAC attribute. Notice that the logs also enabled MPPE encryption on the PPP packets, and that the MPPE keys generated for the TLS connection is correct (both send and receive) as am able to send and receive ICMP datagrams to/from the peer.

/etc/ppp/peers# ifconfig ppp0  
ppp0: flags=4305<UP,POINTOPOINT,RUNNING,NOARP,MULTICAST>  mtu 1496  
        inet 172.16.0.139  netmask 255.255.255.255  destination 172.16.0.135  
        ppp  txqueuelen 3  (Point-to-Point Protocol)  
        RX packets 167  bytes 11696 (11.6 KB)  
        RX errors 0  dropped 0  overruns 0  frame 0  
        TX packets 8  bytes 78 (78.0 B)  
        TX errors 0  dropped 0 overruns 0  carrier 0  collisions 0  
  
/etc/ppp/peers# ping 172.16.0.135  
PING 172.16.0.135 (172.16.0.135) 56(84) bytes of data.  
64 bytes from 172.16.0.135: icmp_seq=1 ttl=128 time=224 ms  
64 bytes from 172.16.0.135: icmp_seq=2 ttl=128 time=34.1 ms  
^C  
--- 172.16.0.135 ping statistics ---  
2 packets transmitted, 2 received, 0% packet loss, time 1001ms  
rtt min/avg/max/mdev = 34.072/129.141/224.211/95.069 ms  
/etc/ppp/peers#   

I note that using all-0s for MPPE keys just after the authentication has completed still causes the server to reject the SSTP_CALL_CONNECTED message. Using the configured MPPE send/recv keys from the SSL_PRF function which can be verified being correct during this step causes also the SSTP_CALL_CONNECTED message to be rejected.

Note that MS-SSTP protocol make no difference between EAP-MSCHAPv2 and EAP-TLS as far as I can tell when it comes to the CMAC generation for the SSTP_CALL_CONNECTED attribute. Using EAP-MSCHAPv2 works and the CMAC attribute of the SSTP_CALL_CONNECTED message is correct.

Answer 1

I have a similar problem when using VPN Tracker 365 on Mac - which since recently supports SSTP.
The error message I'm getting is: (obviously, the root certificate is installed on the Azure VPN gateway, and connection from the Windows 10 VPN client does work. But not everybody can or wants to use Windows clients...)

15:52:31 <<< PPP incoming
000000 C2 27 01 05 00 11 0D 80 00 00 00 07 15 03 01 00 .'..............
000010 02 02 31 ..1
15:52:31 Server declined the user certificate
15:52:31 Error handling incoming data: AuthenticationFailed_EAPTLS (PPPError code 11)

15:52:31    User Authentication Failed (PPP)

    The VPN gateway rejected the user certificate we sent. If the connection has worked before, the user database of the remote gateway might be temporarily out of service.

    Try this:
    •  Please try to connect again in a couple of minutes  

    If this is the first time you're using this connection:

    •  Please enter your user certificate again and then connect again 

    If you already did that, please check the following on your VPN gateway (or ask your VPN gateway's administrator to check it):

    •  Make sure that a user record with the given certificate exists on the VPN gateway
    •  Check the VPN gateway's log for details on the failed connection attempt

    Status: 0x91830 (PPPD_LOGIN_REJECTED_EAPTLS)