Project

General

Profile

Issue #3673

IKEv2/IPSec MSCHAPv2 fails on Android 11 (API 30).

Added by Heath Snoek 3 months ago. Updated 3 months ago.

Status:
Feedback
Priority:
Normal
Category:
configuration
Affected version:
5.9.1
Resolution:

Description

I'm unable to connect using the new support for IKEv2 MSCHAPv2 enabled in the latest Android 11.

Here is relevant syslog entry:

Jan 14 03:26:39 ip-172-31-0-128 charon: 03[NET] received packet: from <my ip>[43427] to 172.31.0.128[500]                                                                                                                                                               
Jan 14 03:26:39 ip-172-31-0-128 charon: 03[NET] waiting for data on sockets                                                                                                                                                                                                     
Jan 14 03:26:39 ip-172-31-0-128 charon: 06[NET] received packet: from <my ip>[43427] to 172.31.0.128[500] (940 bytes)                                                                                                                                                   
Jan 14 03:26:39 ip-172-31-0-128 charon: 06[ENC] parsed IKE_SA_INIT request 0 [ SA No KE N(NATD_S_IP) N(NATD_D_IP) N(FRAG_SUP) N(HASH_ALG) ]                                                                                                                                     
Jan 14 03:26:39 ip-172-31-0-128 charon: 06[CFG] looking for an ike config for 172.31.0.128...<my ip>                                                                                                                                                                    
Jan 14 03:26:39 ip-172-31-0-128 charon: 06[CFG]   candidate: %any...%any, prio 24                                                                                                                                                                                               
Jan 14 03:26:39 ip-172-31-0-128 charon: 06[CFG] found matching ike config: %any...%any with prio 24                                                                                                                                                                             
Jan 14 03:26:39 ip-172-31-0-128 charon: 06[IKE] <my ip> is initiating an IKE_SA                                                                                                                                                                                         
Jan 14 03:26:39 ip-172-31-0-128 charon: 06[IKE] IKE_SA (unnamed)[71] state change: CREATED => CONNECTING                                                                                                                                                                        
Jan 14 03:26:39 ip-172-31-0-128 charon: 06[CFG] selecting proposal:                                                                                                                                                                                                             
Jan 14 03:26:39 ip-172-31-0-128 charon: 06[CFG]   no acceptable ENCRYPTION_ALGORITHM found                                                                                                                                                                                      
Jan 14 03:26:39 ip-172-31-0-128 charon: 06[CFG] selecting proposal:                                                                                                                                                                                                             
Jan 14 03:26:39 ip-172-31-0-128 charon: 06[CFG]   no acceptable PSEUDO_RANDOM_FUNCTION found                                                                                                                                                                                    
Jan 14 03:26:39 ip-172-31-0-128 charon: 06[CFG] selecting proposal:                                                                                                                                                                                                             
Jan 14 03:26:39 ip-172-31-0-128 charon: 06[CFG]   no acceptable PSEUDO_RANDOM_FUNCTION found                                                                                                                                                                                    
Jan 14 03:26:39 ip-172-31-0-128 charon: 06[CFG] selecting proposal:                                                                                                                                                                                                             
Jan 14 03:26:39 ip-172-31-0-128 charon: 06[CFG]   no acceptable ENCRYPTION_ALGORITHM found                                                                                                                                                                                      
Jan 14 03:26:39 ip-172-31-0-128 charon: 06[CFG] selecting proposal:                                                                                                                                                                                                             
Jan 14 03:26:39 ip-172-31-0-128 charon: 06[CFG]   proposal matches                                                                                                                                                                                                              
Jan 14 03:26:39 ip-172-31-0-128 charon: 06[CFG] received proposals: IKE:AES_CBC_256/AES_CBC_192/AES_CBC_128/HMAC_SHA2_512_256/HMAC_SHA2_384_192/HMAC_SHA2_256_128/AES_XCBC_96/PRF_HMAC_SHA1/PRF_AES128_XCBC/MODP_4096/MODP_3072/MODP_2048, IKE:AES_GCM_16_256/AES_GCM_12_256/AES
_GCM_8_256/AES_GCM_16_192/AES_GCM_12_192/AES_GCM_8_192/AES_GCM_16_128/AES_GCM_12_128/AES_GCM_8_128/PRF_HMAC_SHA1/PRF_AES128_XCBC/MODP_4096/MODP_3072/MODP_2048                                                                                                                  
Jan 14 03:26:39 ip-172-31-0-128 charon: 06[CFG] configured proposals: IKE:AES_GCM_16_192/AES_GCM_16_128/PRF_HMAC_SHA2_256/ECP_256/ECP_521, IKE:AES_CBC_192/HMAC_SHA2_256_128/PRF_HMAC_SHA2_256/MODP_3072, IKE:AES_CBC_128/AES_CBC_192/AES_CBC_256/AES_CTR_128/AES_CTR_192/AES_CT
R_256/CAMELLIA_CBC_128/CAMELLIA_CBC_192/CAMELLIA_CBC_256/3DES_CBC/HMAC_SHA2_256_128/HMAC_SHA2_384_192/HMAC_SHA2_512_256/AES_XCBC_96/AES_CMAC_96/HMAC_MD5_96/HMAC_SHA1_96/PRF_AES128_XCBC/PRF_AES128_CMAC/PRF_HMAC_SHA2_256/PRF_HMAC_SHA2_384/PRF_HMAC_SHA2_512/PRF_HMAC_MD5/PRF_
HMAC_SHA1/ECP_256/ECP_384/ECP_521/ECP_256_BP/ECP_384_BP/ECP_512_BP/MODP_3072/MODP_4096/MODP_8192/MODP_2048/MODP_2048_256/MODP_1024, IKE:AES_CCM_16_128/AES_CCM_16_192/AES_CCM_16_256/AES_GCM_16_128/AES_GCM_16_192/AES_GCM_16_256/AES_CCM_8_128/AES_CCM_8_192/AES_CCM_8_256/AES_
CCM_12_128/AES_CCM_12_192/AES_CCM_12_256/AES_GCM_8_128/AES_GCM_8_192/AES_GCM_8_256/AES_GCM_12_128/AES_GCM_12_192/AES_GCM_12_256/PRF_AES128_XCBC/PRF_AES128_CMAC/PRF_HMAC_SHA2_256/PRF_HMAC_SHA2_384/PRF_HMAC_SHA2_512/PRF_HMAC_MD5/PRF_HMAC_SHA1/ECP_256/ECP_384/ECP_521/ECP_256
_BP/ECP_384_BP/ECP_512_BP/MODP_3072/MODP_4096/MODP_8192/MODP_2048/MODP_2048_256/MODP_1024                                                                                                                                                                                       
Jan 14 03:26:39 ip-172-31-0-128 charon: 06[CFG] selected proposal: IKE:AES_CBC_128/HMAC_SHA2_256_128/PRF_AES128_XCBC/MODP_3072                                                                                                                                                  
Jan 14 03:26:39 ip-172-31-0-128 charon: 06[IKE] local host is behind NAT, sending keep alives                                                                                                                                                                                   
Jan 14 03:26:39 ip-172-31-0-128 charon: 06[IKE] remote host is behind NAT                                                                                                                                                                                                       
Jan 14 03:26:39 ip-172-31-0-128 charon: 06[IKE] DH group MODP_4096 inacceptable, requesting MODP_3072                                                                                                                                                                           
Jan 14 03:26:39 ip-172-31-0-128 charon: 06[ENC] generating IKE_SA_INIT response 0 [ N(INVAL_KE) ]                                                                                                                                                                               
Jan 14 03:26:39 ip-172-31-0-128 charon: 06[NET] sending packet: from 172.31.0.128[500] to <my ip>[43427] (38 bytes)                                                                                                                                                     
Jan 14 03:26:39 ip-172-31-0-128 charon: 06[IKE] IKE_SA (unnamed)[71] state change: CONNECTING => DESTROYING                                                                                                                                                                     
Jan 14 03:26:39 ip-172-31-0-128 charon: 01[JOB] next event in 19s 999ms, waiting                                                                                                                                                                                                
Jan 14 03:26:39 ip-172-31-0-128 charon: 04[NET] sending packet: from 172.31.0.128[500] to <my ip>[43427]                                                                                                                                                                
Jan 14 03:26:39 ip-172-31-0-128 charon: 03[NET] received packet: from <my ip>[43427] to 172.31.0.128[500]                                                                                                                                                               
Jan 14 03:26:39 ip-172-31-0-128 charon: 03[NET] waiting for data on sockets                                                                                                                                                                                                     
Jan 14 03:26:39 ip-172-31-0-128 charon: 15[NET] received packet: from <my ip>[43427] to 172.31.0.128[500] (812 bytes)                                                                                                                                                   
Jan 14 03:26:39 ip-172-31-0-128 charon: 15[ENC] parsed IKE_SA_INIT request 0 [ SA No KE N(NATD_S_IP) N(NATD_D_IP) N(FRAG_SUP) N(HASH_ALG) ]                                                                                                                                     
Jan 14 03:26:39 ip-172-31-0-128 charon: 15[CFG] looking for an ike config for 172.31.0.128...<my ip>                                                                                                                                                                    
Jan 14 03:26:39 ip-172-31-0-128 charon: 15[CFG]   candidate: %any...%any, prio 24                                                                                                                                                                                               
Jan 14 03:26:39 ip-172-31-0-128 charon: 15[CFG] found matching ike config: %any...%any with prio 24                                                                                                                                                                             
Jan 14 03:26:39 ip-172-31-0-128 charon: 15[IKE] <my ip> is initiating an IKE_SA                                                                                                                                                                                         
Jan 14 03:26:39 ip-172-31-0-128 charon: 15[IKE] IKE_SA (unnamed)[72] state change: CREATED => CONNECTING                                                                                                                                                                        
Jan 14 03:26:39 ip-172-31-0-128 charon: 15[CFG] selecting proposal:                                                                                                                                                                                                             
Jan 14 03:26:39 ip-172-31-0-128 charon: 15[CFG]   no acceptable ENCRYPTION_ALGORITHM found                                                                                                                                                                                      
Jan 14 03:26:39 ip-172-31-0-128 charon: 15[CFG] selecting proposal:                                                                                                                                                                                                             
Jan 14 03:26:39 ip-172-31-0-128 charon: 15[CFG]   no acceptable PSEUDO_RANDOM_FUNCTION found                                                                                                                                                                                    
Jan 14 03:26:39 ip-172-31-0-128 charon: 15[CFG] selecting proposal:                                                                                                                                                                                                             
Jan 14 03:26:39 ip-172-31-0-128 charon: 15[CFG]   no acceptable PSEUDO_RANDOM_FUNCTION found                                                                                                                                                                                    
Jan 14 03:26:39 ip-172-31-0-128 charon: 15[CFG] selecting proposal:                                                                                                                                                                                                             
Jan 14 03:26:39 ip-172-31-0-128 charon: 15[CFG]   no acceptable ENCRYPTION_ALGORITHM found                                                                                                                                                                                      
Jan 14 03:26:39 ip-172-31-0-128 charon: 15[CFG] selecting proposal:                                                                     
Jan 14 03:26:39 ip-172-31-0-128 charon: 15[CFG]   proposal matches                                                                      
Jan 14 03:26:39 ip-172-31-0-128 charon: 15[CFG] received proposals: IKE:AES_CBC_256/AES_CBC_192/AES_CBC_128/HMAC_SHA2_512_256/HMAC_SHA2_384_192/HMAC_SHA2_256_128/AES_XCBC_96/PRF_HMAC_SHA1/PRF_AES128_XCBC/MODP_4096/MODP_3072/MODP_2048, IKE:AES_GCM_16_256/AES_GCM_12_256/AES
_GCM_8_256/AES_GCM_16_192/AES_GCM_12_192/AES_GCM_8_192/AES_GCM_16_128/AES_GCM_12_128/AES_GCM_8_128/PRF_HMAC_SHA1/PRF_AES128_XCBC/MODP_4096/MODP_3072/MODP_2048
Jan 14 03:26:39 ip-172-31-0-128 charon: 15[CFG] configured proposals: IKE:AES_GCM_16_192/AES_GCM_16_128/PRF_HMAC_SHA2_256/ECP_256/ECP_521, IKE:AES_CBC_192/HMAC_SHA2_256_128/PRF_HMAC_SHA2_256/MODP_3072, IKE:AES_CBC_128/AES_CBC_192/AES_CBC_256/AES_CTR_128/AES_CTR_192/AES_CT
R_256/CAMELLIA_CBC_128/CAMELLIA_CBC_192/CAMELLIA_CBC_256/3DES_CBC/HMAC_SHA2_256_128/HMAC_SHA2_384_192/HMAC_SHA2_512_256/AES_XCBC_96/AES_CMAC_96/HMAC_MD5_96/HMAC_SHA1_96/PRF_AES128_XCBC/PRF_AES128_CMAC/PRF_HMAC_SHA2_256/PRF_HMAC_SHA2_384/PRF_HMAC_SHA2_512/PRF_HMAC_MD5/PRF_
HMAC_SHA1/ECP_256/ECP_384/ECP_521/ECP_256_BP/ECP_384_BP/ECP_512_BP/MODP_3072/MODP_4096/MODP_8192/MODP_2048/MODP_2048_256/MODP_1024, IKE:AES_CCM_16_128/AES_CCM_16_192/AES_CCM_16_256/AES_GCM_16_128/AES_GCM_16_192/AES_GCM_16_256/AES_CCM_8_128/AES_CCM_8_192/AES_CCM_8_256/AES_
CCM_12_128/AES_CCM_12_192/AES_CCM_12_256/AES_GCM_8_128/AES_GCM_8_192/AES_GCM_8_256/AES_GCM_12_128/AES_GCM_12_192/AES_GCM_12_256/PRF_AES128_XCBC/PRF_AES128_CMAC/PRF_HMAC_SHA2_256/PRF_HMAC_SHA2_384/PRF_HMAC_SHA2_512/PRF_HMAC_MD5/PRF_HMAC_SHA1/ECP_256/ECP_384/ECP_521/ECP_256
_BP/ECP_384_BP/ECP_512_BP/MODP_3072/MODP_4096/MODP_8192/MODP_2048/MODP_2048_256/MODP_1024                                               
Jan 14 03:26:39 ip-172-31-0-128 charon: 15[CFG] selected proposal: IKE:AES_CBC_128/HMAC_SHA2_256_128/PRF_AES128_XCBC/MODP_3072        
Jan 14 03:26:39 ip-172-31-0-128 charon: 15[CFG] selected proposal: IKE:AES_CBC_128/HMAC_SHA2_256_128/PRF_AES128_XCBC/MODP_3072                                                                                                                                         [20/3801]
Jan 14 03:26:39 ip-172-31-0-128 charon: 15[LIB] size of DH secret exponent: 3071 bits                                                                                                                                                                                           
Jan 14 03:26:39 ip-172-31-0-128 charon: 15[IKE] local host is behind NAT, sending keep alives                                                                                                                                                                                   
Jan 14 03:26:39 ip-172-31-0-128 charon: 01[JOB] next event in 19s 900ms, waiting                                                                                                                                                                                                
Jan 14 03:26:39 ip-172-31-0-128 charon: 15[IKE] remote host is behind NAT                                                                                                                                                                                                       
Jan 14 03:26:39 ip-172-31-0-128 charon: 15[IKE] sending cert request for "CN=VPN root CA"                                                                                                                                                                                       
Jan 14 03:26:39 ip-172-31-0-128 charon: 15[ENC] generating IKE_SA_INIT response 0 [ SA KE No N(NATD_S_IP) N(NATD_D_IP) CERTREQ N(FRAG_SUP) N(HASH_ALG) N(MULT_AUTH) ]                                                                                                           
Jan 14 03:26:39 ip-172-31-0-128 charon: 15[NET] sending packet: from 172.31.0.128[500] to <my ip>[43427] (617 bytes)                                                                                                                                                    
Jan 14 03:26:39 ip-172-31-0-128 charon: 04[NET] sending packet: from 172.31.0.128[500] to <my ip>[43427]                                                                                                                                                                
Jan 14 03:26:39 ip-172-31-0-128 charon: 01[JOB] next event in 19s 897ms, waiting                                                                                                                                                                                                
Jan 14 03:26:39 ip-172-31-0-128 charon: 03[NET] received packet: from <my ip>[40773] to 172.31.0.128[4500]                                                                                                                                                              
Jan 14 03:26:39 ip-172-31-0-128 charon: 03[NET] waiting for data on sockets                                                                                                                                                                                                     
Jan 14 03:26:39 ip-172-31-0-128 charon: 07[NET] received packet: from <my ip>[40773] to 172.31.0.128[4500] (400 bytes)                                                                                                                                                  
Jan 14 03:26:39 ip-172-31-0-128 charon: 07[ENC] parsed IKE_AUTH request 1 [ IDi IDr SA TSi TSr CPRQ(ADDR ADDR6 DNS DNS6 MASK VER) ]                                                                                                                                             
Jan 14 03:26:39 ip-172-31-0-128 charon: 07[CFG] looking for peer configs matching 172.31.0.128[<server>]...<my ip>[<username>]                                                                                                                                     
Jan 14 03:26:39 ip-172-31-0-128 charon: 07[CFG]   candidate "ikev2-eap-mschapv2", match: 20/1/24 (me/other/ike)                                                                                                                                                                 
Jan 14 03:26:39 ip-172-31-0-128 charon: 07[CFG] selected peer config 'ikev2-eap-mschapv2'                                                                                                                                                                                       
Jan 14 03:26:39 ip-172-31-0-128 charon: 07[IKE] initiating EAP_IDENTITY method (id 0x00)                                                                                                                                                                                        
Jan 14 03:26:39 ip-172-31-0-128 charon: 07[IKE] processing INTERNAL_IP4_ADDRESS attribute                                                                                                                                                                                       
Jan 14 03:26:39 ip-172-31-0-128 charon: 07[IKE] processing INTERNAL_IP6_ADDRESS attribute                                                                                                                                                                                       
Jan 14 03:26:39 ip-172-31-0-128 charon: 07[IKE] processing INTERNAL_IP4_DNS attribute                                                                                                                                                                                           
Jan 14 03:26:39 ip-172-31-0-128 charon: 07[IKE] processing INTERNAL_IP6_DNS attribute                                                                                                                                                                                           
Jan 14 03:26:39 ip-172-31-0-128 charon: 07[IKE] processing INTERNAL_IP4_NETMASK attribute                                                                                                                                                                                       
Jan 14 03:26:39 ip-172-31-0-128 charon: 07[IKE] processing APPLICATION_VERSION attribute                                                                                                                                                                                        
Jan 14 03:26:39 ip-172-31-0-128 charon: 07[IKE] authentication of '<server>' (myself) with RSA_EMSA_PKCS1_SHA2_384 successful                                                                                                                                              
Jan 14 03:26:40 ip-172-31-0-128 charon: 07[IKE] sending end entity cert "CN=<server>"                                                                                                                                                                                      
Jan 14 03:26:40 ip-172-31-0-128 charon: 07[ENC] generating IKE_AUTH response 1 [ IDr CERT AUTH EAP/REQ/ID ]                                                                                                                                                                     
Jan 14 03:26:40 ip-172-31-0-128 charon: 07[ENC] splitting IKE message with length of 1936 bytes into 2 fragments                                                                                                                                                                
Jan 14 03:26:40 ip-172-31-0-128 charon: 07[ENC] generating IKE_AUTH response 1 [ EF(1/2) ]                                                                                                                                                                                      
Jan 14 03:26:40 ip-172-31-0-128 charon: 07[ENC] generating IKE_AUTH response 1 [ EF(2/2) ]                                                                                                                                                                                      
Jan 14 03:26:40 ip-172-31-0-128 charon: 07[NET] sending packet: from 172.31.0.128[4500] to <my ip>[40773] (1236 bytes)                                                                                                                                                  
Jan 14 03:26:40 ip-172-31-0-128 charon: 04[NET] sending packet: from 172.31.0.128[4500] to <my ip>[40773]                                                                                                                                                               
Jan 14 03:26:40 ip-172-31-0-128 charon: 07[NET] sending packet: from 172.31.0.128[4500] to <my ip>[40773] (772 bytes)                                                                                                                                                   
Jan 14 03:26:40 ip-172-31-0-128 charon: 04[NET] sending packet: from 172.31.0.128[4500] to <my ip>[40773]                                                                                                                                                               
Jan 14 03:26:40 ip-172-31-0-128 charon: 03[NET] received packet: from <my ip>[40773] to 172.31.0.128[4500]                                                                                                                                                              
Jan 14 03:26:40 ip-172-31-0-128 charon: 03[NET] waiting for data on sockets                                                                                                                                                                                                     
Jan 14 03:26:40 ip-172-31-0-128 charon: 08[NET] received packet: from <my ip>[40773] to 172.31.0.128[4500] (80 bytes)                                                                                                                                                   
Jan 14 03:26:40 ip-172-31-0-128 charon: 08[ENC] parsed IKE_AUTH request 2 [ EAP/RES/ID ]                                                                                                                                                                                        
Jan 14 03:26:40 ip-172-31-0-128 charon: 08[IKE] initiating EAP_MSCHAPV2 method (id 0x02)                                                                                                                                                                                        
Jan 14 03:26:40 ip-172-31-0-128 charon: 08[ENC] generating IKE_AUTH response 2 [ EAP/REQ/MSCHAPV2 ]                                                                                                                                                                             
Jan 14 03:26:40 ip-172-31-0-128 charon: 08[NET] sending packet: from 172.31.0.128[4500] to <my ip>[40773] (112 bytes)                                                                                                                                                   
Jan 14 03:26:40 ip-172-31-0-128 charon: 04[NET] sending packet: from 172.31.0.128[4500] to <my ip>[40773]                                                                                                                                                               
Jan 14 03:26:40 ip-172-31-0-128 dhclient[374]: XMT: Solicit on eth0, interval 128930ms.                                                                                                                                                                                         
Jan 14 03:26:40 ip-172-31-0-128 charon: 03[NET] received packet: from <my ip>[40773] to 172.31.0.128[4500]                                                                                                                                                              
Jan 14 03:26:40 ip-172-31-0-128 charon: 03[NET] waiting for data on sockets                                                                                                                                                                                                     
Jan 14 03:26:40 ip-172-31-0-128 charon: 12[NET] received packet: from <my ip>[40773] to 172.31.0.128[4500] (144 bytes)                                                                                                                                                  
Jan 14 03:26:40 ip-172-31-0-128 charon: 12[ENC] parsed IKE_AUTH request 3 [ EAP/RES/MSCHAPV2 ]                                                                                                                                                                                  
Jan 14 03:26:40 ip-172-31-0-128 charon: 12[ENC] generating IKE_AUTH response 3 [ EAP/REQ/MSCHAPV2 ]                                                                                                                                                                             
Jan 14 03:26:40 ip-172-31-0-128 charon: 12[NET] sending packet: from 172.31.0.128[4500] to <my ip>[40773] (144 bytes)                                                                                                                                                   
Jan 14 03:26:40 ip-172-31-0-128 charon: 04[NET] sending packet: from 172.31.0.128[4500] to <my ip>[40773]                                                                                                                                                               
Jan 14 03:26:40 ip-172-31-0-128 charon: 03[NET] received packet: from <my ip>[40773] to 172.31.0.128[4500]                                                                                                                                                              
Jan 14 03:26:40 ip-172-31-0-128 charon: 03[NET] waiting for data on sockets                                                                                                                                                                                                     
Jan 14 03:26:40 ip-172-31-0-128 charon: 07[NET] received packet: from <my ip>[40773] to 172.31.0.128[4500] (80 bytes)                                                                                                                                                   
Jan 14 03:26:40 ip-172-31-0-128 charon: 07[ENC] parsed IKE_AUTH request 4 [ EAP/RES/MSCHAPV2 ]                                                                                                                                                                                  
Jan 14 03:26:40 ip-172-31-0-128 charon: 07[IKE] EAP method EAP_MSCHAPV2 succeeded, MSK established                                                                                                                                                                              
Jan 14 03:26:40 ip-172-31-0-128 charon: 07[ENC] generating IKE_AUTH response 4 [ EAP/SUCC ]                                                                                                                                                                                     
Jan 14 03:26:40 ip-172-31-0-128 charon: 07[NET] sending packet: from 172.31.0.128[4500] to <my ip>[40773] (80 bytes)                                                                                                                                                    
Jan 14 03:26:40 ip-172-31-0-128 charon: 04[NET] sending packet: from 172.31.0.128[4500] to <my ip>[40773]                                                                                                                                                               
Jan 14 03:26:40 ip-172-31-0-128 charon: 03[NET] received packet: from <my ip>[40773] to 172.31.0.128[4500]                                                                                                                                                              
Jan 14 03:26:40 ip-172-31-0-128 charon: 03[NET] waiting for data on sockets                                                                                                                                                                                                     
Jan 14 03:26:40 ip-172-31-0-128 charon: 05[NET] received packet: from <my ip>[40773] to 172.31.0.128[4500] (96 bytes)                                                                                                                                                   
Jan 14 03:26:40 ip-172-31-0-128 charon: 05[ENC] parsed IKE_AUTH request 5 [ AUTH ]                                                                                                                                                                                              
Jan 14 03:26:40 ip-172-31-0-128 charon: 05[IKE] verification of AUTH payload with EAP MSK failed                                                                                                                                                                                
Jan 14 03:26:40 ip-172-31-0-128 charon: 05[ENC] generating IKE_AUTH response 5 [ N(AUTH_FAILED) ] <--- why am I getting this?                                                                                                                                                                               
Jan 14 03:26:40 ip-172-31-0-128 charon: 05[NET] sending packet: from 172.31.0.128[4500] to <my ip>[40773] (80 bytes)                                                                                                                                                    
Jan 14 03:26:40 ip-172-31-0-128 charon: 05[IKE] IKE_SA ikev2-eap-mschapv2[72] state change: CONNECTING => DESTROYING                                                                                                                                                            
Jan 14 03:26:40 ip-172-31-0-128 charon: 04[NET] sending packet: from 172.31.0.128[4500] to <my ip>[40773]                                                                                                                                                               
Jan 14 03:26:40 ip-172-31-0-128 charon: 03[NET] received packet: from <my ip>[40773] to 172.31.0.128[4500]                                                                                                                                                              
Jan 14 03:26:40 ip-172-31-0-128 charon: 03[NET] waiting for data on sockets 

Here is the relevant log from the Android device:

2021-01-14 14:32:26.230 1503-15396/? I/EAP: CreatedState: Decoded message: EAP-REQUEST/Identity
2021-01-14 14:32:26.230 1503-15396/? I/EAP: IdentityState: Decoded message: EAP-REQUEST/Identity
2021-01-14 14:32:26.230 1503-10160/? I/EAP: EapAuthenticator: EapStateMachine returned EapResponse
2021-01-14 14:32:26.249 1503-15396/? I/EAP: IdentityState: Decoded message: EAP-REQUEST/EAP-MSCHAP-V2
2021-01-14 14:32:26.249 1503-15396/? I/EAP: MethodState: Decoded message: EAP-REQUEST/EAP-MSCHAP-V2
2021-01-14 14:32:26.254 1503-10160/? I/EAP: EapAuthenticator: EapStateMachine returned EapResponse
2021-01-14 14:32:26.266 1503-15396/? I/EAP: MethodState: Decoded message: EAP-REQUEST/EAP-MSCHAP-V2
2021-01-14 14:32:26.269 1503-10160/? I/EAP: EapAuthenticator: EapStateMachine returned EapResponse
2021-01-14 14:32:26.281 1503-15396/? I/EAP: MethodState: Decoded message: EAP-SUCCESS
2021-01-14 14:32:26.282 1503-10160/? I/EAP: EapAuthenticator: EapStateMachine returned EapSuccess
2021-01-14 14:32:26.295 1503-15390/? D/IkeV2VpnRunner: IkeClosedExceptionally for network 100
    com.android.internal.net.ipsec.ike.exceptions.AuthenticationFailedException
        at com.android.internal.net.ipsec.ike.message.IkeNotifyPayload.validateAndBuildIkeException(IkeNotifyPayload.java:452)
        at com.android.internal.net.ipsec.ike.IkeSessionStateMachine$CreateIkeLocalIkeAuthPostEap.validateIkeAuthRespPostEap(IkeSessionStateMachine.java:3709)
        at com.android.internal.net.ipsec.ike.IkeSessionStateMachine$CreateIkeLocalIkeAuthPostEap.handleResponseIkeMessage(IkeSessionStateMachine.java:3668)
        at com.android.internal.net.ipsec.ike.IkeSessionStateMachine$BusyState.handleReceivedIkePacket(IkeSessionStateMachine.java:1632)
        at com.android.internal.net.ipsec.ike.IkeSessionStateMachine$BusyState.processStateMessage(IkeSessionStateMachine.java:1526)
        at com.android.internal.net.ipsec.ike.IkeSessionStateMachine$CreateIkeLocalIkeAuthPostEap.processStateMessage(IkeSessionStateMachine.java:3655)
        at com.android.internal.net.ipsec.ike.AbstractSessionStateMachine$ExceptionHandlerBase.processMessage(AbstractSessionStateMachine.java:122)
        at com.android.internal.net.ipsec.ike.utils.StateMachine$SmHandler.processMsg(StateMachine.java:992)
        at com.android.internal.net.ipsec.ike.utils.StateMachine$SmHandler.handleMessage(StateMachine.java:809)
        at android.os.Handler.dispatchMessage(Handler.java:106)
        at android.os.Looper.loop(Looper.java:223)
        at android.os.HandlerThread.run(HandlerThread.java:67)

Here is the config:

config setup
    charondebug="ike 2, knl 2, cfg 2, chd 2, job 2, net 2, asn 2, enc 1, lib 2, esp 2, tls 2, imc 2, pts 2" 
    uniqueids=no

conn rw-base
    fragmentation=yes
    dpdaction=clear
    dpdtimeout=90s
    dpddelay=30s

conn rw-config
    also=rw-base
    rightsourceip=172.31.0.0/24
    rightdns=
    leftsubnet=0.0.0.0/0
    leftid=@heathsnoek.me
    leftcert=server-cert.pem
    reauth=no
    rekey=no
    ike=aes192gcm16-aes128gcm16-prfsha256-ecp256-ecp521,aes192-sha256-modp3072
    esp=aes192gcm16-aes128gcm16-ecp256-modp3072,aes192-sha256-ecp256-modp3072
    leftsendcert=always

conn ikev2-eap-mschapv2
    also=rw-config
    rightauth=eap-mschapv2
    eap_identity=%identity
    auto=add

I can connect to this server successfully with the Strongswan app (on older versions of Android). Also using charon-cmd on Linux, a mobileconfig on OSX/iOS.

Any ideas?

syslog-success (15.2 KB) syslog-success Heath Snoek, 14.01.2021 19:09
syslog.txt (15.2 KB) syslog.txt Heath Snoek, 14.01.2021 19:11

History

#1 Updated by Tobias Brunner 3 months ago

  • Description updated (diff)
  • Status changed from New to Feedback
Jan 14 03:26:40 ip-172-31-0-128 charon: 05[ENC] generating IKE_AUTH response 5 [ N(AUTH_FAILED) ] <--- why am I getting this?                                                                                                                                                                               

Because one of the peers calculated a different/wrong authentication hash. Do you use any special (i.e. any non-ASCII) characters in the password? Which strongSwan version do you use?

#2 Updated by Heath Snoek 3 months ago

Linux strongSwan U5.5.1/K4.9.0-11-amd64

No I am not using any non-ASCII characters in the password. I have no problem connecting with the same credentials using charon-cmd or the Strongswan Android App etc.

For reference I have attached a successful connection using charon-cmd:

#3 Updated by Heath Snoek 3 months ago

#4 Updated by Tobias Brunner 3 months ago

OK, I found the problem. They don't pad the MSK like all other implementations do.

According to the EAP-MSCHAPv2 draft, the keys are derived according to RFC 3079 (MPPE). This results in two 128-bit keys, MasterSendKey and MasterReceiveKey (i.e. 32 octets in total). However, the MSK for EAP methods MUST be at least 64 octets according to RFC 5247, so these keys have to be padded somehow.

The first beta versions of Window 7 back in 2009 (which is what we used to test with when we implemented EAP-MSCHAPv2) did it like this: MasterReceiveKey|16 zero bytes|MasterReceiveKey|16 zero bytes. But this was changed with the release candidate of Windows 7 to: MasterReceiveKey|MasterReceiveKey|32 zero bytes, which is what we and other implementations use ever since. So until Google fixes their client accordingly, you won't be able to connect.

#5 Updated by Heath Snoek 3 months ago

Thanks, Tobias.

I will see if I can bring it up as an issue with the Android team somehow.

Also available in: Atom PDF