Ipsec L2L unstable

mik256
mik256 Posts: 12
First Comment Friend Collector
edited April 11 in Security

USG Flex 50 (latest firmware) behind NAT as initiator, stronswan on the other side of the tunnel (also behind NAT, with 500 and 4500 ports redirected).

Tunnel is working fine, but I got random disconnects after several hours sometimes even a day or two, it disconnects and only way how to bring the tunnel back is to reboot zyxel. Then after reboot, it gets instantly connected. There are lot of other tunnels setup on strongswan, mostly tplinks without any issues.

In logs, I can see the following:

Zyxel

[INIT] Send:[SAi1][KE][NONCE][NOTIFY][NOTIFY][VID][VID][VID][VID][VID] 192.168.255.6:500 strongswanPublicIP:500
[INIT] Recv:[SA][KE][NONCE][NOTIFY][NOTIFY][CERTREQ][NOTIFY] strongswanPublicIP:500 192.168.255.6:500
[AUTH] Send:[IDi][CERTREQ][IDr][AUTH][SAi2][TSi][TSr][NOTIFY][NOTIFY][NOTIFY][NOTIFY] 192.168.255.6:4500 strongswanPublicIP:4500
The cookie pair is : 0x664c01cb0705eeef / 0x055c76de34c4e750 192.168.255.6:4500 strongswanPublicIP:4500
IKE SA [mVPN] is disconnected 192.168.255.6:4500 strongswanPublicIP:4500

StrongSwan

received packet: from zyxelPublicIP[55905] to strongswanNATip[500] (648 bytes)
parsed IKE_SA_INIT request 0 [ SA KE No N(NATD_S_IP) N(NATD_D_IP) V V V V V ]
zyxelPublicIP is initiating an IKE_SA
generating IKE_SA_INIT response 0 [ SA KE No N(NATD_S_IP) N(NATD_D_IP) CERTREQ N(MULT_AUTH) ]
sending packet: from 192.168.40.2[500] to zyxelPublicIP[55905] (505 bytes)

What can I do to make the tunnel stable?

All Replies

  • Zyxel_James
    Zyxel_James Posts: 663  Zyxel Employee
    Zyxel Certified Network Administrator - Security Zyxel Certified Network Administrator - Nebula Zyxel Certified Sales Associate 100 Answers

    the logs seem not complete, could you help collect the logs on both sides in three different scenarios? I would like to check the difference in the behavior.

    1. The complete log of strongswan connect to VPN successfully
    2. The complete log of strongswan disconnect after connecting successfully
    3. The complete log of strongswan fails to connect to VPN.

  • mik256
    mik256 Posts: 12
    First Comment Friend Collector
    edited April 11

    Hello, there are many working tunnels on strongswan side, so it's a bit hard do distinguish what belongs to the problematic zyxel one. However, I was able to dig these from unsuccessful reconnection attempt. Strangely, I can't see the Send:[ID][HASH][NOTIFY:INITIAL_CONTACT] 192.168.255.6:4500 strongSwanPublicIP:4500 in strongswan tcpdump and also after zyxel reboot, everything starts working again.

    zyxel
    2 11.04.2024 9:36 info IKE ISAKMP SA [mKerioIKEv1] is disconnected 192.168.255.6:4500 strongSwanPublicIP:4500 IKE_LOG
    3 11.04.2024 9:36 info IKE The cookie pair is : 0x13e9ecf79ca29e16 / 0x7d63139f1706965c 192.168.255.6:4500 strongSwanPublicIP:4500 IKE_LOG
    4 11.04.2024 9:35 info IKE Send:[ID][HASH][NOTIFY:INITIAL_CONTACT] 192.168.255.6:4500 strongSwanPublicIP:4500 IKE_LOG
    5 11.04.2024 9:35 info IKE The cookie pair is : 0x13e9ecf79ca29e16 / 0x7d63139f1706965c 192.168.255.6:4500 strongSwanPublicIP:4500 IKE_LOG
    6 11.04.2024 9:35 info IKE Recv:[KE][NONCE][PRV][PRV] strongSwanPublicIP:500 192.168.255.6:500 IKE_LOG
    7 11.04.2024 9:35 info IKE Send:[KE][NONCE][PRV][PRV] 192.168.255.6:500 strongSwanPublicIP:500 IKE_LOG
    8 11.04.2024 9:35 info IKE The cookie pair is : 0x13e9ecf79ca29e16 / 0x7d63139f1706965c 192.168.255.6:500 strongSwanPublicIP:500 IKE_LOG
    9 11.04.2024 9:35 info IKE Recv:[SA][VID][VID][VID] strongSwanPublicIP:500 192.168.255.6:500 IKE_LOG
    10 11.04.2024 9:35 info IKE The cookie pair is : 0x7d63139f1706965c / 0x13e9ecf79ca29e16 [count=2] strongSwanPublicIP:500 192.168.255.6:500 IKE_LOG
    11 11.04.2024 9:35 info IKE Send:[SA][VID][VID][VID][VID][VID][VID][VID][VID][VID][VID] 192.168.255.6:500 strongSwanPublicIP:500 IKE_LOG
    12 11.04.2024 9:35 info IKE Send Main Mode request to [212.20.119.106] 192.168.255.6:500 strongSwanPublicIP:500 IKE_LOG
    13 11.04.2024 9:35 info IKE Tunnel [mKerioVPN] Sending IKE request 192.168.255.6:500 strongSwanPublicIP:500 IKE_LOG
    14 11.04.2024 9:35 info IKE The cookie pair is : 0x13e9ecf79ca29e16 / 0x0000000000000000 [count=3] 192.168.255.6:500 strongSwanPublicIP:500 IKE_LOG

    strongswan
    [11/Apr/2024 10:20:27] {charon} charon: 08[NET] received packet: from zyxelPublicIP[56228] to 192.168.40.2[500] (398 bytes)
    [11/Apr/2024 10:20:27] {charon} charon: 08[ENC] parsed ID_PROT request 0 [ SA V V V V V V V V V V ]
    [11/Apr/2024 10:20:27] {charon} charon: 08[ENC] received unknown vendor ID: f7:58:f2:26:68:75:0f:03:b0:8d:f6:eb:e1:d0:04:03
    [11/Apr/2024 10:20:27] {charon} charon: 08[IKE] received draft-ietf-ipsec-nat-t-ike-02 vendor ID
    [11/Apr/2024 10:20:27] {charon} charon: 08[IKE] received draft-ietf-ipsec-nat-t-ike-02\n vendor ID
    [11/Apr/2024 10:20:27] {charon} charon: 08[IKE] received draft-ietf-ipsec-nat-t-ike-03 vendor ID
    [11/Apr/2024 10:20:27] {charon} charon: 08[IKE] received NAT-T (RFC 3947) vendor ID
    [11/Apr/2024 10:20:27] {charon} charon: 08[IKE] received DPD vendor ID
    [11/Apr/2024 10:20:27] {charon} charon: 08[ENC] received unknown vendor ID: af:ca:d7:13:68:a1:f1:c9:6b:86:96:fc:77:57
    [11/Apr/2024 10:20:27] {charon} charon: 08[ENC] received unknown vendor ID: f9:19:6d:f8:6b:81:2f:b0:f6:80:26:d8:87:6d:cb:7b:00:04:32:00
    [11/Apr/2024 10:20:27] {charon} charon: 08[ENC] received unknown vendor ID: ac:40:f8:c4:38:99:27:c6:e8:ac:24:53:1b:b7:8b:2b:3f:44:3b:a4:f0:23:38:3c:49:1a:36:9a:08:84:3a:5d:f9:86:fc:5c:c1:4b:ae:ed:8c:ec:b7:90:8f:24:1f:e6:3c:a8:1d:4b:5b:70:72:48:33:6a:19:a8:ae:40:68:99:48:18:f0:de:8a:85:a5:c9:82:f4:e6:6c:12:32:0f:62:9b:74:3d:c1:e7:56:f3:35:5d:9c:a5:b8:b9:e5:67:df:8f:4c:71:15:77:11:75:3d:04:ba:91:e3:65:c1:7d:da:76:82:d4:45:5a:3f:fc:63:2e:57:10:55:91:8e:4e:15
    [11/Apr/2024 10:20:27] {charon} charon: 08[ENC] received unknown vendor ID: b6:c9:8c:ca:29:0a:eb:be:37:f1:9f:31:12:d2:d7:cb
    [11/Apr/2024 10:20:27] {charon} charon: 08[IKE] zyxelPublicIP is initiating a Main Mode IKE_SA
    [11/Apr/2024 10:20:27] {charon} charon: 08[ENC] generating ID_PROT response 0 [ SA V V V ]
    [11/Apr/2024 10:20:27] {charon} charon: 08[NET] sending packet: from 192.168.40.2[500] to zyxelPublicIP[56228] (136 bytes)
    [11/Apr/2024 10:20:28] {charon} charon: 12[NET] received packet: from zyxelPublicIP[56228] to 192.168.40.2[500] (356 bytes)
    [11/Apr/2024 10:20:28] {charon} charon: 12[ENC] parsed ID_PROT request 0 [ KE No NAT-D NAT-D ]
    [11/Apr/2024 10:20:28] {charon} charon: 12[IKE] local host is behind NAT, sending keep alives
    [11/Apr/2024 10:20:28] {charon} charon: 12[IKE] remote host is behind NAT
    [11/Apr/2024 10:20:28] {charon} charon: 12[IKE] trying shared key for '%any'[(null)] - '%any'[(null)]
    [11/Apr/2024 10:20:28] {charon} charon: 12[ENC] generating ID_PROT response 0 [ KE No NAT-D NAT-D ]
    [11/Apr/2024 10:20:28] {charon} charon: 12[NET] sending packet: from 192.168.40.2[500] to zyxelPublicIP[56228] (372 bytes)

  • mik256
    mik256 Posts: 12
    First Comment Friend Collector

    And after reboot, the tunnel connects instantly again:

    63 11.04.2024 10:26 info IKE Tunnel [mKerioIKEv1:mKerioVPN:0xc77fb2c7] built successfully 192.168.255.6:4500  StrongSwanPublicIP:4500 IKE_LOG
    64 11.04.2024 10:26 info IKE [ESP aes-cbc|hmac-sha1-96][SPI 0x8cdfb2f6|0xc77fb2c7][Lifetime 3180] 192.168.255.6:4500  StrongSwanPublicIP:4500 IKE_LOG
    65 11.04.2024 10:26 info IKE [Policy: ipv4(192.168.29.0-192.168.29.255)-ipv4(10.0.0.0-10.255.255.255)] 192.168.255.6:4500  StrongSwanPublicIP:4500 IKE_LOG
    66 11.04.2024 10:26 info IKE [Initiator:192.168.255.6][Responder:StrongSwanPublicIP] 192.168.255.6:4500  StrongSwanPublicIP:4500 IKE_LOG
    67 11.04.2024 10:26 info IKE Send:[HASH] 192.168.255.6:4500  StrongSwanPublicIP:4500 IKE_LOG
    68 11.04.2024 10:26 info IKE Recv:[HASH][SA][NONCE][ID][ID]  StrongSwanPublicIP:4500 192.168.255.6:4500 IKE_LOG
    69 11.04.2024 10:26 info IKE Send:[HASH][SA][NONCE][ID][ID] 192.168.255.6:4500  StrongSwanPublicIP:4500 IKE_LOG
    70 11.04.2024 10:26 info IKE Phase 1 IKE SA process done 192.168.255.6:4500  StrongSwanPublicIP:4500 IKE_LOG
    71 11.04.2024 10:26 info IKE Recv:[ID][HASH]  StrongSwanPublicIP:4500 192.168.255.6:4500 IKE_LOG
    72 11.04.2024 10:26 info IKE The cookie pair is : 0x5f830de2927846be / 0x1fc01b707673badb [count=2]  StrongSwanPublicIP:4500 192.168.255.6:4500 IKE_LOG
    73 11.04.2024 10:26 info IKE Send:[ID][HASH][NOTIFY:INITIAL_CONTACT] 192.168.255.6:4500  StrongSwanPublicIP:4500 IKE_LOG
    74 11.04.2024 10:26 info IKE The cookie pair is : 0x1fc01b707673badb / 0x5f830de2927846be [count=8] 192.168.255.6:4500  StrongSwanPublicIP:4500 IKE_LOG
    75 11.04.2024 10:26 info System NTP update has succeeded. Current time is Thu Apr 11 10:26:38 UTC +02:00 DST 2024. Last time is Thu Apr 11 10:26:09 UTC +02:00 DST 2024. System
    76 11.04.2024 10:26 info IKE Recv:[KE][NONCE][PRV][PRV]  StrongSwanPublicIP:500 192.168.255.6:500 IKE_LOG
    77 11.04.2024 10:26 info IKE Send:[KE][NONCE][PRV][PRV] 192.168.255.6:500  StrongSwanPublicIP:500 IKE_LOG
    78 11.04.2024 10:26 info IKE The cookie pair is : 0x1fc01b707673badb / 0x5f830de2927846be 192.168.255.6:500  StrongSwanPublicIP:500 IKE_LOG
    79 11.04.2024 10:26 info Policy Route Trunk SYSTEM_DEFAULT_WAN_TRUNK alive, related policy route rules will be re-enabled. TRUNK ALIVE
    80 11.04.2024 10:26 info Policy Route Interface wan alive, related policy route rules will be re-enabled. INTERFACE ALIVE
    81 11.04.2024 10:26 alert System Device starts up.
    82 11.04.2024 10:26 info IKE Recv:[SA][VID][VID][VID]  StrongSwanPublicIP:500 192.168.255.6:500 IKE_LOG
    83 11.04.2024 10:26 info IKE The cookie pair is : 0x5f830de2927846be / 0x1fc01b707673badb [count=2]  StrongSwanPublicIP:500 192.168.255.6:500 IKE_LOG
    84 11.04.2024 10:26 info IKE Send:[SA][VID][VID][VID][VID][VID][VID][VID][VID][VID][VID] 192.168.255.6:500  StrongSwanPublicIP:500 IKE_LOG
    85 11.04.2024 10:26 info IKE Send Main Mode request to [StrongSwanPublicIP] 192.168.255.6:500  StrongSwanPublicIP:500 IKE_LOG
    86 11.04.2024 10:26 info IKE Tunnel [mKerioVPN] Sending IKE request 192.168.255.6:500  StrongSwanPublicIP:500 IKE_LOG
    87 11.04.2024 10:26 info IKE The cookie pair is : 0x1fc01b707673badb / 0x0000000000000000 [count=3] 192.168.255.6:500  StrongSwanPublicIP:500 IKE_LOG

    [11/Apr/2024 10:26:40] {charon} charon: 07[NET] received packet: from zyxelPublicIP[56107] to 192.168.40.2[4500] (92 bytes)
    [11/Apr/2024 10:26:40] {charon} charon: 07[IKE] trying shared key for 'StrongSwanPublicIP'[(null)] - '195.12.150.178'[(null)]
    [11/Apr/2024 10:26:40] {charon} charon: 07[ENC] parsed ID_PROT request 0 [ ID HASH N(INITIAL_CONTACT) ]
    [11/Apr/2024 10:26:40] {charon} charon: 07[CFG] looking for pre-shared key peer configs matching 192.168.40.2...zyxelPublicIP[192.168.255.6]
    [11/Apr/2024 10:26:40] {charon} charon: 07[CFG] Including peer config "tunnel_13_1_1_1"
    [11/Apr/2024 10:26:40] {charon} charon: 07[CFG] Skipping peer config "vpnserver_1" - PSK mismatch
    [11/Apr/2024 10:26:40] {charon} charon: 07[CFG] selected peer config "tunnel_13_1_1_1"
    [11/Apr/2024 10:26:40] {charon} charon: 07[IKE] IKE_SA tunnel_13_1_1_1[6302] established between 192.168.40.2[StrongSwanPublicIP]...zyxelPublicIP[192.168.255.6]
    [11/Apr/2024 10:26:40] {charon} charon: 07[ENC] generating ID_PROT response 0 [ ID HASH ]
    [11/Apr/2024 10:26:40] {charon} charon: 07[NET] sending packet: from 192.168.40.2[4500] to zyxelPublicIP[56107] (76 bytes)
    [11/Apr/2024 10:26:41] {charon} charon: 08[NET] received packet: from zyxelPublicIP[56107] to 192.168.40.2[4500] (156 bytes)
    [11/Apr/2024 10:26:41] {charon} charon: 08[ENC] parsed QUICK_MODE request 2407479896 [ HASH SA No ID ID ]
    [11/Apr/2024 10:26:41] {charon} charon: 08[IKE] received 3600s lifetime, configured 0s
    [11/Apr/2024 10:26:41] {charon} charon: 08[ENC] generating QUICK_MODE response 2407479896 [ HASH SA No ID ID ]
    [11/Apr/2024 10:26:41] {charon} charon: 08[NET] sending packet: from 192.168.40.2[4500] to zyxelPublicIP[56107] (188 bytes)
    [11/Apr/2024 10:26:42] {charon} charon: 11[NET] received packet: from zyxelPublicIP[56107] to 192.168.40.2[4500] (60 bytes)
    [11/Apr/2024 10:26:42] {charon} charon: 11[ENC] parsed QUICK_MODE request 2407479896 [ HASH ]
    [11/Apr/2024 10:26:42] {charon} charon: 11[KNL] policy already exists, try to update it
    [11/Apr/2024 10:26:42] {charon} Last message repeated 3 times
    [11/Apr/2024 10:26:42] {charon} charon: 11[IKE] CHILD_SA tunnel_13_1_1_1{21374} established with SPIs c77fb2c7_i 8cdfb2f6_o and TS 10.0.0.0/8 === 192.168.29.0/24

Security Highlight