-1

On an AWS VPS, I installed Strongswan to use it as a VPN. It works fine with iPhone client. However, when I try to connect from a Windows client, the SA connection gets established successfully and works fine for a few minutes, but after a few minutes (2 to 10 minutes, 2 or a little more in most cases) the connection hangs and stops passing traffic. It seems that both sides see the connection as alive, at least I can't see any indications of errors.

I've spent a few days trying to find out what's the matter. There seems to be rather little material on the Internet that describes such situations. In addition, I'm new to Linux administration and networks, so may be I saw a description of this issue and a solution to it, but I just could not understand it. I'll be very grateful for any help.

Below is ipsec.conf (Here real external IP of the server is replaced with EXT.SRVR.IP.ADR)

config setup
    uniqueids=never
    charondebug="ike 2, knl 2, cfg 2, net 2, esp 2, dmn 2,  mgr 2"

conn %default
    keyexchange=ikev2
    ike=aes128gcm16-sha2_256-prfsha256-ecp256,aes256-sha2_256-prfsha256-modp2048!
    esp=aes128gcm16-sha2_256-ecp256,aes256-sha1!
    fragmentation=yes
    rekey=no
    compress=yes
    dpdaction=clear
    left=%any
    leftauth=pubkey
    leftsourceip=EXT.SRVR.IP.ADR
    leftid=EXT.SRVR.IP.ADR
    leftcert=debian.pem
    leftsendcert=always
    leftsubnet=0.0.0.0/0
    right=%any
    rightauth=pubkey
    rightsourceip=10.10.10.0/24
    rightdns=8.8.8.8,8.8.4.4

conn ikev2-pubkey
    auto=add

And here is an excerpt from ipsec.log (real IPs replaced with "EXT.SRVR.IP.ADR", "INT.SRVR.IP.ADR" and "MY.CLNT.IP.ADR" for the external IP of the server, its internal IP and my Windows client respectively, apparently irrelevant lines are omitted)

Mar 17 12:41:17 server-name charon: 03[NET] received packet: from MY.CLNT.IP.ADR[500] to INT.SRVR.IP.ADR[500]
Mar 17 12:41:17 server-name charon: 03[NET] waiting for data on sockets
Mar 17 12:41:17 server-name charon: 07[MGR] checkout IKEv2 SA by message with SPIs cc34c04e15f31fd2_i 0000000000000000_r
Mar 17 12:41:17 server-name charon: 07[MGR] created IKE_SA (unnamed)[1]
Mar 17 12:41:17 server-name charon: 07[NET] received packet: from MY.CLNT.IP.ADR[500] to INT.SRVR.IP.ADR[500] (536 bytes)
Mar 17 12:41:17 server-name charon: 07[ENC] parsed IKE_SA_INIT request 0 [ SA KE No N(NATD_S_IP) N(NATD_D_IP) ]
Mar 17 12:41:17 server-name charon: 07[CFG] looking for an ike config for INT.SRVR.IP.ADR...MY.CLNT.IP.ADR
Mar 17 12:41:17 server-name charon: 07[CFG]   candidate: %any...%any, prio 28
Mar 17 12:41:17 server-name charon: 07[CFG] found matching ike config: %any...%any with prio 28
Mar 17 12:41:17 server-name charon: 07[IKE] MY.CLNT.IP.ADR is initiating an IKE_SA
Mar 17 12:41:17 server-name charon: 07[IKE] IKE_SA (unnamed)[1] state change: CREATED => CONNECTING
Mar 17 12:41:17 server-name charon: 07[CFG] selecting proposal:
Mar 17 12:41:17 server-name charon: 07[CFG]   no acceptable ENCRYPTION_ALGORITHM found
Mar 17 12:41:17 server-name charon: 07[CFG] selecting proposal:
Mar 17 12:41:17 server-name charon: 07[CFG]   no acceptable ENCRYPTION_ALGORITHM found
Mar 17 12:41:17 server-name charon: 07[CFG] selecting proposal:
Mar 17 12:41:17 server-name charon: 07[CFG]   no acceptable ENCRYPTION_ALGORITHM found
Mar 17 12:41:17 server-name charon: 07[CFG] selecting proposal:
Mar 17 12:41:17 server-name charon: 07[CFG]   no acceptable PSEUDO_RANDOM_FUNCTION found
Mar 17 12:41:17 server-name charon: 07[CFG] selecting proposal:
Mar 17 12:41:17 server-name charon: 07[CFG]   proposal matches
Mar 17 12:41:17 server-name charon: 07[CFG] received proposals: IKE:AES_CBC_256/HMAC_SHA1_96/PRF_HMAC_SHA1/MODP_2048, IKE:AES_CBC_256/HMAC_SHA2_256_128/PRF_HMAC_SHA2_256/MODP_2048, IKE:AES_CBC_256/HMAC_SHA2_384_192/PRF_HMAC_SHA2_384/MODP_2048
Mar 17 12:41:17 server-name charon: 07[CFG] configured proposals: IKE:AES_GCM_16_128/PRF_HMAC_SHA2_256/ECP_256, IKE:AES_CBC_256/HMAC_SHA2_256_128/PRF_HMAC_SHA2_256/MODP_2048
Mar 17 12:41:17 server-name charon: 07[CFG] selected proposal: IKE:AES_CBC_256/HMAC_SHA2_256_128/PRF_HMAC_SHA2_256/MODP_2048
Mar 17 12:41:17 server-name charon: 07[IKE] local host is behind NAT, sending keep alives
Mar 17 12:41:17 server-name charon: 07[IKE] remote host is behind NAT
Mar 17 12:41:17 server-name charon: 07[IKE] sending cert request for "CN=EXT.SRVR.IP.ADR"
Mar 17 12:41:17 server-name charon: 07[ENC] generating IKE_SA_INIT response 0 [ SA KE No N(NATD_S_IP) N(NATD_D_IP) CERTREQ N(MULT_AUTH) ]
Mar 17 12:41:17 server-name charon: 07[NET] sending packet: from INT.SRVR.IP.ADR[500] to MY.CLNT.IP.ADR[500] (465 bytes)
Mar 17 12:41:17 server-name charon: 04[NET] sending packet: from INT.SRVR.IP.ADR[500] to MY.CLNT.IP.ADR[500]
Mar 17 12:41:17 server-name charon: 07[MGR] checkin IKE_SA (unnamed)[1]
Mar 17 12:41:17 server-name charon: 07[MGR] checkin of IKE_SA successful
Mar 17 12:41:17 server-name charon: 03[NET] received packet: from MY.CLNT.IP.ADR[4500] to INT.SRVR.IP.ADR[4500]
Mar 17 12:41:17 server-name charon: 03[NET] waiting for data on sockets
Mar 17 12:41:17 server-name charon: 08[MGR] checkout IKEv2 SA by message with SPIs cc34c04e15f31fd2_i e5bd885ad183b108_r
Mar 17 12:41:17 server-name charon: 08[MGR] IKE_SA (unnamed)[1] successfully checked out
Mar 17 12:41:17 server-name charon: 08[NET] received packet: from MY.CLNT.IP.ADR[4500] to INT.SRVR.IP.ADR[4500] (3408 bytes)
Mar 17 12:41:17 server-name charon: 08[ENC] parsed IKE_AUTH request 1 [ IDi CERT CERTREQ AUTH N(MOBIKE_SUP) CPRQ(ADDR DNS NBNS SRV) SA TSi TSr ]
Mar 17 12:41:17 server-name charon: 08[IKE] received cert request for unknown ca with keyid 39:9e:66:a7:20:3c:4d:06:fb:62:6b:65:87:22:35:57:a0:a0:0a:22
...
Mar 17 12:41:17 server-name charon: 08[IKE] received cert request for unknown ca with keyid 01:f0:33:4c:1a:a1:d9:ee:5b:7b:a9:de:43:bc:02:7d:57:09:33:fb
Mar 17 12:41:17 server-name charon: 08[IKE] received cert request for "CN=EXT.SRVR.IP.ADR"
Mar 17 12:41:17 server-name charon: 08[IKE] received cert request for unknown ca with keyid 88:a9:5a:ef:c0:84:fc:13:74:41:6b:b1:63:32:c2:cf:92:59:bb:3b
...
Mar 17 12:41:17 server-name charon: 08[IKE] received cert request for unknown ca with keyid 4f:9c:7d:21:79:9c:ad:0e:d8:b9:0c:57:9f:1a:02:99:e7:90:f3:87
Mar 17 12:41:17 server-name charon: 08[IKE] received 67 cert requests for an unknown ca
Mar 17 12:41:17 server-name charon: 08[IKE] received end entity cert "CN=me"
Mar 17 12:41:17 server-name charon: 08[CFG] looking for peer configs matching INT.SRVR.IP.ADR[%any]...MY.CLNT.IP.ADR[CN=me]
Mar 17 12:41:17 server-name charon: 08[CFG]   candidate "ikev2-pubkey", match: 1/1/28 (me/other/ike)
Mar 17 12:41:17 server-name charon: 08[CFG] selected peer config 'ikev2-pubkey'
Mar 17 12:41:17 server-name charon: 08[CFG]   using certificate "CN=me"
Mar 17 12:41:17 server-name charon: 08[CFG]   certificate "CN=me" key: 4096 bit RSA
Mar 17 12:41:17 server-name charon: 08[CFG]   using trusted ca certificate "CN=EXT.SRVR.IP.ADR"
Mar 17 12:41:17 server-name charon: 08[CFG] checking certificate status of "CN=me"
Mar 17 12:41:17 server-name charon: 08[CFG] ocsp check skipped, no ocsp found
Mar 17 12:41:17 server-name charon: 08[CFG] certificate status is not available
Mar 17 12:41:17 server-name charon: 08[CFG]   certificate "CN=EXT.SRVR.IP.ADR" key: 4096 bit RSA
Mar 17 12:41:17 server-name charon: 08[CFG]   reached self-signed root ca with a path length of 0
Mar 17 12:41:17 server-name charon: 08[IKE] authentication of 'CN=me' with RSA signature successful
Mar 17 12:41:17 server-name charon: 08[IKE] processing INTERNAL_IP4_ADDRESS attribute
Mar 17 12:41:17 server-name charon: 08[IKE] processing INTERNAL_IP4_DNS attribute
Mar 17 12:41:17 server-name charon: 08[IKE] processing INTERNAL_IP4_NBNS attribute
Mar 17 12:41:17 server-name charon: 08[IKE] processing INTERNAL_IP4_SERVER attribute
Mar 17 12:41:17 server-name charon: 08[IKE] peer supports MOBIKE
Mar 17 12:41:17 server-name charon: 08[IKE] authentication of 'EXT.SRVR.IP.ADR' (myself) with RSA signature successful
Mar 17 12:41:17 server-name charon: 08[IKE] IKE_SA ikev2-pubkey[1] established between INT.SRVR.IP.ADR[EXT.SRVR.IP.ADR]...MY.CLNT.IP.ADR[CN=me]
Mar 17 12:41:17 server-name charon: 08[IKE] IKE_SA ikev2-pubkey[1] state change: CONNECTING => ESTABLISHED
Mar 17 12:41:17 server-name charon: 08[IKE] sending end entity cert "CN=EXT.SRVR.IP.ADR"
Mar 17 12:41:17 server-name charon: 08[IKE] peer requested virtual IP %any
Mar 17 12:41:17 server-name charon: 08[CFG] assigning new lease to 'CN=me'
Mar 17 12:41:17 server-name charon: 08[IKE] assigning virtual IP 10.10.10.1 to peer 'CN=me'
Mar 17 12:41:17 server-name charon: 08[IKE] building INTERNAL_IP4_DNS attribute
Mar 17 12:41:17 server-name charon: 08[IKE] building INTERNAL_IP4_DNS attribute
Mar 17 12:41:17 server-name charon: 08[CFG] looking for a child config for 0.0.0.0/0 === 0.0.0.0/0
Mar 17 12:41:17 server-name charon: 08[CFG] proposing traffic selectors for us:
Mar 17 12:41:17 server-name charon: 08[CFG]  0.0.0.0/0
Mar 17 12:41:17 server-name charon: 08[CFG] proposing traffic selectors for other:
Mar 17 12:41:17 server-name charon: 08[CFG]  10.10.10.1/32
Mar 17 12:41:17 server-name charon: 08[CFG]   candidate "ikev2-pubkey" with prio 5+1
Mar 17 12:41:17 server-name charon: 08[CFG] found matching child config "ikev2-pubkey" with prio 6
Mar 17 12:41:17 server-name charon: 08[CFG] selecting proposal:
Mar 17 12:41:17 server-name charon: 08[CFG]   no acceptable ENCRYPTION_ALGORITHM found
Mar 17 12:41:17 server-name charon: 08[CFG] selecting proposal:
Mar 17 12:41:17 server-name charon: 08[CFG]   no acceptable ENCRYPTION_ALGORITHM found
Mar 17 12:41:17 server-name charon: 08[CFG] selecting proposal:
Mar 17 12:41:17 server-name charon: 08[CFG]   no acceptable ENCRYPTION_ALGORITHM found
Mar 17 12:41:17 server-name charon: 08[CFG] selecting proposal:
Mar 17 12:41:17 server-name charon: 08[CFG]   proposal matches
Mar 17 12:41:17 server-name charon: 08[CFG] received proposals: ESP:AES_CBC_128/HMAC_SHA1_96/NO_EXT_SEQ, ESP:AES_CBC_256/HMAC_SHA1_96/NO_EXT_SEQ
Mar 17 12:41:17 server-name charon: 08[CFG] configured proposals: ESP:AES_GCM_16_128/ECP_256/NO_EXT_SEQ, ESP:AES_CBC_256/HMAC_SHA1_96/NO_EXT_SEQ
Mar 17 12:41:17 server-name charon: 08[CFG] selected proposal: ESP:AES_CBC_256/HMAC_SHA1_96/NO_EXT_SEQ
Mar 17 12:41:17 server-name charon: 08[KNL] got SPI c6bcf84d
Mar 17 12:41:17 server-name charon: 08[CFG] selecting traffic selectors for us:
Mar 17 12:41:17 server-name charon: 08[CFG]  config: 0.0.0.0/0, received: 0.0.0.0/0 => match: 0.0.0.0/0
Mar 17 12:41:17 server-name charon: 08[CFG] selecting traffic selectors for other:
Mar 17 12:41:17 server-name charon: 08[CFG]  config: 10.10.10.1/32, received: 0.0.0.0/0 => match: 10.10.10.1/32
Mar 17 12:41:17 server-name charon: 08[KNL] adding SAD entry with SPI c6bcf84d and reqid {1}
Mar 17 12:41:17 server-name charon: 08[KNL]   using encryption algorithm AES_CBC with key size 256
Mar 17 12:41:17 server-name charon: 08[KNL]   using integrity algorithm HMAC_SHA1_96 with key size 160
Mar 17 12:41:17 server-name charon: 08[KNL]   using replay window of 32 packets
Mar 17 12:41:17 server-name charon: 08[KNL] adding SAD entry with SPI b74162a4 and reqid {1}
Mar 17 12:41:17 server-name charon: 08[KNL]   using encryption algorithm AES_CBC with key size 256
Mar 17 12:41:17 server-name charon: 08[KNL]   using integrity algorithm HMAC_SHA1_96 with key size 160
Mar 17 12:41:17 server-name charon: 08[KNL]   using replay window of 0 packets
Mar 17 12:41:17 server-name charon: 08[KNL] adding policy 0.0.0.0/0 === 10.10.10.1/32 out [priority 391808, refcount 1]
Mar 17 12:41:17 server-name charon: 08[KNL] policy already exists, try to update it
Mar 17 12:41:17 server-name charon: 08[KNL] adding policy 10.10.10.1/32 === 0.0.0.0/0 in [priority 391808, refcount 1]
Mar 17 12:41:17 server-name charon: 08[KNL] policy already exists, try to update it
Mar 17 12:41:17 server-name charon: 08[KNL] adding policy 10.10.10.1/32 === 0.0.0.0/0 fwd [priority 391808, refcount 1]
Mar 17 12:41:17 server-name charon: 08[KNL] policy already exists, try to update it
Mar 17 12:41:17 server-name charon: 08[KNL] policy 0.0.0.0/0 === 10.10.10.1/32 out already exists, increasing refcount
Mar 17 12:41:17 server-name charon: 08[KNL] updating policy 0.0.0.0/0 === 10.10.10.1/32 out [priority 191808, refcount 2]
Mar 17 12:41:17 server-name charon: 08[KNL] getting a local address in traffic selector 0.0.0.0/0
Mar 17 12:41:17 server-name charon: 08[KNL] using host %any
Mar 17 12:41:17 server-name charon: 08[KNL] getting iface name for index 2
Mar 17 12:41:17 server-name charon: 08[KNL] using 172.26.0.1 as nexthop and eth0 as dev to reach MY.CLNT.IP.ADR/32
Mar 17 12:41:17 server-name charon: 08[KNL] installing route: 10.10.10.1/32 via 172.26.0.1 src %any dev eth0
Mar 17 12:41:17 server-name charon: 08[KNL] getting iface index for eth0
Mar 17 12:41:17 server-name charon: 08[KNL] policy 10.10.10.1/32 === 0.0.0.0/0 in already exists, increasing refcount
Mar 17 12:41:17 server-name charon: 08[KNL] updating policy 10.10.10.1/32 === 0.0.0.0/0 in [priority 191808, refcount 2]
Mar 17 12:41:17 server-name charon: 08[KNL] policy 10.10.10.1/32 === 0.0.0.0/0 fwd already exists, increasing refcount
Mar 17 12:41:17 server-name charon: 08[KNL] updating policy 10.10.10.1/32 === 0.0.0.0/0 fwd [priority 191808, refcount 2]
Mar 17 12:41:17 server-name charon: 08[IKE] CHILD_SA ikev2-pubkey{1} established with SPIs c6bcf84d_i b74162a4_o and TS 0.0.0.0/0 === 10.10.10.1/32
Mar 17 12:41:17 server-name charon: 08[ENC] generating IKE_AUTH response 1 [ IDr CERT AUTH CPRP(ADDR DNS DNS) SA TSi TSr N(MOBIKE_SUP) N(ADD_6_ADDR) ]
Mar 17 12:41:17 server-name charon: 08[NET] sending packet: from INT.SRVR.IP.ADR[4500] to MY.CLNT.IP.ADR[4500] (2048 bytes)
Mar 17 12:41:17 server-name charon: 04[NET] sending packet: from INT.SRVR.IP.ADR[4500] to MY.CLNT.IP.ADR[4500]
Mar 17 12:41:17 server-name charon: 08[MGR] checkin IKE_SA ikev2-pubkey[1]
Mar 17 12:41:17 server-name charon: 08[MGR] checkin of IKE_SA successful
Mar 17 12:41:37 server-name charon: 10[MGR] checkout IKEv2 SA with SPIs cc34c04e15f31fd2_i e5bd885ad183b108_r
Mar 17 12:41:37 server-name charon: 10[MGR] IKE_SA ikev2-pubkey[1] successfully checked out
Mar 17 12:41:37 server-name charon: 10[KNL] querying policy 0.0.0.0/0 === 10.10.10.1/32 out
Mar 17 12:41:37 server-name charon: 10[MGR] checkin IKE_SA ikev2-pubkey[1]
Mar 17 12:41:37 server-name charon: 10[MGR] checkin of IKE_SA successful
Mar 17 12:41:47 server-name dhclient[358]: PRC: Renewing lease on eth0.
Mar 17 12:41:47 server-name dhclient[358]: XMT: Renew on eth0, interval 9070ms.
Mar 17 12:41:47 server-name dhclient[358]: RCV: Reply message on eth0 from fe80::60:52ff:fe0a:c10e.
Mar 17 12:41:47 server-name charon: 11[MGR] checkout IKEv2 SA with SPIs cc34c04e15f31fd2_i e5bd885ad183b108_r
Mar 17 12:41:47 server-name charon: 11[MGR] IKE_SA ikev2-pubkey[1] successfully checked out
Mar 17 12:41:47 server-name charon: 11[MGR] checkin IKE_SA ikev2-pubkey[1]
Mar 17 12:41:47 server-name charon: 11[MGR] checkin of IKE_SA successful
Mar 17 12:41:47 server-name charon: 12[MGR] checkout IKEv2 SA with SPIs cc34c04e15f31fd2_i e5bd885ad183b108_r
Mar 17 12:41:47 server-name charon: 12[MGR] IKE_SA ikev2-pubkey[1] successfully checked out
Mar 17 12:41:47 server-name charon: 12[KNL] querying policy 10.10.10.1/32 === 0.0.0.0/0 in
Mar 17 12:41:47 server-name charon: 12[KNL] querying policy 10.10.10.1/32 === 0.0.0.0/0 fwd
Mar 17 12:41:47 server-name charon: 12[MGR] checkin IKE_SA ikev2-pubkey[1]
Mar 17 12:41:47 server-name charon: 12[MGR] checkin of IKE_SA successful
Mar 17 12:41:56 server-name charon: 13[MGR] checkout IKEv2 SA with SPIs cc34c04e15f31fd2_i e5bd885ad183b108_r
Mar 17 12:41:56 server-name charon: 13[MGR] IKE_SA ikev2-pubkey[1] successfully checked out
Mar 17 12:41:56 server-name charon: 13[KNL] querying policy 0.0.0.0/0 === 10.10.10.1/32 out
Mar 17 12:41:56 server-name charon: 13[MGR] checkin IKE_SA ikev2-pubkey[1]
Mar 17 12:41:56 server-name charon: 13[MGR] checkin of IKE_SA successful
...
Mar 17 12:49:35 server-name charon: 16[MGR] checkout IKEv2 SA with SPIs cc34c04e15f31fd2_i e5bd885ad183b108_r
Mar 17 12:49:35 server-name charon: 16[MGR] IKE_SA ikev2-pubkey[1] successfully checked out
Mar 17 12:49:35 server-name charon: 16[KNL] querying policy 10.10.10.1/32 === 0.0.0.0/0 in
Mar 17 12:49:35 server-name charon: 16[KNL] querying policy 10.10.10.1/32 === 0.0.0.0/0 fwd
Mar 17 12:49:35 server-name charon: 16[MGR] checkin IKE_SA ikev2-pubkey[1]
Mar 17 12:49:35 server-name charon: 16[MGR] checkin of IKE_SA successful
Mar 17 12:49:51 server-name charon: 05[MGR] checkout IKEv2 SA with SPIs cc34c04e15f31fd2_i e5bd885ad183b108_r
Mar 17 12:49:51 server-name charon: 05[MGR] IKE_SA ikev2-pubkey[1] successfully checked out
Mar 17 12:49:51 server-name charon: 05[KNL] querying policy 0.0.0.0/0 === 10.10.10.1/32 out
Mar 17 12:49:51 server-name charon: 05[MGR] checkin IKE_SA ikev2-pubkey[1]
Mar 17 12:49:51 server-name charon: 05[MGR] checkin of IKE_SA successful
Mar 17 12:49:55 server-name charon: 06[MGR] checkout IKEv2 SA with SPIs cc34c04e15f31fd2_i e5bd885ad183b108_r
Mar 17 12:49:55 server-name charon: 06[MGR] IKE_SA ikev2-pubkey[1] successfully checked out
Mar 17 12:49:55 server-name charon: 06[KNL] querying policy 10.10.10.1/32 === 0.0.0.0/0 in
Mar 17 12:49:55 server-name charon: 06[KNL] querying policy 10.10.10.1/32 === 0.0.0.0/0 fwd
Mar 17 12:49:55 server-name charon: 06[IKE] sending DPD request
Mar 17 12:49:55 server-name charon: 06[IKE] queueing IKE_DPD task
Mar 17 12:49:55 server-name charon: 06[IKE] activating new tasks
Mar 17 12:49:55 server-name charon: 06[IKE]   activating IKE_DPD task
Mar 17 12:49:55 server-name charon: 06[ENC] generating INFORMATIONAL request 0 [ ]
Mar 17 12:49:55 server-name charon: 06[NET] sending packet: from INT.SRVR.IP.ADR[4500] to MY.CLNT.IP.ADR[4500] (80 bytes)
Mar 17 12:49:55 server-name charon: 06[MGR] checkin IKE_SA ikev2-pubkey[1]
Mar 17 12:49:55 server-name charon: 06[MGR] checkin of IKE_SA successful
Mar 17 12:49:55 server-name charon: 04[NET] sending packet: from INT.SRVR.IP.ADR[4500] to MY.CLNT.IP.ADR[4500]
Mar 17 12:49:55 server-name charon: 03[NET] received packet: from MY.CLNT.IP.ADR[4500] to INT.SRVR.IP.ADR[4500]
Mar 17 12:49:55 server-name charon: 03[NET] waiting for data on sockets
Mar 17 12:49:55 server-name charon: 07[MGR] checkout IKEv2 SA by message with SPIs cc34c04e15f31fd2_i e5bd885ad183b108_r
Mar 17 12:49:55 server-name charon: 07[MGR] IKE_SA ikev2-pubkey[1] successfully checked out
Mar 17 12:49:55 server-name charon: 07[NET] received packet: from MY.CLNT.IP.ADR[4500] to INT.SRVR.IP.ADR[4500] (80 bytes)
Mar 17 12:49:55 server-name charon: 07[ENC] parsed INFORMATIONAL response 0 [ ]
Mar 17 12:49:55 server-name charon: 07[IKE] activating new tasks
Mar 17 12:49:55 server-name charon: 07[IKE] nothing to initiate
Mar 17 12:49:55 server-name charon: 07[MGR] checkin IKE_SA ikev2-pubkey[1]
Mar 17 12:49:55 server-name charon: 07[MGR] checkin of IKE_SA successful
Mar 17 12:49:57 server-name dhclient[358]: PRC: Renewing lease on eth0.
Mar 17 12:49:57 server-name dhclient[358]: XMT: Renew on eth0, interval 10290ms.
Mar 17 12:49:57 server-name dhclient[358]: RCV: Reply message on eth0 from fe80::60:52ff:fe0a:c10e.
Mar 17 12:49:59 server-name charon: 09[MGR] checkout IKEv2 SA with SPIs cc34c04e15f31fd2_i e5bd885ad183b108_r
Mar 17 12:49:59 server-name charon: 09[MGR] IKE_SA ikev2-pubkey[1] successfully checked out
Mar 17 12:49:59 server-name charon: 09[MGR] checkin IKE_SA ikev2-pubkey[1]
Mar 17 12:49:59 server-name charon: 09[MGR] checkin of IKE_SA successful
Mar 17 12:50:00 server-name charon: 03[NET] received packet: from MY.CLNT.IP.ADR[4500] to INT.SRVR.IP.ADR[4500]
Mar 17 12:50:00 server-name charon: 03[NET] waiting for data on sockets
Mar 17 12:50:00 server-name charon: 08[MGR] checkout IKEv2 SA by message with SPIs cc34c04e15f31fd2_i e5bd885ad183b108_r
Mar 17 12:50:00 server-name charon: 08[MGR] IKE_SA ikev2-pubkey[1] successfully checked out
Mar 17 12:50:00 server-name charon: 08[NET] received packet: from MY.CLNT.IP.ADR[4500] to INT.SRVR.IP.ADR[4500] (80 bytes)
Mar 17 12:50:00 server-name charon: 08[ENC] parsed INFORMATIONAL request 2 [ D ]
Mar 17 12:50:00 server-name charon: 08[IKE] received DELETE for ESP CHILD_SA with SPI b74162a4
Mar 17 12:50:00 server-name charon: 08[KNL] querying SAD entry with SPI c6bcf84d
Mar 17 12:50:00 server-name charon: 08[KNL] querying SAD entry with SPI b74162a4
Mar 17 12:50:00 server-name charon: 08[IKE] closing CHILD_SA ikev2-pubkey{1} with SPIs c6bcf84d_i (1148939 bytes) b74162a4_o (21040410 bytes) and TS 0.0.0.0/0 === 10.10.10.1/32
Mar 17 12:50:00 server-name charon: 08[IKE] sending DELETE for ESP CHILD_SA with SPI c6bcf84d
Mar 17 12:50:00 server-name charon: 08[IKE] CHILD_SA closed
Mar 17 12:50:00 server-name charon: 08[KNL] deleting policy 0.0.0.0/0 === 10.10.10.1/32 out
Mar 17 12:50:00 server-name charon: 08[KNL] policy still used by another CHILD_SA, not removed
Mar 17 12:50:00 server-name charon: 08[KNL] updating policy 0.0.0.0/0 === 10.10.10.1/32 out [priority 391808, refcount 1]
Mar 17 12:50:00 server-name charon: 08[KNL] deleting policy 10.10.10.1/32 === 0.0.0.0/0 in
Mar 17 12:50:00 server-name charon: 08[KNL] policy still used by another CHILD_SA, not removed
Mar 17 12:50:00 server-name charon: 08[KNL] updating policy 10.10.10.1/32 === 0.0.0.0/0 in [priority 391808, refcount 1]
Mar 17 12:50:00 server-name charon: 08[KNL] deleting policy 10.10.10.1/32 === 0.0.0.0/0 fwd
Mar 17 12:50:00 server-name charon: 08[KNL] policy still used by another CHILD_SA, not removed
Mar 17 12:50:00 server-name charon: 08[KNL] updating policy 10.10.10.1/32 === 0.0.0.0/0 fwd [priority 391808, refcount 1]
Mar 17 12:50:00 server-name charon: 08[KNL] deleting policy 0.0.0.0/0 === 10.10.10.1/32 out
Mar 17 12:50:00 server-name charon: 08[KNL] getting iface index for eth0
Mar 17 12:50:00 server-name charon: 08[KNL] deleting policy 10.10.10.1/32 === 0.0.0.0/0 in
Mar 17 12:50:00 server-name charon: 08[KNL] deleting policy 10.10.10.1/32 === 0.0.0.0/0 fwd
Mar 17 12:50:00 server-name charon: 08[KNL] deleting SAD entry with SPI c6bcf84d
Mar 17 12:50:00 server-name charon: 08[KNL] deleted SAD entry with SPI c6bcf84d
Mar 17 12:50:00 server-name charon: 08[KNL] deleting SAD entry with SPI b74162a4
Mar 17 12:50:00 server-name charon: 08[KNL] deleted SAD entry with SPI b74162a4
Mar 17 12:50:00 server-name charon: 08[ENC] generating INFORMATIONAL response 2 [ D ]
Mar 17 12:50:00 server-name charon: 08[NET] sending packet: from INT.SRVR.IP.ADR[4500] to MY.CLNT.IP.ADR[4500] (80 bytes)
Mar 17 12:50:00 server-name charon: 08[MGR] checkin IKE_SA ikev2-pubkey[1]
Mar 17 12:50:00 server-name charon: 08[MGR] checkin of IKE_SA successful
Mar 17 12:50:00 server-name charon: 04[NET] sending packet: from INT.SRVR.IP.ADR[4500] to MY.CLNT.IP.ADR[4500]
Mar 17 12:50:00 server-name charon: 03[NET] received packet: from MY.CLNT.IP.ADR[4500] to INT.SRVR.IP.ADR[4500]
Mar 17 12:50:00 server-name charon: 03[NET] waiting for data on sockets
Mar 17 12:50:00 server-name charon: 11[MGR] checkout IKEv2 SA by message with SPIs cc34c04e15f31fd2_i e5bd885ad183b108_r
Mar 17 12:50:00 server-name charon: 11[MGR] IKE_SA ikev2-pubkey[1] successfully checked out
Mar 17 12:50:00 server-name charon: 11[NET] received packet: from MY.CLNT.IP.ADR[4500] to INT.SRVR.IP.ADR[4500] (80 bytes)
Mar 17 12:50:00 server-name charon: 11[ENC] parsed INFORMATIONAL request 3 [ D ]
Mar 17 12:50:00 server-name charon: 11[IKE] received DELETE for IKE_SA ikev2-pubkey[1]
Mar 17 12:50:00 server-name charon: 11[IKE] deleting IKE_SA ikev2-pubkey[1] between INT.SRVR.IP.ADR[EXT.SRVR.IP.ADR]...MY.CLNT.IP.ADR[CN=me]
Mar 17 12:50:00 server-name charon: 11[IKE] IKE_SA ikev2-pubkey[1] state change: ESTABLISHED => DELETING
Mar 17 12:50:00 server-name charon: 11[IKE] IKE_SA deleted
Mar 17 12:50:00 server-name charon: 11[ENC] generating INFORMATIONAL response 3 [ ]
Mar 17 12:50:00 server-name charon: 11[NET] sending packet: from INT.SRVR.IP.ADR[4500] to MY.CLNT.IP.ADR[4500] (80 bytes)
Mar 17 12:50:00 server-name charon: 11[MGR] checkin and destroy IKE_SA ikev2-pubkey[1]
Mar 17 12:50:00 server-name charon: 11[IKE] IKE_SA ikev2-pubkey[1] state change: DELETING => DESTROYING
Mar 17 12:50:00 server-name charon: 11[CFG] lease 10.10.10.1 by 'CN=me' went offline
Mar 17 12:50:00 server-name charon: 11[MGR] checkin and destroy of IKE_SA successful

Connection properties reported by Windows:

DataEncryption = Require maximum
PrerequisiteEntry = 
AutoLogon = No
UseRasCredentials = Yes
Authentication Type = Machine Certificate 
Ipv4DefaultGateway = Yes
Ipv4AddressAssignment = By Server
Ipv4DNSServerAssignment = By Server
Ipv6DefaultGateway = Yes
Ipv6AddressAssignment = By Server
Ipv6DNSServerAssignment = By Server
IpDnsFlags = Register primary domain suffix
IpNBTEnabled = Yes
UseFlags = Private Connection
ConnectOnWinlogon = No
Mobility enabled for IKEv2 = Yes.
Dial-in User = admin
VpnStrategy = IKEv2

When the connection is frozen (does not pass traffic), swanctl --list-sas reprts the following

ikev2-pubkey: #1, ESTABLISHED, IKEv2, f77fbfbe7c371b32_i e0e250355a87db62_r*
   local  'EXT.SRVR.IP.ADR' @ INT.SRVR.IP.ADR[4500]
   remote 'CN=me' @ MY.CLNT.IP.ADR[4500] [10.10.10.1]
   AES_CBC-256/HMAC_SHA2_256_128/PRF_HMAC_SHA2_256/MODP_2048
   established 287s ago
   ikev2-pubkey: #1, reqid 1, INSTALLED, TUNNEL-in-UDP, ESP:AES_CBC-256/HMAC_SHA1_96
     installed 287s ago
     in  ce57563f, 792014 bytes,  4493 packets,   150s ago
     out 6b24b7fd, 10904301 bytes, 10680 packets,     1s ago
     local  0.0.0.0/0
     remote 10.10.10.1/32

Windows also shows the connection as working, and no signs of errors in the event viewer and no relevant blocked packets in the SEP firewall logs.

Server: Debian 4.9.246-2, strongSwan 5.5.1.

Client: Windows 2008 R2, Agile VPN (set up through connection properties)

What may be the reason of such behavior and how to fix it?

What can I do to find out the exact reason?

I would be very grateful for any help.

UPD1: The connection freezes most often (or may be always) when the outgoing traffic becomes relatively high. For example, when I visit speedtest.net, the connection freezes an the moment when it tries to meter the upload speed.

UPD2: Other devices work fine on the same local network, behind the same router, NAT, ISP etc. This clearly indicates that the problem is only related to the specific machine with W2k8. There is SEP firewall on the machine, but it is not the culprit -- turning it off does not affect the behavior. Strongswan is hardly relevant too, since it is an already-established tunnel that freezes.

m. vokhm
  • 1
  • 5
  • Seems to be a client issue. We see in the log that it first deletes the CHILD_SA and then the IKE_SA. No idea why it would do that. Not only the deletion as such but also that it first deletes the CHILD_SA because deleting the IKE_SA deletes that anyway. Does it log anything? – ecdsa Mar 18 '22 at 12:15
  • @ecdsa -- When you say "Does it log anything?", do you mean that I can find something relevant in some other log? Then, where do I look at? Or do I change the `charondebug` settings in the conf file to see some additional info? Then what should I change? – m. vokhm Mar 18 '22 at 12:56
  • I was referring to the client (somewhere in the event viewer maybe). – ecdsa Mar 18 '22 at 13:17
  • @ecdsa Oh, I see. No, nothing pertaining to the issue. Everything looks like if the connection was successfully established, has been working for some time, and then disconnected by the user. – m. vokhm Mar 18 '22 at 13:40

1 Answers1

0

The reason was a router with not quite good local ports. Wireshark showed that quite a lot of packets in the local ethernet was being lost. Plain tcp connections could bare with it so I could not notice the disrepair, but esp tunnel had been freezing.

I realize that it's not too informative message, yet I put it here as an answer so that other people who might encounter a similar issue didn't lose too much time googling, studying manuals, and checking configurations, when simply replacing the router may solve the problem.

m. vokhm
  • 1
  • 5