Testing DMVPN with 1.2.0 rc10 - encryption problem with spoke to spoke and spoke to hub communication at the same time

General questions
1

Currently I am testing the baseline DMVPN configuration from the Wiki (https://wiki.vyos.net/wiki/DMVPN)with vyos 1.2 rc10. I am doing the tests under GNS3/KVM. I use the configuration from the Wiki, adapted to my test environment.
In parallel I test the same setup with Vyos 1.1.8. to compare.
I use the same configuration for both Vyos versions.
Now to my questions and problems.

  1. under version 1.2.0 rc10 there is no output of the command “show vpn ipsec sa”. The output is empty.

    vyos@SPOKE1:~$ show vpn ipsec sa
    Connection State Up Bytes In/Out Remote address Remote ID Proposal

In comparison, the output under 1.1.8.
vyos@SPOKE1:~$ show vpn ipsec sa
Peer ID / IP Local ID / IP
------------ -------------
1.1.1.1 2.2.2.100

Tunnel  State  Bytes Out/In   Encrypt  Hash  NAT-T  A-Time  L-Time  Proto
------  -----  -------------  -------  ----  -----  ------  ------  -----
tun0    up     134.0/154.0    aes256   sha1  no     3500    3600    gre

  1. after the environment has started up (version 1.2.0 rc10), the tunnels from each spoke to the hub are ready. Ping between SPOKE1 and HUB and SPOKE 2 and HUB works encrypted without problems. A tunnel between SPOKE1 and SPOKE2 is not yet established. When I start a ping between SPOKE1 and SPOKE2, the tunnel is built dynamically and the ping is encrypted. If I then execute a ping again from SPOKE1 to the HUB, it is transported unencrypted (as seen in the Wireshark trace). Is this a problem with the configuration under 1.2.0 rc10? With version 1.1.8 both pings are encrypted. Under 1.2.0.rc10 there is no only 1 sa in SPOKE1 (SPOKE1 to SPOKE2).

    vyos@SPOKE1:~$ show vpn ipsec sa verbose
    Status of IKE charon daemon (strongSwan 5.6.2, Linux 4.19.4-amd64-vyos, x86_64):
    uptime: 11 minutes, since Dec 09 11:06:13 2018
    malloc: sbrk 1892352, mmap 0, used 788832, free 1103520
    worker threads: 11 of 16 idle, 5/0/0/0 working, job queue: 0/0/0/0, scheduled: 6
    loaded plugins: charon test-vectors ldap pkcs11 tpm aes rc2 sha2 sha1 md5 mgf1 random nonce x509 revocation constraints pubkey pkcs1 pkcs7 pkcs8 pkcs12 pgp dnskey sshkey pem openssl gcrypt af-alg fips-prf gmp curve25519 agent xcbc cmac hmac ctr ccm gcm curl attr kernel-netlink resolve socket-default connmark stroke vici updown eap-identity eap-aka eap-md5 eap-gtc eap-mschapv2 eap-radius eap-tls eap-ttls eap-tnc xauth-generic xauth-eap xauth-pam xauth-noauth tnc-tnccs dhcp lookip error-notify certexpire led addrblock counters
    Listening IP addresses:
    2.2.2.100
    Connections:
    vpnprof-dmvpn-tun0: %any…%any IKEv1
    vpnprof-dmvpn-tun0: local: [2.2.2.100] uses pre-shared key authentication
    vpnprof-dmvpn-tun0: remote: uses pre-shared key authentication
    dmvpn: child: dynamic[gre] === dynamic[gre] TUNNEL
    Security Associations (1 up, 0 connecting):
    vpnprof-dmvpn-tun0[3]: ESTABLISHED 62 seconds ago, 2.2.2.100[2.2.2.100]…3.3.3.100[3.3.3.100]
    vpnprof-dmvpn-tun0[3]: IKEv1 SPIs: 7df9376b7341d794_i 676dda869a6da723_r*, rekeying in 58 minutes
    vpnprof-dmvpn-tun0[3]: IKE proposal: AES_CBC_256/HMAC_SHA1_96/PRF_HMAC_SHA1/MODP_1024
    dmvpn{3}: INSTALLED, TUNNEL, reqid 2, ESP SPIs: cce2aa15_i c2a13f28_o
    dmvpn{3}: AES_CBC_256/HMAC_SHA1_96/MODP_1024, 224 bytes_i (2 pkts, 61s ago), 224 bytes_o (2 pkts, 61s ago), rekeying in 24 minutes
    dmvpn{3}: 2.2.2.100/32[gre] === 3.3.3.100/32[gre]

2

I think we need some more info. Here’s my design. The router INTERNET simulates the Internet.

dmvpn

If I start the topology SPOKE1 and SPOKE2 are connected with the HUB. Here are the Outputs from HUB, SPOKE1 and SPOKE2.

vyos@HUB:~$ show vpn ipsec sa 
Connection    State    Up    Bytes In/Out    Remote address    Remote ID    Proposal
------------  -------  ----  --------------  ----------------  -----------  ----------

The output is empty.

grafik
grafik653×617 76.2 KB

vyos@SPOKE1:~$ show vpn ipsec sa 
Connection    State    Up    Bytes In/Out    Remote address    Remote ID    Proposal
------------  -------  ----  --------------  ----------------  -----------  ----------

The output from SPOKE1 is empty also.

grafik

The output of SPOKE2 is identical to SPOKE1.
The Ping from SPOKE1 to HUB and from SPOKE2 to HUB works as expected. The traffic is encrypted. With the Ping from SPOKE1 to SPOKE2 some things are interesting.

  1. the Ping traffic is encrypted (as expected)
  2. both SA’s on the HUB are deleted (not expected)
  3. new SA’s on SPOKE1 and SPOKE2 are generated (expected)
  4. after that the Ping’s from SPOKE1 and SPOKE2 to HUB are unecrypted (not expected but it is no SA on SPOKE1, SPOKE2 and HUB for that communication)

Output Ping from SPOKE1 to SPOKE2

vyos@SPOKE1:~$ ping 192.168.3.1 interface 192.168.2.1 count 3
PING 192.168.3.1 (192.168.3.1) from 192.168.2.1 : 56(84) bytes of data.
64 bytes from 192.168.3.1: icmp_seq=1 ttl=63 time=2.89 ms
64 bytes from 192.168.3.1: icmp_seq=2 ttl=64 time=11.5 ms
64 bytes from 192.168.3.1: icmp_seq=3 ttl=64 time=5.58 ms

--- 192.168.3.1 ping statistics ---
3 packets transmitted, 3 received, 0% packet loss, time 2002ms
rtt min/avg/max/mdev = 2.898/6.669/11.521/3.602 ms

Output from HUB (ipsec)

vyos@HUB:~$ show vpn ipsec sa verbose 
Status of IKE charon daemon (strongSwan 5.6.2, Linux 4.19.4-amd64-vyos, x86_64):
  uptime: 62 minutes, since Dec 13 19:39:05 2018
  malloc: sbrk 1892352, mmap 0, used 772256, free 1120096
  worker threads: 11 of 16 idle, 5/0/0/0 working, job queue: 0/0/0/0, scheduled: 6
  loaded plugins: charon test-vectors ldap pkcs11 tpm aes rc2 sha2 sha1 md5 mgf1 random nonce x509 revocation constraints pubkey pkcs1 pkcs7 pkcs8 pkcs12 pgp dnskey sshkey pem openssl gcrypt af-alg fips-prf gmp curve25519 agent xcbc cmac hmac ctr ccm gcm curl attr kernel-netlink resolve socket-default connmark stroke vici updown eap-identity eap-aka eap-md5 eap-gtc eap-mschapv2 eap-radius eap-tls eap-ttls eap-tnc xauth-generic xauth-eap xauth-pam xauth-noauth tnc-tnccs dhcp lookip error-notify certexpire led addrblock counters
Listening IP addresses:
  1.1.1.1
Connections:
vpnprof-dmvpn-tun0:  %any...%any  IKEv1
vpnprof-dmvpn-tun0:   local:  [1.1.1.1] uses pre-shared key authentication
vpnprof-dmvpn-tun0:   remote: uses pre-shared key authentication
       dmvpn:   child:  dynamic[gre] === dynamic[gre] TUNNEL
Security Associations (0 up, 0 connecting):
  none

Output from SPOKE1 (ipsec)

vyos@SPOKE1:~$ show vpn ipsec sa verbose 
Status of IKE charon daemon (strongSwan 5.6.2, Linux 4.19.4-amd64-vyos, x86_64):
  uptime: 61 minutes, since Dec 13 19:40:06 2018
  malloc: sbrk 1892352, mmap 0, used 789968, free 1102384
  worker threads: 11 of 16 idle, 5/0/0/0 working, job queue: 0/0/0/0, scheduled: 8
  loaded plugins: charon test-vectors ldap pkcs11 tpm aes rc2 sha2 sha1 md5 mgf1 random nonce x509 revocation constraints pubkey pkcs1 pkcs7 pkcs8 pkcs12 pgp dnskey sshkey pem openssl gcrypt af-alg fips-prf gmp curve25519 agent xcbc cmac hmac ctr ccm gcm curl attr kernel-netlink resolve socket-default connmark stroke vici updown eap-identity eap-aka eap-md5 eap-gtc eap-mschapv2 eap-radius eap-tls eap-ttls eap-tnc xauth-generic xauth-eap xauth-pam xauth-noauth tnc-tnccs dhcp lookip error-notify certexpire led addrblock counters
Listening IP addresses:
  2.2.2.100
Connections:
vpnprof-dmvpn-tun0:  %any...%any  IKEv1
vpnprof-dmvpn-tun0:   local:  [2.2.2.100] uses pre-shared key authentication
vpnprof-dmvpn-tun0:   remote: uses pre-shared key authentication
       dmvpn:   child:  dynamic[gre] === dynamic[gre] TUNNEL
Security Associations (1 up, 0 connecting):
vpnprof-dmvpn-tun0[3]: ESTABLISHED 12 seconds ago, 2.2.2.100[2.2.2.100]...3.3.3.100[3.3.3.100]
vpnprof-dmvpn-tun0[3]: IKEv1 SPIs: 09149165f6a38672_i* 4f9b919418eed65e_r, rekeying in 59 minutes
vpnprof-dmvpn-tun0[3]: IKE proposal: AES_CBC_256/HMAC_SHA1_96/PRF_HMAC_SHA1/MODP_1024
       dmvpn{5}:  INSTALLED, TUNNEL, reqid 2, ESP SPIs: ca78a753_i cb2ce35e_o
       dmvpn{5}:  AES_CBC_256/HMAC_SHA1_96/MODP_1024, 224 bytes_i (2 pkts, 10s ago), 224 bytes_o (2 pkts, 11s ago), rekeying in 20 minutes
       dmvpn{5}:   2.2.2.100/32[gre] === 3.3.3.100/32[gre]

here still the trace from ping of SPOKE1 to HUB (unencrypted included NHRP traffic)

grafik
grafik938×99 9.34 KB

Here the log data (ipsec) of HUB and SPOKE1. There are DELETE for ike_sa messages in the log file.

vyos@HUB:~$ show log | match "HUB charon"
Dec 13 19:39:05 HUB charon[1592]: 00[DMN] Starting IKE charon daemon (strongSwan 5.6.2, Linux 4.19.4-amd64-vyos, x86_64)
Dec 13 19:39:05 HUB charon[1592]: 00[CFG] PKCS11 module '<name>' lacks library path
Dec 13 19:39:05 HUB charon[1592]: 00[CFG] loading ca certificates from '/etc/ipsec.d/cacerts'
Dec 13 19:39:05 HUB charon[1592]: 00[CFG] loading aa certificates from '/etc/ipsec.d/aacerts'
Dec 13 19:39:05 HUB charon[1592]: 00[CFG] loading ocsp signer certificates from '/etc/ipsec.d/ocspcerts'
Dec 13 19:39:05 HUB charon[1592]: 00[CFG] loading attribute certificates from '/etc/ipsec.d/acerts'
Dec 13 19:39:05 HUB charon[1592]: 00[CFG] loading crls from '/etc/ipsec.d/crls'
Dec 13 19:39:05 HUB charon[1592]: 00[CFG] loading secrets from '/etc/ipsec.secrets'
Dec 13 19:39:05 HUB charon[1592]: 00[CFG] loaded 0 RADIUS server configurations
Dec 13 19:39:05 HUB charon[1592]: 00[CFG] HA config misses local/remote address
Dec 13 19:39:05 HUB charon[1592]: 00[LIB] loaded plugins: charon test-vectors ldap pkcs11 tpm aes rc2 sha2 sha1 md5 mgf1 random nonce x509 revocation constraints pubkey pkcs1 pkcs7 pkcs8 pkcs12 pgp dnskey sshkey pem openssl gcrypt af-alg fips-prf gmp curve25519 agent xcbc cmac hmac ctr ccm gcm curl attr kernel-netlink resolve socket-default connmark stroke vici updown eap-identity eap-aka eap-md5 eap-gtc eap-mschapv2 eap-radius eap-tls eap-ttls eap-tnc xauth-generic xauth-eap xauth-pam xauth-noauth tnc-tnccs dhcp lookip error-notify certexpire led addrblock counters
Dec 13 19:39:05 HUB charon[1592]: 00[LIB] dropped capabilities, running as uid 0, gid 0
Dec 13 19:39:05 HUB charon[1592]: 00[JOB] spawning 16 worker threads
Dec 13 19:39:06 HUB charon[1592]: 13[CFG] loaded IKE shared key with id 'ike-dmvpn-tun0' for: '%any'
Dec 13 19:39:06 HUB charon[1592]: 06[CFG] added vici connection: vpnprof-dmvpn-tun0
Dec 13 19:40:18 HUB charon[1592]: 13[NET] received packet: from 2.2.2.100[500] to 1.1.1.1[500] (216 bytes)
Dec 13 19:40:18 HUB charon[1592]: 13[ENC] parsed ID_PROT request 0 [ SA V V V V V ]
Dec 13 19:40:18 HUB charon[1592]: 13[IKE] received XAuth vendor ID
Dec 13 19:40:18 HUB charon[1592]: 14[NET] received packet: from 3.3.3.100[500] to 1.1.1.1[500] (216 bytes)
Dec 13 19:40:18 HUB charon[1592]: 14[ENC] parsed ID_PROT request 0 [ SA V V V V V ]
Dec 13 19:40:18 HUB charon[1592]: 14[IKE] received XAuth vendor ID
Dec 13 19:40:18 HUB charon[1592]: 14[IKE] received DPD vendor ID
Dec 13 19:40:18 HUB charon[1592]: 14[IKE] received FRAGMENTATION vendor ID
Dec 13 19:40:18 HUB charon[1592]: 14[IKE] received NAT-T (RFC 3947) vendor ID
Dec 13 19:40:18 HUB charon[1592]: 14[IKE] received draft-ietf-ipsec-nat-t-ike-02\n vendor ID
Dec 13 19:40:18 HUB charon[1592]: 14[IKE] 3.3.3.100 is initiating a Main Mode IKE_SA
Dec 13 19:40:18 HUB charon[1592]: 14[ENC] generating ID_PROT response 0 [ SA V V V V ]
Dec 13 19:40:18 HUB charon[1592]: 14[NET] sending packet: from 1.1.1.1[500] to 3.3.3.100[500] (160 bytes)
Dec 13 19:40:18 HUB charon[1592]: 13[IKE] received DPD vendor ID
Dec 13 19:40:18 HUB charon[1592]: 13[IKE] received FRAGMENTATION vendor ID
Dec 13 19:40:18 HUB charon[1592]: 13[IKE] received NAT-T (RFC 3947) vendor ID
Dec 13 19:40:18 HUB charon[1592]: 13[IKE] received draft-ietf-ipsec-nat-t-ike-02\n vendor ID
Dec 13 19:40:18 HUB charon[1592]: 13[IKE] 2.2.2.100 is initiating a Main Mode IKE_SA
Dec 13 19:40:18 HUB charon[1592]: 13[ENC] generating ID_PROT response 0 [ SA V V V V ]
Dec 13 19:40:18 HUB charon[1592]: 13[NET] sending packet: from 1.1.1.1[500] to 2.2.2.100[500] (160 bytes)
Dec 13 19:40:18 HUB charon[1592]: 15[NET] received packet: from 3.3.3.100[500] to 1.1.1.1[500] (244 bytes)
Dec 13 19:40:18 HUB charon[1592]: 15[ENC] parsed ID_PROT request 0 [ KE No NAT-D NAT-D ]
Dec 13 19:40:18 HUB charon[1592]: 16[NET] received packet: from 2.2.2.100[500] to 1.1.1.1[500] (244 bytes)
Dec 13 19:40:18 HUB charon[1592]: 16[ENC] parsed ID_PROT request 0 [ KE No NAT-D NAT-D ]
Dec 13 19:40:18 HUB charon[1592]: 16[ENC] generating ID_PROT response 0 [ KE No NAT-D NAT-D ]
Dec 13 19:40:18 HUB charon[1592]: 16[NET] sending packet: from 1.1.1.1[500] to 2.2.2.100[500] (244 bytes)
Dec 13 19:40:18 HUB charon[1592]: 15[ENC] generating ID_PROT response 0 [ KE No NAT-D NAT-D ]
Dec 13 19:40:18 HUB charon[1592]: 15[NET] sending packet: from 1.1.1.1[500] to 3.3.3.100[500] (244 bytes)
Dec 13 19:40:18 HUB charon[1592]: 05[NET] received packet: from 2.2.2.100[500] to 1.1.1.1[500] (76 bytes)
Dec 13 19:40:18 HUB charon[1592]: 05[ENC] parsed ID_PROT request 0 [ ID HASH ]
Dec 13 19:40:18 HUB charon[1592]: 05[CFG] looking for pre-shared key peer configs matching 1.1.1.1...2.2.2.100[2.2.2.100]
Dec 13 19:40:18 HUB charon[1592]: 05[CFG] selected peer config "vpnprof-dmvpn-tun0"
Dec 13 19:40:18 HUB charon[1592]: 05[IKE] IKE_SA vpnprof-dmvpn-tun0[1] established between 1.1.1.1[1.1.1.1]...2.2.2.100[2.2.2.100]
Dec 13 19:40:18 HUB charon[1592]: 05[IKE] scheduling rekeying in 3558s
Dec 13 19:40:18 HUB charon[1592]: 05[IKE] maximum IKE_SA lifetime 3918s
Dec 13 19:40:18 HUB charon[1592]: 05[ENC] generating ID_PROT response 0 [ ID HASH ]
Dec 13 19:40:18 HUB charon[1592]: 05[NET] sending packet: from 1.1.1.1[500] to 2.2.2.100[500] (76 bytes)
Dec 13 19:40:18 HUB charon[1592]: 07[NET] received packet: from 3.3.3.100[500] to 1.1.1.1[500] (76 bytes)
Dec 13 19:40:18 HUB charon[1592]: 07[ENC] parsed ID_PROT request 0 [ ID HASH ]
Dec 13 19:40:18 HUB charon[1592]: 07[CFG] looking for pre-shared key peer configs matching 1.1.1.1...3.3.3.100[3.3.3.100]
Dec 13 19:40:18 HUB charon[1592]: 07[CFG] selected peer config "vpnprof-dmvpn-tun0"
Dec 13 19:40:18 HUB charon[1592]: 07[IKE] IKE_SA vpnprof-dmvpn-tun0[2] established between 1.1.1.1[1.1.1.1]...3.3.3.100[3.3.3.100]
Dec 13 19:40:18 HUB charon[1592]: 07[IKE] scheduling rekeying in 3573s
Dec 13 19:40:18 HUB charon[1592]: 07[IKE] maximum IKE_SA lifetime 3933s
Dec 13 19:40:18 HUB charon[1592]: 07[ENC] generating ID_PROT response 0 [ ID HASH ]
Dec 13 19:40:18 HUB charon[1592]: 07[NET] sending packet: from 1.1.1.1[500] to 3.3.3.100[500] (76 bytes)
Dec 13 19:40:18 HUB charon[1592]: 09[NET] received packet: from 3.3.3.100[500] to 1.1.1.1[500] (332 bytes)
Dec 13 19:40:18 HUB charon[1592]: 09[ENC] parsed QUICK_MODE request 2555396170 [ HASH SA No KE ID ID ]
Dec 13 19:40:18 HUB charon[1592]: 09[ENC] generating QUICK_MODE response 2555396170 [ HASH SA No KE ID ID ]
Dec 13 19:40:18 HUB charon[1592]: 09[NET] sending packet: from 1.1.1.1[500] to 3.3.3.100[500] (316 bytes)
Dec 13 19:40:18 HUB charon[1592]: 10[NET] received packet: from 2.2.2.100[500] to 1.1.1.1[500] (332 bytes)
Dec 13 19:40:18 HUB charon[1592]: 10[ENC] parsed QUICK_MODE request 1897044593 [ HASH SA No KE ID ID ]
Dec 13 19:40:18 HUB charon[1592]: 10[ENC] generating QUICK_MODE response 1897044593 [ HASH SA No KE ID ID ]
Dec 13 19:40:18 HUB charon[1592]: 10[NET] sending packet: from 1.1.1.1[500] to 2.2.2.100[500] (316 bytes)
Dec 13 19:40:18 HUB charon[1592]: 11[NET] received packet: from 3.3.3.100[500] to 1.1.1.1[500] (60 bytes)
Dec 13 19:40:18 HUB charon[1592]: 11[ENC] parsed QUICK_MODE request 2555396170 [ HASH ]
Dec 13 19:40:18 HUB charon[1592]: 12[NET] received packet: from 2.2.2.100[500] to 1.1.1.1[500] (60 bytes)
Dec 13 19:40:18 HUB charon[1592]: 12[ENC] parsed QUICK_MODE request 1897044593 [ HASH ]
Dec 13 19:40:18 HUB charon[1592]: 11[IKE] CHILD_SA dmvpn{1} established with SPIs c9775a22_i c47ecb7d_o and TS 1.1.1.1/32[gre] === 3.3.3.100/32[gre]
Dec 13 19:40:18 HUB charon[1592]: 12[IKE] CHILD_SA dmvpn{2} established with SPIs c0c6eec5_i c8873515_o and TS 1.1.1.1/32[gre] === 2.2.2.100/32[gre]
Dec 13 20:02:04 HUB charon[1592]: 07[KNL] creating rekey job for CHILD_SA ESP/0xc8873515/2.2.2.100
Dec 13 20:02:04 HUB charon[1592]: 07[ENC] generating QUICK_MODE request 1168808787 [ HASH SA No KE ID ID ]
Dec 13 20:02:04 HUB charon[1592]: 07[NET] sending packet: from 1.1.1.1[500] to 2.2.2.100[500] (332 bytes)
Dec 13 20:02:04 HUB charon[1592]: 09[NET] received packet: from 2.2.2.100[500] to 1.1.1.1[500] (316 bytes)
Dec 13 20:02:04 HUB charon[1592]: 09[ENC] parsed QUICK_MODE response 1168808787 [ HASH SA No KE ID ID ]
Dec 13 20:02:04 HUB charon[1592]: 09[IKE] CHILD_SA dmvpn{3} established with SPIs cb3ec703_i c3f84e90_o and TS 1.1.1.1/32[gre] === 2.2.2.100/32[gre]
Dec 13 20:02:04 HUB charon[1592]: 09[ENC] generating QUICK_MODE request 1168808787 [ HASH ]
Dec 13 20:02:04 HUB charon[1592]: 09[NET] sending packet: from 1.1.1.1[500] to 2.2.2.100[500] (60 bytes)
Dec 13 20:03:53 HUB charon[1592]: 11[KNL] creating rekey job for CHILD_SA ESP/0xc9775a22/1.1.1.1
Dec 13 20:03:53 HUB charon[1592]: 11[ENC] generating QUICK_MODE request 2917389512 [ HASH SA No KE ID ID ]
Dec 13 20:03:53 HUB charon[1592]: 11[NET] sending packet: from 1.1.1.1[500] to 3.3.3.100[500] (332 bytes)
Dec 13 20:03:53 HUB charon[1592]: 14[NET] received packet: from 3.3.3.100[500] to 1.1.1.1[500] (316 bytes)
Dec 13 20:03:53 HUB charon[1592]: 14[ENC] parsed QUICK_MODE response 2917389512 [ HASH SA No KE ID ID ]
Dec 13 20:03:53 HUB charon[1592]: 14[IKE] CHILD_SA dmvpn{4} established with SPIs cec83b87_i c265746f_o and TS 1.1.1.1/32[gre] === 3.3.3.100/32[gre]
Dec 13 20:03:53 HUB charon[1592]: 14[ENC] generating QUICK_MODE request 2917389512 [ HASH ]
Dec 13 20:03:53 HUB charon[1592]: 14[NET] sending packet: from 1.1.1.1[500] to 3.3.3.100[500] (60 bytes)
Dec 13 20:09:00 HUB charon[1592]: 16[KNL] creating rekey job for CHILD_SA ESP/0xc47ecb7d/3.3.3.100
Dec 13 20:09:09 HUB charon[1592]: 06[KNL] creating rekey job for CHILD_SA ESP/0xc0c6eec5/1.1.1.1
Dec 13 20:13:18 HUB charon[1592]: 08[NET] received packet: from 3.3.3.100[500] to 1.1.1.1[500] (76 bytes)
Dec 13 20:13:18 HUB charon[1592]: 08[ENC] parsed INFORMATIONAL_V1 request 1484942209 [ HASH D ]
Dec 13 20:13:18 HUB charon[1592]: 08[IKE] received DELETE for ESP CHILD_SA with SPI c47ecb7d
Dec 13 20:13:18 HUB charon[1592]: 08[IKE] closing CHILD_SA dmvpn{1} with SPIs c9775a22_i (228 bytes) c47ecb7d_o (268 bytes) and TS 1.1.1.1/32[gre] === 3.3.3.100/32[gre]
Dec 13 20:13:18 HUB charon[1592]: 07[NET] received packet: from 2.2.2.100[500] to 1.1.1.1[500] (76 bytes)
Dec 13 20:13:18 HUB charon[1592]: 07[ENC] parsed INFORMATIONAL_V1 request 2981139358 [ HASH D ]
Dec 13 20:13:18 HUB charon[1592]: 07[IKE] received DELETE for ESP CHILD_SA with SPI c8873515
Dec 13 20:13:18 HUB charon[1592]: 07[IKE] closing CHILD_SA dmvpn{2} with SPIs c0c6eec5_i (228 bytes) c8873515_o (268 bytes) and TS 1.1.1.1/32[gre] === 2.2.2.100/32[gre]
Dec 13 20:24:13 HUB charon[1592]: 12[KNL] creating rekey job for CHILD_SA ESP/0xcb3ec703/1.1.1.1
Dec 13 20:24:13 HUB charon[1592]: 12[ENC] generating QUICK_MODE request 2301216445 [ HASH SA No KE ID ID ]
Dec 13 20:24:13 HUB charon[1592]: 12[NET] sending packet: from 1.1.1.1[500] to 2.2.2.100[500] (332 bytes)
Dec 13 20:24:13 HUB charon[1592]: 14[NET] received packet: from 2.2.2.100[500] to 1.1.1.1[500] (316 bytes)
Dec 13 20:24:13 HUB charon[1592]: 14[ENC] parsed QUICK_MODE response 2301216445 [ HASH SA No KE ID ID ]
Dec 13 20:24:13 HUB charon[1592]: 14[IKE] CHILD_SA dmvpn{5} established with SPIs cb511dd6_i c8050767_o and TS 1.1.1.1/32[gre] === 2.2.2.100/32[gre]
Dec 13 20:24:13 HUB charon[1592]: 14[ENC] generating QUICK_MODE request 2301216445 [ HASH ]
Dec 13 20:24:13 HUB charon[1592]: 14[NET] sending packet: from 1.1.1.1[500] to 2.2.2.100[500] (60 bytes)
Dec 13 20:24:26 HUB charon[1592]: 16[KNL] creating rekey job for CHILD_SA ESP/0xc3f84e90/2.2.2.100
Dec 13 20:26:34 HUB charon[1592]: 06[KNL] creating rekey job for CHILD_SA ESP/0xc265746f/3.3.3.100
Dec 13 20:26:34 HUB charon[1592]: 06[ENC] generating QUICK_MODE request 3200482401 [ HASH SA No KE ID ID ]
Dec 13 20:26:34 HUB charon[1592]: 06[NET] sending packet: from 1.1.1.1[500] to 3.3.3.100[500] (332 bytes)
Dec 13 20:26:34 HUB charon[1592]: 08[NET] received packet: from 3.3.3.100[500] to 1.1.1.1[500] (316 bytes)
Dec 13 20:26:34 HUB charon[1592]: 08[ENC] parsed QUICK_MODE response 3200482401 [ HASH SA No KE ID ID ]
Dec 13 20:26:34 HUB charon[1592]: 08[IKE] CHILD_SA dmvpn{6} established with SPIs cb7b33e7_i c9393fa5_o and TS 1.1.1.1/32[gre] === 3.3.3.100/32[gre]
Dec 13 20:26:34 HUB charon[1592]: 08[ENC] generating QUICK_MODE request 3200482401 [ HASH ]
Dec 13 20:26:34 HUB charon[1592]: 08[NET] sending packet: from 1.1.1.1[500] to 3.3.3.100[500] (60 bytes)
Dec 13 20:26:44 HUB charon[1592]: 10[KNL] creating rekey job for CHILD_SA ESP/0xcec83b87/1.1.1.1
Dec 13 20:35:04 HUB charon[1592]: 11[KNL] creating delete job for CHILD_SA ESP/0xcb3ec703/1.1.1.1
Dec 13 20:35:04 HUB charon[1592]: 11[IKE] closing expired CHILD_SA dmvpn{3} with SPIs cb3ec703_i c3f84e90_o and TS 1.1.1.1/32[gre] === 2.2.2.100/32[gre]
Dec 13 20:35:04 HUB charon[1592]: 11[IKE] sending DELETE for ESP CHILD_SA with SPI cb3ec703
Dec 13 20:35:04 HUB charon[1592]: 11[ENC] generating INFORMATIONAL_V1 request 2168447913 [ HASH D ]
Dec 13 20:35:04 HUB charon[1592]: 11[NET] sending packet: from 1.1.1.1[500] to 2.2.2.100[500] (76 bytes)
Dec 13 20:36:53 HUB charon[1592]: 14[KNL] creating delete job for CHILD_SA ESP/0xc265746f/3.3.3.100
Dec 13 20:36:53 HUB charon[1592]: 14[IKE] closing expired CHILD_SA dmvpn{4} with SPIs cec83b87_i c265746f_o and TS 1.1.1.1/32[gre] === 3.3.3.100/32[gre]
Dec 13 20:36:53 HUB charon[1592]: 14[IKE] sending DELETE for ESP CHILD_SA with SPI cec83b87
Dec 13 20:36:53 HUB charon[1592]: 14[ENC] generating INFORMATIONAL_V1 request 1784278580 [ HASH D ]
Dec 13 20:36:53 HUB charon[1592]: 14[NET] sending packet: from 1.1.1.1[500] to 3.3.3.100[500] (76 bytes)
Dec 13 20:36:53 HUB charon[1592]: 16[KNL] creating delete job for CHILD_SA ESP/0xcec83b87/1.1.1.1
Dec 13 20:36:53 HUB charon[1592]: 16[JOB] CHILD_SA ESP/0xcec83b87/1.1.1.1 not found for delete
Dec 13 20:36:53 HUB charon[1592]: 05[NET] received packet: from 3.3.3.100[500] to 1.1.1.1[500] (76 bytes)
Dec 13 20:36:53 HUB charon[1592]: 05[ENC] parsed INFORMATIONAL_V1 request 2420502710 [ HASH D ]
Dec 13 20:36:53 HUB charon[1592]: 05[IKE] received DELETE for ESP CHILD_SA with SPI c265746f
Dec 13 20:36:53 HUB charon[1592]: 05[IKE] CHILD_SA not found, ignored
Dec 13 20:37:35 HUB charon[1592]: 06[NET] received packet: from 2.2.2.100[500] to 1.1.1.1[500] (216 bytes)
Dec 13 20:37:35 HUB charon[1592]: 06[ENC] parsed ID_PROT request 0 [ SA V V V V V ]
Dec 13 20:37:35 HUB charon[1592]: 08[NET] received packet: from 3.3.3.100[500] to 1.1.1.1[500] (216 bytes)
Dec 13 20:37:35 HUB charon[1592]: 08[ENC] parsed ID_PROT request 0 [ SA V V V V V ]
Dec 13 20:37:35 HUB charon[1592]: 08[IKE] received XAuth vendor ID
Dec 13 20:37:35 HUB charon[1592]: 08[IKE] received DPD vendor ID
Dec 13 20:37:35 HUB charon[1592]: 08[IKE] received FRAGMENTATION vendor ID
Dec 13 20:37:35 HUB charon[1592]: 08[IKE] received NAT-T (RFC 3947) vendor ID
Dec 13 20:37:35 HUB charon[1592]: 08[IKE] received draft-ietf-ipsec-nat-t-ike-02\n vendor ID
Dec 13 20:37:35 HUB charon[1592]: 08[IKE] 3.3.3.100 is initiating a Main Mode IKE_SA
Dec 13 20:37:35 HUB charon[1592]: 08[ENC] generating ID_PROT response 0 [ SA V V V V ]
Dec 13 20:37:35 HUB charon[1592]: 08[NET] sending packet: from 1.1.1.1[500] to 3.3.3.100[500] (160 bytes)
Dec 13 20:37:35 HUB charon[1592]: 06[IKE] received XAuth vendor ID
Dec 13 20:37:35 HUB charon[1592]: 06[IKE] received DPD vendor ID
Dec 13 20:37:35 HUB charon[1592]: 06[IKE] received FRAGMENTATION vendor ID
Dec 13 20:37:35 HUB charon[1592]: 06[IKE] received NAT-T (RFC 3947) vendor ID
Dec 13 20:37:35 HUB charon[1592]: 06[IKE] received draft-ietf-ipsec-nat-t-ike-02\n vendor ID
Dec 13 20:37:35 HUB charon[1592]: 06[IKE] 2.2.2.100 is initiating a Main Mode IKE_SA
Dec 13 20:37:35 HUB charon[1592]: 06[ENC] generating ID_PROT response 0 [ SA V V V V ]
Dec 13 20:37:35 HUB charon[1592]: 06[NET] sending packet: from 1.1.1.1[500] to 2.2.2.100[500] (160 bytes)
Dec 13 20:37:35 HUB charon[1592]: 07[NET] received packet: from 3.3.3.100[500] to 1.1.1.1[500] (244 bytes)
Dec 13 20:37:35 HUB charon[1592]: 07[ENC] parsed ID_PROT request 0 [ KE No NAT-D NAT-D ]
Dec 13 20:37:35 HUB charon[1592]: 10[NET] received packet: from 2.2.2.100[500] to 1.1.1.1[500] (244 bytes)
Dec 13 20:37:35 HUB charon[1592]: 10[ENC] parsed ID_PROT request 0 [ KE No NAT-D NAT-D ]
Dec 13 20:37:35 HUB charon[1592]: 07[ENC] generating ID_PROT response 0 [ KE No NAT-D NAT-D ]
Dec 13 20:37:35 HUB charon[1592]: 07[NET] sending packet: from 1.1.1.1[500] to 3.3.3.100[500] (244 bytes)
Dec 13 20:37:35 HUB charon[1592]: 10[ENC] generating ID_PROT response 0 [ KE No NAT-D NAT-D ]
Dec 13 20:37:35 HUB charon[1592]: 10[NET] sending packet: from 1.1.1.1[500] to 2.2.2.100[500] (244 bytes)
Dec 13 20:37:35 HUB charon[1592]: 09[NET] received packet: from 3.3.3.100[500] to 1.1.1.1[500] (76 bytes)
Dec 13 20:37:35 HUB charon[1592]: 09[ENC] parsed ID_PROT request 0 [ ID HASH ]
Dec 13 20:37:35 HUB charon[1592]: 09[CFG] looking for pre-shared key peer configs matching 1.1.1.1...3.3.3.100[3.3.3.100]
Dec 13 20:37:35 HUB charon[1592]: 09[CFG] selected peer config "vpnprof-dmvpn-tun0"
Dec 13 20:37:35 HUB charon[1592]: 09[IKE] IKE_SA vpnprof-dmvpn-tun0[4] established between 1.1.1.1[1.1.1.1]...3.3.3.100[3.3.3.100]
Dec 13 20:37:35 HUB charon[1592]: 09[IKE] scheduling rekeying in 3550s
Dec 13 20:37:35 HUB charon[1592]: 09[IKE] maximum IKE_SA lifetime 3910s
Dec 13 20:37:35 HUB charon[1592]: 09[ENC] generating ID_PROT response 0 [ ID HASH ]
Dec 13 20:37:35 HUB charon[1592]: 09[NET] sending packet: from 1.1.1.1[500] to 3.3.3.100[500] (76 bytes)
Dec 13 20:37:35 HUB charon[1592]: 09[IKE] detected reauth of existing IKE_SA, adopting 1 children and 0 virtual IPs
Dec 13 20:37:35 HUB charon[1592]: 12[NET] received packet: from 2.2.2.100[500] to 1.1.1.1[500] (76 bytes)
Dec 13 20:37:35 HUB charon[1592]: 12[ENC] parsed ID_PROT request 0 [ ID HASH ]
Dec 13 20:37:35 HUB charon[1592]: 12[CFG] looking for pre-shared key peer configs matching 1.1.1.1...2.2.2.100[2.2.2.100]
Dec 13 20:37:35 HUB charon[1592]: 12[CFG] selected peer config "vpnprof-dmvpn-tun0"
Dec 13 20:37:35 HUB charon[1592]: 12[IKE] IKE_SA vpnprof-dmvpn-tun0[3] established between 1.1.1.1[1.1.1.1]...2.2.2.100[2.2.2.100]
Dec 13 20:37:35 HUB charon[1592]: 12[IKE] scheduling rekeying in 3466s
Dec 13 20:37:35 HUB charon[1592]: 12[IKE] maximum IKE_SA lifetime 3826s
Dec 13 20:37:35 HUB charon[1592]: 12[ENC] generating ID_PROT response 0 [ ID HASH ]
Dec 13 20:37:35 HUB charon[1592]: 12[NET] sending packet: from 1.1.1.1[500] to 2.2.2.100[500] (76 bytes)
Dec 13 20:37:35 HUB charon[1592]: 13[IKE] detected reauth of existing IKE_SA, adopting 1 children and 0 virtual IPs
Dec 13 20:37:45 HUB charon[1592]: 16[IKE] deleting IKE_SA vpnprof-dmvpn-tun0[2] between 1.1.1.1[1.1.1.1]...3.3.3.100[3.3.3.100]
Dec 13 20:37:45 HUB charon[1592]: 16[IKE] sending DELETE for IKE_SA vpnprof-dmvpn-tun0[2]
Dec 13 20:37:45 HUB charon[1592]: 16[ENC] generating INFORMATIONAL_V1 request 2295421205 [ HASH D ]
Dec 13 20:37:45 HUB charon[1592]: 16[NET] sending packet: from 1.1.1.1[500] to 3.3.3.100[500] (92 bytes)
Dec 13 20:37:45 HUB charon[1592]: 15[IKE] deleting IKE_SA vpnprof-dmvpn-tun0[1] between 1.1.1.1[1.1.1.1]...2.2.2.100[2.2.2.100]
Dec 13 20:37:45 HUB charon[1592]: 15[IKE] sending DELETE for IKE_SA vpnprof-dmvpn-tun0[1]
Dec 13 20:37:45 HUB charon[1592]: 15[ENC] generating INFORMATIONAL_V1 request 570999357 [ HASH D ]
Dec 13 20:37:45 HUB charon[1592]: 15[NET] sending packet: from 1.1.1.1[500] to 2.2.2.100[500] (92 bytes)
Dec 13 20:41:18 HUB charon[1592]: 07[NET] received packet: from 2.2.2.100[500] to 1.1.1.1[500] (76 bytes)
Dec 13 20:41:18 HUB charon[1592]: 07[ENC] parsed INFORMATIONAL_V1 request 2118346251 [ HASH D ]
Dec 13 20:41:18 HUB charon[1592]: 07[IKE] received DELETE for ESP CHILD_SA with SPI c8050767
Dec 13 20:41:18 HUB charon[1592]: 07[IKE] closing CHILD_SA dmvpn{5} with SPIs cb511dd6_i (624 bytes) c8050767_o (586 bytes) and TS 1.1.1.1/32[gre] === 2.2.2.100/32[gre]
Dec 13 20:41:18 HUB charon[1592]: 07[NET] received packet: from 2.2.2.100[500] to 1.1.1.1[500] (92 bytes)
Dec 13 20:41:18 HUB charon[1592]: 07[ENC] parsed INFORMATIONAL_V1 request 2880919864 [ HASH D ]
Dec 13 20:41:18 HUB charon[1592]: 07[IKE] received DELETE for IKE_SA vpnprof-dmvpn-tun0[3]
Dec 13 20:41:18 HUB charon[1592]: 07[IKE] deleting IKE_SA vpnprof-dmvpn-tun0[3] between 1.1.1.1[1.1.1.1]...2.2.2.100[2.2.2.100]
Dec 13 20:41:18 HUB charon[1592]: 09[NET] received packet: from 3.3.3.100[500] to 1.1.1.1[500] (76 bytes)
Dec 13 20:41:18 HUB charon[1592]: 09[ENC] parsed INFORMATIONAL_V1 request 1537196675 [ HASH D ]
Dec 13 20:41:18 HUB charon[1592]: 09[IKE] received DELETE for ESP CHILD_SA with SPI c9393fa5
Dec 13 20:41:18 HUB charon[1592]: 09[IKE] closing CHILD_SA dmvpn{6} with SPIs cb7b33e7_i (624 bytes) c9393fa5_o (586 bytes) and TS 1.1.1.1/32[gre] === 3.3.3.100/32[gre]
Dec 13 20:41:18 HUB charon[1592]: 11[NET] received packet: from 3.3.3.100[500] to 1.1.1.1[500] (92 bytes)
Dec 13 20:41:18 HUB charon[1592]: 11[ENC] parsed INFORMATIONAL_V1 request 3489084340 [ HASH D ]
Dec 13 20:41:18 HUB charon[1592]: 11[IKE] received DELETE for IKE_SA vpnprof-dmvpn-tun0[4]
Dec 13 20:41:18 HUB charon[1592]: 11[IKE] deleting IKE_SA vpnprof-dmvpn-tun0[4] between 1.1.1.1[1.1.1.1]...3.3.3.100[3.3.3.100]

The configuration of SPOKE1, SPOKE2 and HUB is identical to the DMVPN example in the wiki of Vyos. What could be the problem? Does it need another configuration with 1.2.0 rc10?

3

Hi!

There is actually a known error in the strongswan implementations that makes encryption fail when running dmvpn. Take a look at ⚓ T1070 SWANCTL: DMVPN: ALL peers are deleted in swan when opennhrp tries to delete ONE peer . I’ve been looking into the strongswan code behind this but have not found the trigger for what makes it happen…

4

Hi, okay. Thanks for that information. During the search I had not found the entry in the development portal.

5

Hi VyOS Maintainers

I just found this problem in VyOS 1.4; still, so I searched the forum and found this paper…

May I know is there a workaround on this security issue? Thanks!