[strongSwan] Problems with xauth and dpd

[Harald Jung]

Hi,

After upgrading to strongswan 5.0.0, i've started to run certain test
scenarios.
 
I've problems witch enabling dpd on the client side, while using xauth.
If I remove the dpd parameters from the client-side the connection comes
up without any problems:

server-side:
conn v_ipsec_test
        keyexchange=ikev1
        left="10.15.224.32"
        leftprotoport="0/0"
        rightprotoport="0/0"
        leftid="@master"
        rightid="@slave"
        authby="xauthpsk"
        auto="add"
        right="10.15.224.35"
        rekey="yes"
        type="tunnel"
        xauth="server"
        dpdaction="clear"
        dpddelay="10"
        dpdtimeout="30"

client-side (working config):
conn v_ipsec_test
        keyexchange=ikev1
        left="10.15.224.35"
        leftprotoport="0/0"
        rightprotoport="0/0"
        leftid="@slave"
        rightid="@master"
        auto="start"
        right="10.15.224.32"
        rightauth="psk"
        rekey="yes"
        leftauth="psk"
        leftauth2="xauth"
        type="tunnel"
        xauth_identity="xauthuser"

client-side (config with dpd):
conn v_ipsec_test
        keyexchange=ikev1
        left="10.15.224.35"
        leftprotoport="0/0"
        rightprotoport="0/0"
        leftid="@slave"
        rightid="@master"
        auto="start"
        right="10.15.224.32"
        rightauth="psk"
        rekey="yes"
        leftauth="psk"
        leftauth2="xauth"
        type="tunnel"
        xauth_identity="xauthuser"
        dpdaction="clear"
        dpddelay="10"
        dpdtimeout="30"


Working Szenario:
client-side:
Security Associations (1 up, 0 connecting):
v_ipsec_test[7]: ESTABLISHED 70 seconds ago,
10.15.224.35[slave]...10.15.224.32[master]
v_ipsec_test{7}:  INSTALLED, TUNNEL, ESP SPIs: c8c0ef5d_i c26810b7_o
v_ipsec_test{7}:   10.15.224.35/32 === 10.15.224.32/32

server-side
Security Associations (1 up, 0 connecting):
v_ipsec_test[9]: ESTABLISHED 104 seconds ago,
10.15.224.32[master]...10.15.224.35[slave]
v_ipsec_test{7}:  INSTALLED, TUNNEL, ESP SPIs: c26810b7_i c8c0ef5d_o
v_ipsec_test{7}:   10.15.224.32/32 === 10.15.224.35/32 


DPD-Szenario:
client-side
Security Associations (1 up, 0 connecting):
v_ipsec_test[1]: ESTABLISHED 8 seconds ago,
10.15.224.35[slave]...10.15.224.32[master]

server-side:
Security Associations (0 up, 0 connecting):
  none


sniplet of server log:
Sep  7 15:50:18 tstmaster3 charon: 12[ENC] verifying message structure 
Sep  7 15:50:18 tstmaster3 charon: 12[ENC] found payload of type
HASH_V1 
Sep  7 15:50:18 tstmaster3 charon: 12[ENC] found payload of type
SECURITY_ASSOCIATION_V1 
Sep  7 15:50:18 tstmaster3 charon: 12[ENC] found payload of type
NONCE_V1 
Sep  7 15:50:18 tstmaster3 charon: 12[ENC] found payload of type
KEY_EXCHANGE_V1 
Sep  7 15:50:18 tstmaster3 charon: 12[ENC] parsed QUICK_MODE request
4005786177 [ HASH SA No KE ] 
Sep  7 15:50:18 tstmaster3 charon: 12[ENC] verified IKEv1 message with
hash => 20 bytes @ 0x2003db80 
Sep  7 15:50:18 tstmaster3 charon: 12[ENC]    0: A7 83 26 C0 13 4C DD 8C
D5 8B ED 14 03 E7 59 C5  ..&..L........Y. 
Sep  7 15:50:18 tstmaster3 charon: 12[ENC]   16: 45 C9 83 E5
E... 
Sep  7 15:50:18 tstmaster3 charon: 12[IKE] received quick mode request
for unestablished IKE_SA, ignored 
Sep  7 15:50:18 tstmaster3 charon: 12[MGR] checkin and destroy IKE_SA
v_ipsec_test[11] 
Sep  7 15:50:18 tstmaster3 charon: 12[IKE] IKE_SA v_ipsec_test[11] state
change: CONNECTING => DESTROYING



sniplet if server log with dpd disabled on client:

Sep  7 15:52:15 tstmaster3 charon: 02[ENC] verified IKEv1 message with
hash => 20 bytes @ 0x2003b430 
Sep  7 15:52:15 tstmaster3 charon: 02[ENC]    0: 03 98 9F 8D 0C 56 A1 31
48 11 16 9F F9 94 B1 D6  .....V.1H....... 
Sep  7 15:52:15 tstmaster3 charon: 02[ENC]   16: B9 23 13
31                                      .#.1 
Sep  7 15:52:15 tstmaster3 charon: 02[IKE] IKE_SA v_ipsec_test[12]
established between 10.15.224.32[master]...10.15.224.35[slave] 
Sep  7 15:52:15 tstmaster3 charon: 02[IKE] IKE_SA v_ipsec_test[12]
established between 10.15.224.32[master]...10.15.224.35[slave] 
Sep  7 15:52:15 tstmaster3 charon: 02[IKE] IKE_SA v_ipsec_test[12] state
change: CONNECTING => ESTABLISHED

sniplet of client-log:
Sep  7 15:58:37 tstslave3 charon: 04[MGR] IKE_SA v_ipsec_test[1]
successfully checked out 
Sep  7 15:58:37 tstslave3 charon: 04[IKE] sending retransmit 1 of
request message ID 1220258976, seq 4 
Sep  7 15:58:37 tstslave3 charon: 04[NET] sending packet: from
10.15.224.35[500] to 10.15.224.32[500] 
Sep  7 15:58:37 tstslave3 charon: 04[MGR] checkin IKE_SA
v_ipsec_test[1] 
Sep  7 15:58:37 tstslave3 charon: 04[MGR] check-in of IKE_SA
successful. 
Sep  7 15:58:37 tstslave3 charon: 15[NET] sending packet: from
10.15.224.35[500] to 10.15.224.32[500] 
Sep  7 15:58:37 tstslave3 charon: 14[JOB] next event in 5s 965ms,
waiting 
Sep  7 15:58:43 tstslave3 charon: 14[JOB] got event, queuing job for
execution 
Sep  7 15:58:43 tstslave3 charon: 14[JOB] next event in 1s 233ms,
waiting 
Sep  7 15:58:43 tstslave3 charon: 03[MGR] checkout IKE_SA 
Sep  7 15:58:43 tstslave3 charon: 03[MGR] IKE_SA v_ipsec_test[1]
successfully checked out 
Sep  7 15:58:43 tstslave3 charon: 03[IKE] delaying task initiation,
QUICK_MODE exchange in progress 
Sep  7 15:58:43 tstslave3 charon: 03[MGR] checkin IKE_SA
v_ipsec_test[1] 
Sep  7 15:58:43 tstslave3 charon: 03[MGR] check-in of IKE_SA
successful. 
Sep  7 15:58:43 tstslave3 charon: 14[JOB] next event in 1s 233ms,
waiting 
Sep  7 15:58:44 tstslave3 charon: 14[JOB] got event, queuing job for
execution 
Sep  7 15:58:44 tstslave3 charon: 14[JOB] next event in 8s 766ms,
waiting 
Sep  7 15:58:44 tstslave3 charon: 02[MGR] checkout IKE_SA


best regards 
Harald