Issue #2724
strongswan ipsec fails to finish connection (hangs after installing DNS server via resolvconf)
Affected version:
5.6.2
Resolution:
No change required
Description
From downstream Ubuntu bug tracker: https://bugs.launchpad.net/ubuntu/+source/strongswan/+bug/1786261
Used to work fine in Ubuntu 16.04 LTS, and Ubuntu 17.10. (I'm not sure which strongswan versions existed there - but also it could be a compatibility issue with some other package too...)
Currently installed package in Ubuntu 18.04:
ii strongswan 5.6.2-1ubuntu2 all IPsec VPN solution metapackage
A while ago I upgrade to 18.04 LTS and had consistent issues with strongswan ipsec connectivity VPN.
sudo ipsec up <CONNECTION_NAME> ... all the goods happen ... but near the end: IKE_SA <CONNECTION_NAME>[1] established between 1.0.0.6[<USER_SNIPPED>]...64.7.137.180[OU=Domain Control Validated, CN=<SNIPPED_HOST>.com] scheduling reauthentication in 56358s maximum IKE_SA lifetime 56538s installing DNS server 192.168.194.20 via resolvconf installing DNS server 192.168.196.20 via resolvconf <<HANGS FOREVER>>
while in this state, we see:
sudo ipsec statusall
Status of IKE charon daemon (strongSwan 5.6.2, Linux 4.15.0-29-generic, x86_64):
uptime: 6 minutes, since Aug 09 10:03:04 2018
malloc: sbrk 3403776, mmap 532480, used 1301456, free 2102320
worker threads: 11 of 16 idle, 5/0/0/0 working, job queue: 0/0/0/0, scheduled: 0
loaded plugins: charon test-vectors unbound ldap pkcs11 tpm aesni aes rc2 sha2 sha1 md4 md5 mgf1 random nonce x509 revocation constraints acert pubkey pkcs1 pkcs7 pkcs8 pkcs12 pgp dnskey sshkey dnscert ipseckey pem openssl gcrypt af-alg fips-prf gmp curve25519 agent chapoly xcbc cmac hmac ctr ccm gcm ntru bliss curl soup mysql sqlite attr kernel-netlink resolve socket-default connmark farp stroke vici updown eap-identity eap-sim eap-sim-pcsc eap-aka eap-aka-3gpp2 eap-simaka-pseudonym eap-simaka-reauth eap-md5 eap-gtc eap-mschapv2 eap-dynamic eap-radius eap-tls eap-ttls eap-peap eap-tnc xauth-generic xauth-eap xauth-pam xauth-noauth tnc-tnccs tnccs-20 tnccs-11 tnccs-dynamic dhcp whitelist lookip error-notify certexpire led radattr addrblock unity counters
Listening IP addresses:
1.0.0.6
192.168.130.9
192.168.140.17
192.168.130.14
192.168.140.2
192.168.130.13
192.168.130.15
192.168.130.16
192.168.130.8
172.17.0.1
192.168.122.1
Connections:
<SITE_SNIPPED>primary: %any...<SITE_SNIPPED>primary.<SNIPPED>.com IKEv2, dpddelay=30s
<SITE_SNIPPED>primary: local: [<USER_SNIPPED>] uses EAP_MSCHAPV2 authentication
<SITE_SNIPPED>primary: remote: [OU=Domain Control Validated, CN=<SNIPPED>.com] uses public key authentication
<SITE_SNIPPED>primary: child: 192.168.140.0/24 === 192.168.128.0/17 10.0.0.0/8 172.16.0.0/12 TUNNEL, dpdaction=clear
<SITE_SNIPPED>secondary: %any...<SITE_SNIPPED>secondary.<SNIPPED>.com IKEv2, dpddelay=30s
<SITE_SNIPPED>secondary: local: [<USER_SNIPPED>] uses EAP_MSCHAPV2 authentication
<SITE_SNIPPED>secondary: remote: [OU=Domain Control Validated, CN=<SNIPPED>.com] uses public key authentication
<SITE_SNIPPED>secondary: child: 192.168.130.0/24 === 192.168.128.0/17 10.0.0.0/8 172.16.0.0/12 TUNNEL, dpdaction=clear
Routed Connections:
<SITE_SNIPPED>secondary{2}: ROUTED, TUNNEL, reqid 2
<SITE_SNIPPED>secondary{2}: 192.168.130.0/24 === 10.0.0.0/8 172.16.0.0/12 192.168.128.0/17
<SITE_SNIPPED>primary{1}: ROUTED, TUNNEL, reqid 1
<SITE_SNIPPED>primary{1}: 192.168.140.0/24 === 10.0.0.0/8 172.16.0.0/12 192.168.128.0/17
Security Associations (0 up, 0 connecting):
none
here are the logs (post-restart of strongswan service)
journalctl --system -u strongswan
Aug 09 10:03:05 <HOSTNAME_SNIPPED> systemd[1]: Started strongSwan IPsec IKEv1/IKEv2 daemon using ipsec.conf. Aug 09 10:03:05 <HOSTNAME_SNIPPED> ipsec[10448]: Starting strongSwan 5.6.2 IPsec [starter]... Aug 09 10:03:05 <HOSTNAME_SNIPPED> ipsec_starter[10448]: Starting strongSwan 5.6.2 IPsec [starter]... Aug 09 10:03:05 <HOSTNAME_SNIPPED> charon[10474]: 00[DMN] Starting IKE charon daemon (strongSwan 5.6.2, Linux 4.15.0-29-generic, x86_64) Aug 09 10:03:05 <HOSTNAME_SNIPPED> charon[10474]: 00[CFG] PKCS11 module '<name>' lacks library path Aug 09 10:03:05 <HOSTNAME_SNIPPED> charon[10474]: 00[CFG] disabling load-tester plugin, not configured Aug 09 10:03:05 <HOSTNAME_SNIPPED> charon[10474]: 00[LIB] plugin 'load-tester': failed to load - load_tester_plugin_create returned NULL Aug 09 10:03:05 <HOSTNAME_SNIPPED> charon[10474]: 00[KNL] unable to create IPv4 routing table rule Aug 09 10:03:05 <HOSTNAME_SNIPPED> charon[10474]: 00[KNL] unable to create IPv6 routing table rule Aug 09 10:03:05 <HOSTNAME_SNIPPED> charon[10474]: 00[CFG] dnscert plugin is disabled Aug 09 10:03:05 <HOSTNAME_SNIPPED> charon[10474]: 00[CFG] ipseckey plugin is disabled Aug 09 10:03:05 <HOSTNAME_SNIPPED> charon[10474]: 00[CFG] attr-sql plugin: database URI not set Aug 09 10:03:05 <HOSTNAME_SNIPPED> charon[10474]: 00[CFG] loading ca certificates from '/etc/ipsec.d/cacerts' Aug 09 10:03:05 <HOSTNAME_SNIPPED> charon[10474]: 00[CFG] loaded ca certificate "C=US, ST=Arizona, L=Scottsdale, O=GoDaddy.com, Inc., CN=Go Daddy Root Certificate Authority - G2" from '/etc/ipsec.d/cacerts/<SNIPPED>-wildca Aug 09 10:03:05 <HOSTNAME_SNIPPED> charon[10474]: 00[CFG] loading aa certificates from '/etc/ipsec.d/aacerts' Aug 09 10:03:05 <HOSTNAME_SNIPPED> charon[10474]: 00[CFG] loading ocsp signer certificates from '/etc/ipsec.d/ocspcerts' Aug 09 10:03:05 <HOSTNAME_SNIPPED> charon[10474]: 00[CFG] loading attribute certificates from '/etc/ipsec.d/acerts' Aug 09 10:03:05 <HOSTNAME_SNIPPED> charon[10474]: 00[CFG] loading crls from '/etc/ipsec.d/crls' Aug 09 10:03:05 <HOSTNAME_SNIPPED> charon[10474]: 00[CFG] loading secrets from '/etc/ipsec.secrets' Aug 09 10:03:05 <HOSTNAME_SNIPPED> charon[10474]: 00[CFG] loaded EAP secret for <USER_SNIPPED> Aug 09 10:03:05 <HOSTNAME_SNIPPED> charon[10474]: 00[CFG] sql plugin: database URI not set Aug 09 10:03:05 <HOSTNAME_SNIPPED> charon[10474]: 00[CFG] opening triplet file /etc/ipsec.d/triplets.dat failed: No such file or directory Aug 09 10:03:05 <HOSTNAME_SNIPPED> charon[10474]: 00[CFG] eap-simaka-sql database URI missing Aug 09 10:03:05 <HOSTNAME_SNIPPED> charon[10474]: 00[CFG] loaded 0 RADIUS server configurations Aug 09 10:03:05 <HOSTNAME_SNIPPED> charon[10474]: 00[CFG] HA config misses local/remote address Aug 09 10:03:05 <HOSTNAME_SNIPPED> charon[10474]: 00[CFG] no threshold configured for systime-fix, disabled Aug 09 10:03:05 <HOSTNAME_SNIPPED> charon[10474]: 00[CFG] coupling file path unspecified Aug 09 10:03:05 <HOSTNAME_SNIPPED> charon[10474]: 00[LIB] loaded plugins: charon test-vectors unbound ldap pkcs11 tpm aesni aes rc2 sha2 sha1 md4 md5 mgf1 random nonce x509 revocation constraints acert pubkey pkcs1 pkcs7 pk Aug 09 10:03:05 <HOSTNAME_SNIPPED> charon[10474]: 00[LIB] dropped capabilities, running as uid 0, gid 0 Aug 09 10:03:05 <HOSTNAME_SNIPPED> charon[10474]: 00[JOB] spawning 16 worker threads Aug 09 10:03:05 <HOSTNAME_SNIPPED> ipsec[10448]: charon (10474) started after 40 ms Aug 09 10:03:05 <HOSTNAME_SNIPPED> ipsec_starter[10448]: charon (10474) started after 40 ms
---
and when I try to connect:
Aug 09 10:03:05 <HOSTNAME_SNIPPED> charon[10474]: 04[CFG] received stroke: add connection '<SITE_SNIPPED>primary' Aug 09 10:03:15 <HOSTNAME_SNIPPED> charon[10474]: 04[CFG] CA certificate "/etc/ipsec.d/cacerts/<SNIPPED>-wildcard.pem" not found, discarding CA constraint Aug 09 10:03:15 <HOSTNAME_SNIPPED> charon[10474]: 04[CFG] added configuration '<SITE_SNIPPED>primary' Aug 09 10:03:15 <HOSTNAME_SNIPPED> charon[10474]: 07[CFG] received stroke: route '<SITE_SNIPPED>primary' Aug 09 10:03:20 <HOSTNAME_SNIPPED> charon[10474]: 07[KNL] policy already exists, try to update it Aug 09 10:03:20 <HOSTNAME_SNIPPED> charon[10474]: 07[KNL] policy already exists, try to update it Aug 09 10:03:20 <HOSTNAME_SNIPPED> charon[10474]: 07[KNL] policy already exists, try to update it Aug 09 10:03:20 <HOSTNAME_SNIPPED> ipsec[10448]: '<SITE_SNIPPED>primary' routed Aug 09 10:03:20 <HOSTNAME_SNIPPED> charon[10474]: 07[KNL] policy already exists, try to update it Aug 09 10:03:20 <HOSTNAME_SNIPPED> charon[10474]: 07[KNL] policy already exists, try to update it Aug 09 10:03:20 <HOSTNAME_SNIPPED> charon[10474]: 07[KNL] policy already exists, try to update it Aug 09 10:03:20 <HOSTNAME_SNIPPED> charon[10474]: 07[KNL] policy already exists, try to update it Aug 09 10:03:20 <HOSTNAME_SNIPPED> charon[10474]: 07[KNL] policy already exists, try to update it Aug 09 10:03:20 <HOSTNAME_SNIPPED> charon[10474]: 07[KNL] policy already exists, try to update it Aug 09 10:03:20 <HOSTNAME_SNIPPED> ipsec_starter[10448]: '<SITE_SNIPPED>primary' routed Aug 09 10:03:20 <HOSTNAME_SNIPPED> ipsec_starter[10448]: Aug 09 10:03:20 <HOSTNAME_SNIPPED> charon[10474]: 12[CFG] received stroke: add connection '<SITE_SNIPPED>secondary' Aug 09 10:03:25 <HOSTNAME_SNIPPED> charon[10474]: 12[CFG] CA certificate "/etc/ipsec.d/cacerts/<SNIPPED>-wildcard.pem" not found, discarding CA constraint Aug 09 10:03:25 <HOSTNAME_SNIPPED> charon[10474]: 12[CFG] added configuration '<SITE_SNIPPED>secondary' Aug 09 10:03:25 <HOSTNAME_SNIPPED> charon[10474]: 14[CFG] received stroke: route '<SITE_SNIPPED>secondary' Aug 09 10:03:30 <HOSTNAME_SNIPPED> charon[10474]: 14[KNL] policy already exists, try to update it Aug 09 10:03:30 <HOSTNAME_SNIPPED> charon[10474]: 14[KNL] policy already exists, try to update it Aug 09 10:03:30 <HOSTNAME_SNIPPED> ipsec[10448]: '<SITE_SNIPPED>secondary' routed Aug 09 10:03:30 <HOSTNAME_SNIPPED> charon[10474]: 14[KNL] policy already exists, try to update it Aug 09 10:03:30 <HOSTNAME_SNIPPED> charon[10474]: 14[KNL] policy already exists, try to update it Aug 09 10:03:30 <HOSTNAME_SNIPPED> charon[10474]: 14[KNL] policy already exists, try to update it Aug 09 10:03:30 <HOSTNAME_SNIPPED> charon[10474]: 14[KNL] policy already exists, try to update it Aug 09 10:03:30 <HOSTNAME_SNIPPED> charon[10474]: 14[KNL] policy already exists, try to update it Aug 09 10:03:30 <HOSTNAME_SNIPPED> charon[10474]: 14[KNL] policy already exists, try to update it Aug 09 10:03:30 <HOSTNAME_SNIPPED> charon[10474]: 14[KNL] policy already exists, try to update it Aug 09 10:03:30 <HOSTNAME_SNIPPED> ipsec_starter[10448]: '<SITE_SNIPPED>secondary' routed Aug 09 10:03:30 <HOSTNAME_SNIPPED> ipsec_starter[10448]: <<NOTHING ELSE>> HUNG
For reference (which may be relevant), the configuration is:
$ cat /etc/ipsec.conf
# ipsec.conf - strongSwan IPsec configuration file
version 2.0
config setup
charondebug="dmn 1,mgr 1,ike 2,chd 1,job 1,cfg 1,knl 1,net 1,tls 1,lib 1,enc 1,tnc 1"
conn %default
ikelifetime = 56600s
keylife = 43200s
rekeymargin = 3m
keyingtries = 1
keyexchange = ikev2
fragmentation = yes
ike = aes256-sha256-modp1024
esp = aes256-sha256-modp1536!
mobike = yes
forceencaps = yes
conn <SITE_SNIPPED>primary
auto = route
compress = no
dpdaction = clear
type = tunnel
leftsourceip = %config
leftdns = 192.168.194.20,192.168.196.20
leftsubnet = 192.168.140.0/24
leftfirewall = no
leftauth = eap-mschapv2
leftid = "<USER_SNIPPED>"
right = <SITE_SNIPPED>primary.<SNIPPED>.com
rightid = "OU=Domain Control Validated, CN=<SNIPPED>.com"
rightauth = pubkey
rightca = /etc/ipsec.d/cacerts/<SNIPPED>-wildcard.pem
rightsubnet = 192.168.128.0/17,10.0.0.0/8,172.16.0.0/12
aaa_identity = "OU=Domain Control Validated, CN=<SNIPPED>.com"
--
COMPARE to the success case (post-fresh-reboot)
sudo ipsec up <CONNECTION_NAME>
... all the goods happen ...
but near the end:
IKE_SA <CONNECTION_NAME>[1] established between 1.0.0.6[<USER_SNIPPED>]...64.7.137.180[OU=Domain Control Validated, CN=<SNIPPED_HOST>.com]
scheduling reauthentication in 56358s
maximum IKE_SA lifetime 56538s
installing DNS server 192.168.194.20 via resolvconf
installing DNS server 192.168.196.20 via resolvconf
<<DOES NOT HANG HERE>>
installing new virtual IP 192.168.130.12
CHILD_SA <SITE_SNIPPED>{3} established with SPIs c01ade25_i 9ae55d41_o and TS 192.168.130.12/32 === 10.0.0.0/8 172.16.0.0/12 192.168.128.0/17
connection '<SITE_SNIPPED>' established successfully
and the logs ... this is AFTER the above snippet where it hangs ... see how it continues on!
Aug 10 07:58:58 <HOSTNAME_SNIPPED> charon[32489]: 09[CFG] received stroke: initiate '<SITE_SNIPPED>secondary' Aug 10 07:58:58 <HOSTNAME_SNIPPED> charon[32489]: 06[IKE] queueing IKE_VENDOR task Aug 10 07:58:58 <HOSTNAME_SNIPPED> charon[32489]: 06[IKE] queueing IKE_INIT task Aug 10 07:58:58 <HOSTNAME_SNIPPED> charon[32489]: 06[IKE] queueing IKE_NATD task Aug 10 07:58:58 <HOSTNAME_SNIPPED> charon[32489]: 06[IKE] queueing IKE_CERT_PRE task Aug 10 07:58:58 <HOSTNAME_SNIPPED> charon[32489]: 06[IKE] queueing IKE_AUTH task Aug 10 07:58:58 <HOSTNAME_SNIPPED> charon[32489]: 06[IKE] queueing IKE_CERT_POST task Aug 10 07:58:58 <HOSTNAME_SNIPPED> charon[32489]: 06[IKE] queueing IKE_CONFIG task Aug 10 07:58:58 <HOSTNAME_SNIPPED> charon[32489]: 06[IKE] queueing IKE_AUTH_LIFETIME task Aug 10 07:58:58 <HOSTNAME_SNIPPED> charon[32489]: 06[IKE] queueing IKE_MOBIKE task Aug 10 07:58:58 <HOSTNAME_SNIPPED> charon[32489]: 06[IKE] queueing IKE_ME task Aug 10 07:58:58 <HOSTNAME_SNIPPED> charon[32489]: 06[IKE] queueing CHILD_CREATE task Aug 10 07:58:58 <HOSTNAME_SNIPPED> charon[32489]: 06[IKE] activating new tasks Aug 10 07:58:58 <HOSTNAME_SNIPPED> charon[32489]: 06[IKE] activating IKE_VENDOR task Aug 10 07:58:58 <HOSTNAME_SNIPPED> charon[32489]: 06[IKE] activating IKE_INIT task Aug 10 07:58:58 <HOSTNAME_SNIPPED> charon[32489]: 06[IKE] activating IKE_NATD task Aug 10 07:58:58 <HOSTNAME_SNIPPED> charon[32489]: 06[IKE] activating IKE_CERT_PRE task Aug 10 07:58:58 <HOSTNAME_SNIPPED> charon[32489]: 06[IKE] activating IKE_ME task Aug 10 07:58:58 <HOSTNAME_SNIPPED> charon[32489]: 06[IKE] activating IKE_AUTH task Aug 10 07:58:58 <HOSTNAME_SNIPPED> charon[32489]: 06[IKE] activating IKE_CERT_POST task Aug 10 07:58:58 <HOSTNAME_SNIPPED> charon[32489]: 06[IKE] activating IKE_CONFIG task Aug 10 07:58:58 <HOSTNAME_SNIPPED> charon[32489]: 06[IKE] activating CHILD_CREATE task Aug 10 07:58:58 <HOSTNAME_SNIPPED> charon[32489]: 06[IKE] activating IKE_AUTH_LIFETIME task Aug 10 07:58:58 <HOSTNAME_SNIPPED> charon[32489]: 06[IKE] activating IKE_MOBIKE task Aug 10 07:58:58 <HOSTNAME_SNIPPED> charon[32489]: 06[IKE] initiating IKE_SA <SITE_SNIPPED>secondary[1] to 64.7.137.180 Aug 10 07:58:58 <HOSTNAME_SNIPPED> charon[32489]: 06[IKE] initiating IKE_SA <SITE_SNIPPED>secondary[1] to 64.7.137.180 Aug 10 07:58:58 <HOSTNAME_SNIPPED> charon[32489]: 06[IKE] IKE_SA <SITE_SNIPPED>secondary[1] state change: CREATED => CONNECTING Aug 10 07:58:58 <HOSTNAME_SNIPPED> charon[32489]: 06[ENC] generating IKE_SA_INIT request 0 [ SA KE No N(NATD_S_IP) N(NATD_D_IP) N(FRAG_SUP) N(HASH_ALG) N(REDIR_SUP) Aug 10 07:58:58 <HOSTNAME_SNIPPED> charon[32489]: 06[NET] sending packet: from 1.0.0.6[500] to 64.7.137.180[500] (1224 bytes) Aug 10 07:58:58 <HOSTNAME_SNIPPED> charon[32489]: 08[NET] received packet: from 64.7.137.180[500] to 1.0.0.6[500] (288 bytes) Aug 10 07:58:58 <HOSTNAME_SNIPPED> charon[32489]: 08[ENC] parsed IKE_SA_INIT response 0 [ SA KE No N(NATD_S_IP) N(NATD_D_IP) ] Aug 10 07:58:58 <HOSTNAME_SNIPPED> charon[32489]: 08[IKE] local host is behind NAT, sending keep alives Aug 10 07:58:58 <HOSTNAME_SNIPPED> charon[32489]: 08[IKE] reinitiating already active tasks Aug 10 07:58:58 <HOSTNAME_SNIPPED> ipsec[32464]: 00[DMN] Starting IKE charon daemon (strongSwan 5.6.2, Linux 4.15.0-29-generic, x86_64) Aug 10 07:58:58 <HOSTNAME_SNIPPED> ipsec[32464]: 00[CFG] PKCS11 module '<name>' lacks library path Aug 10 07:58:58 <HOSTNAME_SNIPPED> ipsec[32464]: 00[CFG] disabling load-tester plugin, not configured Aug 10 07:58:58 <HOSTNAME_SNIPPED> ipsec[32464]: 00[LIB] plugin 'load-tester': failed to load - load_tester_plugin_create returned NULL Aug 10 07:58:58 <HOSTNAME_SNIPPED> ipsec[32464]: 00[CFG] dnscert plugin is disabled Aug 10 07:58:58 <HOSTNAME_SNIPPED> ipsec[32464]: 00[CFG] ipseckey plugin is disabled Aug 10 07:58:58 <HOSTNAME_SNIPPED> ipsec[32464]: 00[CFG] attr-sql plugin: database URI not set Aug 10 07:58:58 <HOSTNAME_SNIPPED> ipsec[32464]: 00[CFG] loading ca certificates from '/etc/ipsec.d/cacerts' Aug 10 07:58:58 <HOSTNAME_SNIPPED> ipsec[32464]: 00[CFG] loaded ca certificate "C=US, ST=Arizona, L=Scottsdale, O=GoDaddy.com, Inc., CN=Go Daddy Root Certificate A Aug 10 07:58:58 <HOSTNAME_SNIPPED> ipsec[32464]: 00[CFG] loading aa certificates from '/etc/ipsec.d/aacerts' Aug 10 07:58:58 <HOSTNAME_SNIPPED> ipsec[32464]: 00[CFG] loading ocsp signer certificates from '/etc/ipsec.d/ocspcerts' Aug 10 07:58:58 <HOSTNAME_SNIPPED> ipsec[32464]: 00[CFG] loading attribute certificates from '/etc/ipsec.d/acerts' Aug 10 07:58:58 <HOSTNAME_SNIPPED> ipsec[32464]: 00[CFG] loading crls from '/etc/ipsec.d/crls' Aug 10 07:58:58 <HOSTNAME_SNIPPED> ipsec[32464]: 00[CFG] loading secrets from '/etc/ipsec.secrets' Aug 10 07:58:58 <HOSTNAME_SNIPPED> ipsec[32464]: 00[CFG] loaded EAP secret for <USER_SNIPPED> Aug 10 07:58:58 <HOSTNAME_SNIPPED> ipsec[32464]: 00[CFG] sql plugin: database URI not set Aug 10 07:58:58 <HOSTNAME_SNIPPED> ipsec[32464]: 00[CFG] opening triplet file /etc/ipsec.d/triplets.dat failed: No such file or directory Aug 10 07:58:58 <HOSTNAME_SNIPPED> ipsec[32464]: 00[CFG] eap-simaka-sql database URI missing Aug 10 07:58:58 <HOSTNAME_SNIPPED> ipsec[32464]: 00[CFG] loaded 0 RADIUS server configurations Aug 10 07:58:58 <HOSTNAME_SNIPPED> ipsec[32464]: 00[CFG] HA config misses local/remote address Aug 10 07:58:58 <HOSTNAME_SNIPPED> ipsec[32464]: 00[CFG] no threshold configured for systime-fix, disabled Aug 10 07:58:58 <HOSTNAME_SNIPPED> ipsec[32464]: 00[CFG] coupling file path unspecified Aug 10 07:58:58 <HOSTNAME_SNIPPED> charon[32489]: 08[IKE] IKE_CERT_PRE task Aug 10 07:58:58 <HOSTNAME_SNIPPED> ipsec[32464]: 00[LIB] loaded plugins: charon test-vectors unbound ldap pkcs11 tpm aesni aes rc2 sha2 sha1 md4 md5 mgf1 random nonc Aug 10 07:58:58 <HOSTNAME_SNIPPED> ipsec[32464]: 00[LIB] dropped capabilities, running as uid 0, gid 0 Aug 10 07:58:58 <HOSTNAME_SNIPPED> ipsec[32464]: 00[JOB] spawning 16 worker threads Aug 10 07:58:58 <HOSTNAME_SNIPPED> ipsec[32464]: 06[CFG] received stroke: add connection '<SITE_SNIPPED>primary' Aug 10 07:58:58 <HOSTNAME_SNIPPED> ipsec[32464]: 06[CFG] CA certificate "/etc/ipsec.d/cacerts/<SNIPPED>-wildcard.pem" not found, discarding CA constraint Aug 10 07:58:58 <HOSTNAME_SNIPPED> ipsec[32464]: 06[CFG] added configuration '<SITE_SNIPPED>primary' Aug 10 07:58:58 <HOSTNAME_SNIPPED> ipsec[32464]: 07[CFG] received stroke: route '<SITE_SNIPPED>primary' Aug 10 07:58:58 <HOSTNAME_SNIPPED> ipsec[32464]: 10[CFG] received stroke: add connection '<SITE_SNIPPED>secondary' Aug 10 07:58:58 <HOSTNAME_SNIPPED> ipsec[32464]: 10[CFG] CA certificate "/etc/ipsec.d/cacerts/<SNIPPED>-wildcard.pem" not found, discarding CA constraint Aug 10 07:58:58 <HOSTNAME_SNIPPED> ipsec[32464]: 10[CFG] added configuration '<SITE_SNIPPED>secondary' Aug 10 07:58:58 <HOSTNAME_SNIPPED> ipsec[32464]: 13[CFG] received stroke: route '<SITE_SNIPPED>secondary' Aug 10 07:58:58 <HOSTNAME_SNIPPED> ipsec[32464]: 09[CFG] received stroke: initiate '<SITE_SNIPPED>secondary' .... etc. etc. ... (experts probably know what this looks like ;o)
History
#1 Updated by Ferm ulator about 7 years ago
based on the log differences, it looks like it fails to add a virtual IP eh
#2 Updated by Ferm ulator about 7 years ago
It's also worth noting. Probably teardown related. I just did something unusual to my standard workflows (to test https://bugs.launchpad.net/ubuntu/+source/strongswan/+bug/1786250), which was to teardown the connection, then reconnect it. The issue was reproduced.
#3 Updated by Tobias Brunner about 7 years ago
- Status changed from New to Feedback
The output of ipsec up won't show the complete picture, check the log.
and when I try to connect:
Nothing here shows the connection attempt, that's just the config getting loaded.
For reference (which may be relevant), the configuration is:
That's not the complete configuration (there apparently is a "secondary" config).
Also, you configure leftsourceip=%config yet you also configure leftsubnet. Usually, with virtual IPs leftsubnet is set to %dynamic (the default, i.e. not setting the value works too). You also configure auto=route, which was not really supported in combination with leftsourceip=%config in versions before 5.6.3 (see #85).
COMPARE to the success case (post-fresh-reboot)
So the connection is successful after a reboot? Only later attempts fail?
By the way, your logs are a mess (see HelpRequests for some sane config for debugging).
Aug 09 10:03:05 <HOSTNAME_SNIPPED> charon[10474]: 00[KNL] unable to create IPv4 routing table rule Aug 09 10:03:05 <HOSTNAME_SNIPPED> charon[10474]: 00[KNL] unable to create IPv6 routing table rule
This looks suspicious.
#4 Updated by Ferm ulator about 7 years ago
Thanks Tobias for the quick response!
For the configuration feedback, unfortunately I cannot speak much to it -- my company provided me with how to connect, that is what works for everyone. (and works fine for me on first connect fresh reboot -- and before Ubuntu 18.04 upgrade, worked 100% all the time -- and, that same configuration works on Linux Mint 18.X which runs 5.3.5)
for issue debug
--
OK starting over, trying to keep it chronological.
System is broken (at the moment) - unable to VPN.
1. restart strongswan
2. wait for statusall to show:
$ sudo ipsec statusall
Status of IKE charon daemon (strongSwan 5.6.2, Linux 4.15.0-29-generic, x86_64):
uptime: 65 seconds, since Aug 10 12:10:09 2018
malloc: sbrk 3538944, mmap 532480, used 1315856, free 2223088
worker threads: 11 of 16 idle, 5/0/0/0 working, job queue: 0/0/0/0, scheduled: 0
loaded plugins: charon test-vectors unbound ldap pkcs11 tpm aesni aes rc2 sha2 sha1 md4 md5 mgf1 random nonce x509 revocation constraints acert pubkey pkcs1 pkcs7 pkcs8 pkcs12 pgp dnskey sshkey dnscert ipseckey pem openssl gcrypt af-alg fips-prf gmp curve25519 agent chapoly xcbc cmac hmac ctr ccm gcm ntru bliss curl soup mysql sqlite attr kernel-netlink resolve socket-default connmark farp stroke vici updown eap-identity eap-sim eap-sim-pcsc eap-aka eap-aka-3gpp2 eap-simaka-pseudonym eap-simaka-reauth eap-md5 eap-gtc eap-mschapv2 eap-dynamic eap-radius eap-tls eap-ttls eap-peap eap-tnc xauth-generic xauth-eap xauth-pam xauth-noauth tnc-tnccs tnccs-20 tnccs-11 tnccs-dynamic dhcp whitelist lookip error-notify certexpire led radattr addrblock unity counters
Listening IP addresses:
1.0.0.6
192.168.140.2
192.168.140.4
192.168.130.9
172.17.0.1
192.168.122.1
Connections:
<SITE_SNIPPED>: %any...<SITE_SNIPPED>.<SNIPPED>.com IKEv2, dpddelay=30s
<SITE_SNIPPED>: local: [<USER_SNIPPED>] uses EAP_MSCHAPV2 authentication
<SITE_SNIPPED>: remote: [OU=Domain Control Validated, CN=<SNIPPED>.com] uses public key authentication
<SITE_SNIPPED>: child: 192.168.140.0/24 === 192.168.128.0/17 10.0.0.0/8 172.16.0.0/12 TUNNEL, dpdaction=clear
<SITE_SNIPPED>secondary: %any...<SITE_SNIPPED>secondary.<SNIPPED>.com IKEv2, dpddelay=30s
<SITE_SNIPPED>secondary: local: [<USER_SNIPPED>] uses EAP_MSCHAPV2 authentication
<SITE_SNIPPED>secondary: remote: [OU=Domain Control Validated, CN=<SNIPPED>.com] uses public key authentication
<SITE_SNIPPED>secondary: child: 192.168.130.0/24 === 192.168.128.0/17 10.0.0.0/8 172.16.0.0/12 TUNNEL, dpdaction=clear
Routed Connections:
<SITE_SNIPPED>secondary{2}: ROUTED, TUNNEL, reqid 2
<SITE_SNIPPED>secondary{2}: 192.168.130.0/24 === 10.0.0.0/8 172.16.0.0/12 192.168.128.0/17
<SITE_SNIPPED>{1}: ROUTED, TUNNEL, reqid 1
<SITE_SNIPPED>{1}: 192.168.140.0/24 === 10.0.0.0/8 172.16.0.0/12 192.168.128.0/17
Security Associations (0 up, 0 connecting):
none
You're right about the log mixups, sorry! Here's a better state:
just at this state, after restarting strongswan
Aug 10 12:10:35 fermmy ipsec_starter[13494]:
Issue connection up attempt:
sudo ipsec up <CONNECTION_NAME>
Following log with:
$ journalctl --system -u strongswan -ef
here we go:
Aug 10 12:13:24 <HOSTNAME_SNIPPED> charon[13522]: 10[CFG] received stroke: initiate '<SITE_SNIPPED>secondary'
Aug 10 12:13:24 <HOSTNAME_SNIPPED> charon[13522]: 07[IKE] queueing IKE_VENDOR task
Aug 10 12:13:24 <HOSTNAME_SNIPPED> charon[13522]: 07[IKE] queueing IKE_INIT task
Aug 10 12:13:24 <HOSTNAME_SNIPPED> ipsec[13494]: 00[DMN] Starting IKE charon daemon (strongSwan 5.6.2, Linux 4.15.0-29-generic, x86_64)
Aug 10 12:13:24 <HOSTNAME_SNIPPED> ipsec[13494]: 00[CFG] PKCS11 module '<name>' lacks library path
Aug 10 12:13:24 <HOSTNAME_SNIPPED> ipsec[13494]: 00[CFG] disabling load-tester plugin, not configured
Aug 10 12:13:24 <HOSTNAME_SNIPPED> ipsec[13494]: 00[LIB] plugin 'load-tester': failed to load - load_tester_plugin_create returned NULL
Aug 10 12:13:24 <HOSTNAME_SNIPPED> ipsec[13494]: 00[KNL] unable to create IPv4 routing table rule
Aug 10 12:13:24 <HOSTNAME_SNIPPED> ipsec[13494]: 00[KNL] unable to create IPv6 routing table rule
Aug 10 12:13:24 <HOSTNAME_SNIPPED> ipsec[13494]: 00[CFG] dnscert plugin is disabled
Aug 10 12:13:24 <HOSTNAME_SNIPPED> ipsec[13494]: 00[CFG] ipseckey plugin is disabled
Aug 10 12:13:24 <HOSTNAME_SNIPPED> ipsec[13494]: 00[CFG] attr-sql plugin: database URI not set
Aug 10 12:13:24 <HOSTNAME_SNIPPED> ipsec[13494]: 00[CFG] loading ca certificates from '/etc/ipsec.d/cacerts'
Aug 10 12:13:24 <HOSTNAME_SNIPPED> ipsec[13494]: 00[CFG] loaded ca certificate "C=US, ST=Arizona, L=Scottsdale, O=GoDaddy.com, Inc., CN=Go Daddy Root Certificate Authority - G2" from '/etc/ipsec.d/cacerts/<SNIPPED>-wildcard.pem'
Aug 10 12:13:24 <HOSTNAME_SNIPPED> ipsec[13494]: 00[CFG] loading aa certificates from '/etc/ipsec.d/aacerts'
Aug 10 12:13:24 <HOSTNAME_SNIPPED> ipsec[13494]: 00[CFG] loading ocsp signer certificates from '/etc/ipsec.d/ocspcerts'
Aug 10 12:13:24 <HOSTNAME_SNIPPED> ipsec[13494]: 00[CFG] loading attribute certificates from '/etc/ipsec.d/acerts'
Aug 10 12:13:24 <HOSTNAME_SNIPPED> ipsec[13494]: 00[CFG] loading crls from '/etc/ipsec.d/crls'
Aug 10 12:13:24 <HOSTNAME_SNIPPED> ipsec[13494]: 00[CFG] loading secrets from '/etc/ipsec.secrets'
Aug 10 12:13:24 <HOSTNAME_SNIPPED> ipsec[13494]: 00[CFG] loaded EAP secret for <USER_SNIPPED>
Aug 10 12:13:24 <HOSTNAME_SNIPPED> ipsec[13494]: 00[CFG] sql plugin: database URI not set
Aug 10 12:13:24 <HOSTNAME_SNIPPED> ipsec[13494]: 00[CFG] opening triplet file /etc/ipsec.d/triplets.dat failed: No such file or directory
Aug 10 12:13:24 <HOSTNAME_SNIPPED> ipsec[13494]: 00[CFG] eap-simaka-sql database URI missing
Aug 10 12:13:24 <HOSTNAME_SNIPPED> ipsec[13494]: 00[CFG] loaded 0 RADIUS server configurations
Aug 10 12:13:24 <HOSTNAME_SNIPPED> ipsec[13494]: 00[CFG] HA config misses local/remote address
Aug 10 12:13:24 <HOSTNAME_SNIPPED> ipsec[13494]: 00[CFG] no threshold configured for systime-fix, disabled
Aug 10 12:13:24 <HOSTNAME_SNIPPED> ipsec[13494]: 00[CFG] coupling file path unspecified
Aug 10 12:13:24 <HOSTNAME_SNIPPED> charon[13522]: 07[IKE] queueing IKE_NATD task
Aug 10 12:13:24 <HOSTNAME_SNIPPED> ipsec[13494]: 00[LIB] loaded plugins: charon test-vectors unbound ldap pkcs11 tpm aesni aes rc2 sha2 sha1 md4 md5 mgf1 random nonce x509 revocation constraints acert pubkey pkcs1 pkcs7 pkcs8 pkcs12 pgp dnskey sshkey dnscert ipseckey pem openssl gcrypt af-alg fips-prf gmp curve25519 agent chapoly xcbc cmac hmac ctr ccm gcm ntru bliss curl soup mysql sqlite attr kernel-netlink resolve socket-default connmark farp stroke vici updown eap-identity eap-sim eap-sim-pcsc eap-aka eap-aka-3gpp2 eap-simaka-pseudonym eap-simaka-reauth eap-md5 eap-gtc eap-mschapv2 eap-dynamic eap-radius eap-tls eap-ttls eap-peap eap-tnc xauth-generic xauth-eap xauth-pam xauth-noauth tnc-tnccs tnccs-20 tnccs-11 tnccs-dynamic dhcp whitelist lookip error-notify certexpire led radattr addrblock unity counters
Aug 10 12:13:24 <HOSTNAME_SNIPPED> ipsec[13494]: 00[LIB] dropped capabilities, running as uid 0, gid 0
Aug 10 12:13:24 <HOSTNAME_SNIPPED> ipsec[13494]: 00[JOB] spawning 16 worker threads
Aug 10 12:13:24 <HOSTNAME_SNIPPED> ipsec[13494]: 02[CFG] received stroke: add connection '<SITE_SNIPPED>primary'
Aug 10 12:13:24 <HOSTNAME_SNIPPED> ipsec[13494]: 02[CFG] CA certificate "/etc/ipsec.d/cacerts/<SNIPPED>-wildcard.pem" not found, discarding CA constraint
Aug 10 12:13:24 <HOSTNAME_SNIPPED> ipsec[13494]: 02[CFG] added configuration '<SITE_SNIPPED>primary'
Aug 10 12:13:24 <HOSTNAME_SNIPPED> ipsec[13494]: 15[CFG] received stroke: route '<SITE_SNIPPED>primary'
Aug 10 12:13:24 <HOSTNAME_SNIPPED> ipsec[13494]: 15[KNL] policy already exists, try to update it
Aug 10 12:13:24 <HOSTNAME_SNIPPED> ipsec[13494]: 08[CFG] received stroke: add connection '<SITE_SNIPPED>secondary'
Aug 10 12:13:24 <HOSTNAME_SNIPPED> ipsec[13494]: 08[CFG] CA certificate "/etc/ipsec.d/cacerts/<SNIPPED>-wildcard.pem" not found, discarding CA constraint
Aug 10 12:13:24 <HOSTNAME_SNIPPED> ipsec[13494]: 08[CFG] added configuration '<SITE_SNIPPED>secondary'
Aug 10 12:13:24 <HOSTNAME_SNIPPED> ipsec[13494]: 06[CFG] received stroke: route '<SITE_SNIPPED>secondary'
Aug 10 12:13:24 <HOSTNAME_SNIPPED> ipsec[13494]: 06[KNL] policy already exists, try to update it
Aug 10 12:13:24 <HOSTNAME_SNIPPED> charon[13522]: 07[IKE] queueing IKE_CERT_PRE task
Aug 10 12:13:24 <HOSTNAME_SNIPPED> ipsec[13494]: 06[KNL] policy already exists, try to update it
Aug 10 12:13:24 <HOSTNAME_SNIPPED> ipsec[13494]: 10[CFG] received stroke: initiate '<SITE_SNIPPED>secondary'
Aug 10 12:13:24 <HOSTNAME_SNIPPED> ipsec[13494]: 07[IKE] queueing IKE_VENDOR task
Aug 10 12:13:24 <HOSTNAME_SNIPPED> ipsec[13494]: 07[IKE] queueing IKE_INIT task
Aug 10 12:13:24 <HOSTNAME_SNIPPED> ipsec[13494]: 07[IKE] queueing IKE_NATD task
Aug 10 12:13:24 <HOSTNAME_SNIPPED> ipsec[13494]: 07[IKE] queueing IKE_CERT_PRE task
Aug 10 12:13:24 <HOSTNAME_SNIPPED> ipsec[13494]: 07[IKE] queueing IKE_AUTH task
Aug 10 12:13:24 <HOSTNAME_SNIPPED> ipsec[13494]: 07[IKE] queueing IKE_CERT_POST task
Aug 10 12:13:24 <HOSTNAME_SNIPPED> ipsec[13494]: 07[IKE] queueing IKE_CONFIG task
Aug 10 12:13:24 <HOSTNAME_SNIPPED> ipsec[13494]: 07[IKE] queueing IKE_AUTH_LIFETIME task
Aug 10 12:13:24 <HOSTNAME_SNIPPED> ipsec[13494]: 07[IKE] queueing IKE_MOBIKE task
Aug 10 12:13:24 <HOSTNAME_SNIPPED> ipsec[13494]: 07[IKE] queueing IKE_ME task
Aug 10 12:13:24 <HOSTNAME_SNIPPED> ipsec[13494]: 07[IKE] queueing CHILD_CREATE task
Aug 10 12:13:24 <HOSTNAME_SNIPPED> ipsec[13494]: 07[IKE] activating new tasks
Aug 10 12:13:24 <HOSTNAME_SNIPPED> charon[13522]: 07[IKE] queueing IKE_AUTH task
Aug 10 12:13:24 <HOSTNAME_SNIPPED> charon[13522]: 07[IKE] queueing IKE_CERT_POST task
Aug 10 12:13:24 <HOSTNAME_SNIPPED> charon[13522]: 07[IKE] queueing IKE_CONFIG task
Aug 10 12:13:24 <HOSTNAME_SNIPPED> charon[13522]: 07[IKE] queueing IKE_AUTH_LIFETIME task
Aug 10 12:13:24 <HOSTNAME_SNIPPED> charon[13522]: 07[IKE] queueing IKE_MOBIKE task
Aug 10 12:13:24 <HOSTNAME_SNIPPED> charon[13522]: 07[IKE] queueing IKE_ME task
Aug 10 12:13:24 <HOSTNAME_SNIPPED> charon[13522]: 07[IKE] queueing CHILD_CREATE task
Aug 10 12:13:24 <HOSTNAME_SNIPPED> charon[13522]: 07[IKE] activating new tasks
Aug 10 12:13:24 <HOSTNAME_SNIPPED> charon[13522]: 07[IKE] activating IKE_VENDOR task
Aug 10 12:13:24 <HOSTNAME_SNIPPED> charon[13522]: 07[IKE] activating IKE_INIT task
Aug 10 12:13:24 <HOSTNAME_SNIPPED> charon[13522]: 07[IKE] activating IKE_NATD task
Aug 10 12:13:24 <HOSTNAME_SNIPPED> charon[13522]: 07[IKE] activating IKE_CERT_PRE task
Aug 10 12:13:24 <HOSTNAME_SNIPPED> charon[13522]: 07[IKE] activating IKE_ME task
Aug 10 12:13:24 <HOSTNAME_SNIPPED> charon[13522]: 07[IKE] activating IKE_AUTH task
Aug 10 12:13:24 <HOSTNAME_SNIPPED> charon[13522]: 07[IKE] activating IKE_CERT_POST task
Aug 10 12:13:24 <HOSTNAME_SNIPPED> charon[13522]: 07[IKE] activating IKE_CONFIG task
Aug 10 12:13:24 <HOSTNAME_SNIPPED> charon[13522]: 07[IKE] activating CHILD_CREATE task
Aug 10 12:13:24 <HOSTNAME_SNIPPED> charon[13522]: 07[IKE] activating IKE_AUTH_LIFETIME task
Aug 10 12:13:24 <HOSTNAME_SNIPPED> charon[13522]: 07[IKE] activating IKE_MOBIKE task
Aug 10 12:13:24 <HOSTNAME_SNIPPED> charon[13522]: 07[IKE] initiating IKE_SA <SITE_SNIPPED>secondary[1] to 64.7.137.180
Aug 10 12:13:24 <HOSTNAME_SNIPPED> charon[13522]: 07[IKE] initiating IKE_SA <SITE_SNIPPED>secondary[1] to 64.7.137.180
Aug 10 12:13:24 <HOSTNAME_SNIPPED> charon[13522]: 07[IKE] IKE_SA <SITE_SNIPPED>secondary[1] state change: CREATED => CONNECTING
Aug 10 12:13:24 <HOSTNAME_SNIPPED> charon[13522]: 07[ENC] generating IKE_SA_INIT request 0 [ SA KE No N(NATD_S_IP) N(NATD_D_IP) N(FRAG_SUP) N(HASH_ALG) N(REDIR_SUP) ]
Aug 10 12:13:24 <HOSTNAME_SNIPPED> charon[13522]: 07[NET] sending packet: from 1.0.0.6[500] to 64.7.137.180[500] (1224 bytes)
Aug 10 12:13:24 <HOSTNAME_SNIPPED> charon[13522]: 01[NET] received packet: from 64.7.137.180[500] to 1.0.0.6[500] (288 bytes)
Aug 10 12:13:24 <HOSTNAME_SNIPPED> charon[13522]: 01[ENC] parsed IKE_SA_INIT response 0 [ SA KE No N(NATD_S_IP) N(NATD_D_IP) ]
Aug 10 12:13:24 <HOSTNAME_SNIPPED> charon[13522]: 01[IKE] local host is behind NAT, sending keep alives
Aug 10 12:13:24 <HOSTNAME_SNIPPED> charon[13522]: 01[IKE] reinitiating already active tasks
Aug 10 12:13:24 <HOSTNAME_SNIPPED> charon[13522]: 01[IKE] IKE_CERT_PRE task
Aug 10 12:13:24 <HOSTNAME_SNIPPED> charon[13522]: 01[IKE] IKE_AUTH task
Aug 10 12:13:24 <HOSTNAME_SNIPPED> charon[13522]: 01[IKE] sending cert request for "C=US, ST=Arizona, L=Scottsdale, O=GoDaddy.com, Inc., CN=Go Daddy Root Certificate Authority - G2"
Aug 10 12:13:24 <HOSTNAME_SNIPPED> charon[13522]: 01[IKE] building INTERNAL_IP4_DNS attribute
Aug 10 12:13:24 <HOSTNAME_SNIPPED> charon[13522]: 01[IKE] building INTERNAL_IP4_DNS attribute
Aug 10 12:13:24 <HOSTNAME_SNIPPED> charon[13522]: 01[IKE] building INTERNAL_IP4_DNS attribute
Aug 10 12:13:24 <HOSTNAME_SNIPPED> charon[13522]: 01[IKE] establishing CHILD_SA <SITE_SNIPPED>secondary{3}
Aug 10 12:13:24 <HOSTNAME_SNIPPED> charon[13522]: 01[IKE] establishing CHILD_SA <SITE_SNIPPED>secondary{3}
Aug 10 12:13:24 <HOSTNAME_SNIPPED> charon[13522]: 01[ENC] generating IKE_AUTH request 1 [ IDi N(INIT_CONTACT) CERTREQ IDr CPRQ(ADDR DNS DNS DNS) SA TSi TSr N(MOBIKE_SUP) N(ADD_4_ADDR) N(ADD_4_ADDR) N(ADD_4_ADDR) N(ADD_4_ADDR) N(ADD_4_ADDR) N(EAP_ONLY) N(MSG_ID_SYN_SUP) ]
Aug 10 12:13:24 <HOSTNAME_SNIPPED> charon[13522]: 01[NET] sending packet: from 1.0.0.6[4500] to 64.7.137.180[4500] (432 bytes)
Aug 10 12:13:24 <HOSTNAME_SNIPPED> charon[13522]: 16[NET] received packet: from 64.7.137.180[4500] to 1.0.0.6[4500] (4096 bytes)
Aug 10 12:13:24 <HOSTNAME_SNIPPED> charon[13522]: 16[ENC] parsed IKE_AUTH response 1 [ IDr CERT CERT CERT AUTH EAP/REQ/ID ]
Aug 10 12:13:24 <HOSTNAME_SNIPPED> charon[13522]: 16[IKE] received end entity cert "OU=Domain Control Validated, CN=<SNIPPED>.com"
Aug 10 12:13:24 <HOSTNAME_SNIPPED> charon[13522]: 16[IKE] received issuer cert "C=US, ST=Arizona, L=Scottsdale, O=GoDaddy.com, Inc., OU=http://certs.godaddy.com/repository/, CN=Go Daddy Secure Certificate Authority - G2"
Aug 10 12:13:24 <HOSTNAME_SNIPPED> charon[13522]: 16[IKE] received issuer cert "C=US, ST=Arizona, L=Scottsdale, O=GoDaddy.com, Inc., CN=Go Daddy Root Certificate Authority - G2"
Aug 10 12:13:24 <HOSTNAME_SNIPPED> charon[13522]: 16[CFG] using certificate "OU=Domain Control Validated, CN=<SNIPPED>.com"
Aug 10 12:13:24 <HOSTNAME_SNIPPED> charon[13522]: 16[CFG] using untrusted intermediate certificate "C=US, ST=Arizona, L=Scottsdale, O=GoDaddy.com, Inc., OU=http://certs.godaddy.com/repository/, CN=Go Daddy Secure Certificate Authority - G2"
Aug 10 12:13:24 <HOSTNAME_SNIPPED> charon[13522]: 16[CFG] checking certificate status of "OU=Domain Control Validated, CN=<SNIPPED>.com"
Aug 10 12:13:24 <HOSTNAME_SNIPPED> charon[13522]: 16[CFG] requesting ocsp status from 'http://ocsp.godaddy.com/' ...
Aug 10 12:13:25 <HOSTNAME_SNIPPED> charon[13522]: 16[CFG] ocsp response correctly signed by "C=US, ST=Arizona, L=Scottsdale, O=GoDaddy Inc., CN=Go Daddy Validation Authority - G2"
Aug 10 12:13:25 <HOSTNAME_SNIPPED> charon[13522]: 16[CFG] ocsp response is valid: until Aug 11 08:26:21 2018
Aug 10 12:13:25 <HOSTNAME_SNIPPED> charon[13522]: 16[CFG] certificate status is good
Aug 10 12:13:25 <HOSTNAME_SNIPPED> charon[13522]: 16[CFG] using trusted ca certificate "C=US, ST=Arizona, L=Scottsdale, O=GoDaddy.com, Inc., CN=Go Daddy Root Certificate Authority - G2"
Aug 10 12:13:25 <HOSTNAME_SNIPPED> charon[13522]: 16[CFG] checking certificate status of "C=US, ST=Arizona, L=Scottsdale, O=GoDaddy.com, Inc., OU=http://certs.godaddy.com/repository/, CN=Go Daddy Secure Certificate Authority - G2"
Aug 10 12:13:25 <HOSTNAME_SNIPPED> charon[13522]: 16[CFG] ocsp response verification failed, no signer certificate 'C=US, ST=Arizona, L=Scottsdale, O=GoDaddy Inc., CN=Go Daddy Validation Authority - G2' found
Aug 10 12:13:25 <HOSTNAME_SNIPPED> charon[13522]: 16[CFG] requesting ocsp status from 'http://ocsp.godaddy.com/' ...
Aug 10 12:13:25 <HOSTNAME_SNIPPED> charon[13522]: 16[CFG] ocsp response correctly signed by "C=US, ST=Arizona, L=Scottsdale, O=GoDaddy.com, Inc., CN=Go Daddy Root Validation Authority - G2"
Aug 10 12:13:25 <HOSTNAME_SNIPPED> charon[13522]: 16[CFG] ocsp response is valid: until Aug 11 14:22:36 2018
Aug 10 12:13:25 <HOSTNAME_SNIPPED> charon[13522]: 16[CFG] certificate status is good
Aug 10 12:13:25 <HOSTNAME_SNIPPED> ipsec[13494]: 07[IKE] activating IKE_VENDOR task
Aug 10 12:13:25 <HOSTNAME_SNIPPED> ipsec[13494]: 07[IKE] activating IKE_INIT task
Aug 10 12:13:25 <HOSTNAME_SNIPPED> ipsec[13494]: 07[IKE] activating IKE_NATD task
Aug 10 12:13:25 <HOSTNAME_SNIPPED> ipsec[13494]: 07[IKE] activating IKE_CERT_PRE task
Aug 10 12:13:25 <HOSTNAME_SNIPPED> ipsec[13494]: 07[IKE] activating IKE_ME task
Aug 10 12:13:25 <HOSTNAME_SNIPPED> ipsec[13494]: 07[IKE] activating IKE_AUTH task
Aug 10 12:13:25 <HOSTNAME_SNIPPED> ipsec[13494]: 07[IKE] activating IKE_CERT_POST task
Aug 10 12:13:25 <HOSTNAME_SNIPPED> ipsec[13494]: 07[IKE] activating IKE_CONFIG task
Aug 10 12:13:25 <HOSTNAME_SNIPPED> ipsec[13494]: 07[IKE] activating CHILD_CREATE task
Aug 10 12:13:25 <HOSTNAME_SNIPPED> ipsec[13494]: 07[IKE] activating IKE_AUTH_LIFETIME task
Aug 10 12:13:25 <HOSTNAME_SNIPPED> ipsec[13494]: 07[IKE] activating IKE_MOBIKE task
Aug 10 12:13:25 <HOSTNAME_SNIPPED> ipsec[13494]: 07[IKE] initiating IKE_SA <SITE_SNIPPED>secondary[1] to 64.7.137.180
Aug 10 12:13:25 <HOSTNAME_SNIPPED> ipsec[13494]: 07[IKE] IKE_SA <SITE_SNIPPED>secondary[1] state change: CREATED => CONNECTING
Aug 10 12:13:25 <HOSTNAME_SNIPPED> ipsec[13494]: 07[ENC] generating IKE_SA_INIT request 0 [ SA KE No N(NATD_S_IP) N(NATD_D_IP) N(FRAG_SUP) N(HASH_ALG) N(REDIR_SUP) ]
Aug 10 12:13:25 <HOSTNAME_SNIPPED> ipsec[13494]: 07[NET] sending packet: from 1.0.0.6[500] to 64.7.137.180[500] (1224 bytes)
Aug 10 12:13:25 <HOSTNAME_SNIPPED> ipsec[13494]: 01[NET] received packet: from 64.7.137.180[500] to 1.0.0.6[500] (288 bytes)
Aug 10 12:13:25 <HOSTNAME_SNIPPED> ipsec[13494]: 01[ENC] parsed IKE_SA_INIT response 0 [ SA KE No N(NATD_S_IP) N(NATD_D_IP) ]
Aug 10 12:13:25 <HOSTNAME_SNIPPED> ipsec[13494]: 01[IKE] local host is behind NAT, sending keep alives
Aug 10 12:13:25 <HOSTNAME_SNIPPED> ipsec[13494]: 01[IKE] reinitiating already active tasks
Aug 10 12:13:25 <HOSTNAME_SNIPPED> ipsec[13494]: 01[IKE] IKE_CERT_PRE task
Aug 10 12:13:25 <HOSTNAME_SNIPPED> ipsec[13494]: 01[IKE] IKE_AUTH task
Aug 10 12:13:25 <HOSTNAME_SNIPPED> ipsec[13494]: 01[IKE] sending cert request for "C=US, ST=Arizona, L=Scottsdale, O=GoDaddy.com, Inc., CN=Go Daddy Root Certificate Authority - G2"
Aug 10 12:13:25 <HOSTNAME_SNIPPED> ipsec[13494]: 01[IKE] building INTERNAL_IP4_DNS attribute
Aug 10 12:13:25 <HOSTNAME_SNIPPED> ipsec[13494]: 01[IKE] establishing CHILD_SA <SITE_SNIPPED>secondary{3}
Aug 10 12:13:25 <HOSTNAME_SNIPPED> ipsec[13494]: 01[ENC] generating IKE_AUTH request 1 [ IDi N(INIT_CONTACT) CERTREQ IDr CPRQ(ADDR DNS DNS DNS) SA TSi TSr N(MOBIKE_SUP) N(ADD_4_ADDR) N(ADD_4_ADDR) N(ADD_4_ADDR) N(ADD_4_ADDR) N(ADD_4_ADDR) N(EAP_ONLY) N(MSG_ID_SYN_SUP) ]
Aug 10 12:13:25 <HOSTNAME_SNIPPED> ipsec[13494]: 01[NET] sending packet: from 1.0.0.6[4500] to 64.7.137.180[4500] (432 bytes)
Aug 10 12:13:25 <HOSTNAME_SNIPPED> ipsec[13494]: 16[NET] received packet: from 64.7.137.180[4500] to 1.0.0.6[4500] (4096 bytes)
Aug 10 12:13:25 <HOSTNAME_SNIPPED> ipsec[13494]: 16[ENC] parsed IKE_AUTH response 1 [ IDr CERT CERT CERT AUTH EAP/REQ/ID ]
Aug 10 12:13:25 <HOSTNAME_SNIPPED> ipsec[13494]: 16[IKE] received end entity cert "OU=Domain Control Validated, CN=<SNIPPED>.com"
Aug 10 12:13:25 <HOSTNAME_SNIPPED> ipsec[13494]: 16[IKE] received issuer cert "C=US, ST=Arizona, L=Scottsdale, O=GoDaddy.com, Inc., OU=http://certs.godaddy.com/repository/, CN=Go Daddy Secure Certificate Authority - G2"
Aug 10 12:13:25 <HOSTNAME_SNIPPED> charon[13522]: 16[CFG] certificate policy 2.16.840.1.114413.1.7.23.1 for 'OU=Domain Control Validated, CN=<SNIPPED>.com' not allowed by trustchain, ignored
Aug 10 12:13:25 <HOSTNAME_SNIPPED> ipsec[13494]: 16[IKE] received issuer cert "C=US, ST=Arizona, L=Scottsdale, O=GoDaddy.com, Inc., CN=Go Daddy Root Certificate Authority - G2"
Aug 10 12:13:25 <HOSTNAME_SNIPPED> ipsec[13494]: 16[CFG] using certificate "OU=Domain Control Validated, CN=<SNIPPED>.com"
Aug 10 12:13:25 <HOSTNAME_SNIPPED> ipsec[13494]: 16[CFG] using untrusted intermediate certificate "C=US, ST=Arizona, L=Scottsdale, O=GoDaddy.com, Inc., OU=http://certs.godaddy.com/repository/, CN=Go Daddy Secure Certificate Authority - G2"
Aug 10 12:13:25 <HOSTNAME_SNIPPED> ipsec[13494]: 16[CFG] checking certificate status of "OU=Domain Control Validated, CN=<SNIPPED>.com"
Aug 10 12:13:25 <HOSTNAME_SNIPPED> ipsec[13494]: 16[CFG] requesting ocsp status from 'http://ocsp.godaddy.com/' ...
Aug 10 12:13:25 <HOSTNAME_SNIPPED> ipsec[13494]: 16[CFG] ocsp response correctly signed by "C=US, ST=Arizona, L=Scottsdale, O=GoDaddy Inc., CN=Go Daddy Validation Authority - G2"
Aug 10 12:13:25 <HOSTNAME_SNIPPED> ipsec[13494]: 16[CFG] ocsp response is valid: until Aug 11 08:26:21 2018
Aug 10 12:13:25 <HOSTNAME_SNIPPED> ipsec[13494]: 16[CFG] certificate status is good
Aug 10 12:13:25 <HOSTNAME_SNIPPED> ipsec[13494]: 16[CFG] using trusted ca certificate "C=US, ST=Arizona, L=Scottsdale, O=GoDaddy.com, Inc., CN=Go Daddy Root Certificate Authority - G2"
Aug 10 12:13:25 <HOSTNAME_SNIPPED> ipsec[13494]: 16[CFG] checking certificate status of "C=US, ST=Arizona, L=Scottsdale, O=GoDaddy.com, Inc., OU=http://certs.godaddy.com/repository/, CN=Go Daddy Secure Certificate Authority - G2"
Aug 10 12:13:25 <HOSTNAME_SNIPPED> ipsec[13494]: 16[CFG] ocsp response verification failed, no signer certificate 'C=US, ST=Arizona, L=Scottsdale, O=GoDaddy Inc., CN=Go Daddy Validation Authority - G2' found
Aug 10 12:13:25 <HOSTNAME_SNIPPED> ipsec[13494]: 16[CFG] requesting ocsp status from 'http://ocsp.godaddy.com/' ...
Aug 10 12:13:25 <HOSTNAME_SNIPPED> ipsec[13494]: 16[CFG] ocsp response correctly signed by "C=US, ST=Arizona, L=Scottsdale, O=GoDaddy.com, Inc., CN=Go Daddy Root Validation Authority - G2"
Aug 10 12:13:25 <HOSTNAME_SNIPPED> ipsec[13494]: 16[CFG] ocsp response is valid: until Aug 11 14:22:36 2018
Aug 10 12:13:25 <HOSTNAME_SNIPPED> ipsec[13494]: 16[CFG] certificate status is good
Aug 10 12:13:25 <HOSTNAME_SNIPPED> ipsec[13494]: 16[CFG] certificate policy 2.16.840.1.114413.1.7.23.1 for 'OU=Domain Control Validated, CN=<SNIPPED>.com' not allowed by trustchain, ignored
Aug 10 12:13:25 <HOSTNAME_SNIPPED> ipsec[13494]: 16[CFG] certificate policy 2.23.140.1.2.1 for 'OU=Domain Control Validated, CN=<SNIPPED>.com' not allowed by trustchain, ignored
Aug 10 12:13:25 <HOSTNAME_SNIPPED> ipsec[13494]: 16[CFG] reached self-signed root ca with a path length of 1
Aug 10 12:13:25 <HOSTNAME_SNIPPED> ipsec[13494]: 16[IKE] authentication of 'OU=Domain Control Validated, CN=<SNIPPED>.com' with RSA signature successful
Aug 10 12:13:25 <HOSTNAME_SNIPPED> charon[13522]: 16[CFG] certificate policy 2.23.140.1.2.1 for 'OU=Domain Control Validated, CN=<SNIPPED>.com' not allowed by trustchain, ignored
Aug 10 12:13:25 <HOSTNAME_SNIPPED> charon[13522]: 16[CFG] reached self-signed root ca with a path length of 1
Aug 10 12:13:25 <HOSTNAME_SNIPPED> charon[13522]: 16[IKE] authentication of 'OU=Domain Control Validated, CN=<SNIPPED>.com' with RSA signature successful
Aug 10 12:13:25 <HOSTNAME_SNIPPED> charon[13522]: 16[IKE] server requested EAP_IDENTITY (id 0x92), sending '<USER_SNIPPED>'
Aug 10 12:13:25 <HOSTNAME_SNIPPED> charon[13522]: 16[IKE] reinitiating already active tasks
Aug 10 12:13:25 <HOSTNAME_SNIPPED> charon[13522]: 16[IKE] IKE_AUTH task
Aug 10 12:13:25 <HOSTNAME_SNIPPED> charon[13522]: 16[ENC] generating IKE_AUTH request 2 [ EAP/RES/ID ]
Aug 10 12:13:25 <HOSTNAME_SNIPPED> charon[13522]: 16[NET] sending packet: from 1.0.0.6[4500] to 64.7.137.180[4500] (96 bytes)
Aug 10 12:13:25 <HOSTNAME_SNIPPED> charon[13522]: 02[NET] received packet: from 64.7.137.180[4500] to 1.0.0.6[4500] (80 bytes)
Aug 10 12:13:25 <HOSTNAME_SNIPPED> charon[13522]: 02[ENC] parsed IKE_AUTH response 2 [ EAP/REQ/PEAP ]
Aug 10 12:13:25 <HOSTNAME_SNIPPED> charon[13522]: 02[IKE] server requested EAP_PEAP authentication (id 0x93)
Aug 10 12:13:25 <HOSTNAME_SNIPPED> charon[13522]: 02[IKE] requesting EAP_MSCHAPV2 authentication, sending EAP_NAK
Aug 10 12:13:25 <HOSTNAME_SNIPPED> charon[13522]: 02[IKE] reinitiating already active tasks
Aug 10 12:13:25 <HOSTNAME_SNIPPED> charon[13522]: 02[IKE] IKE_AUTH task
Aug 10 12:13:25 <HOSTNAME_SNIPPED> charon[13522]: 02[ENC] generating IKE_AUTH request 3 [ EAP/RES/NAK ]
Aug 10 12:13:25 <HOSTNAME_SNIPPED> charon[13522]: 02[NET] sending packet: from 1.0.0.6[4500] to 64.7.137.180[4500] (80 bytes)
Aug 10 12:13:25 <HOSTNAME_SNIPPED> charon[13522]: 03[NET] received packet: from 64.7.137.180[4500] to 1.0.0.6[4500] (112 bytes)
Aug 10 12:13:25 <HOSTNAME_SNIPPED> charon[13522]: 03[ENC] parsed IKE_AUTH response 3 [ EAP/REQ/MSCHAPV2 ]
Aug 10 12:13:25 <HOSTNAME_SNIPPED> charon[13522]: 03[IKE] server requested EAP_MSCHAPV2 authentication (id 0x94)
Aug 10 12:13:25 <HOSTNAME_SNIPPED> charon[13522]: 03[IKE] reinitiating already active tasks
Aug 10 12:13:25 <HOSTNAME_SNIPPED> charon[13522]: 03[IKE] IKE_AUTH task
Aug 10 12:13:25 <HOSTNAME_SNIPPED> charon[13522]: 03[ENC] generating IKE_AUTH request 4 [ EAP/RES/MSCHAPV2 ]
Aug 10 12:13:25 <HOSTNAME_SNIPPED> charon[13522]: 03[NET] sending packet: from 1.0.0.6[4500] to 64.7.137.180[4500] (144 bytes)
Aug 10 12:13:25 <HOSTNAME_SNIPPED> charon[13522]: 08[NET] received packet: from 64.7.137.180[4500] to 1.0.0.6[4500] (128 bytes)
Aug 10 12:13:25 <HOSTNAME_SNIPPED> charon[13522]: 08[ENC] parsed IKE_AUTH response 4 [ EAP/REQ/MSCHAPV2 ]
Aug 10 12:13:25 <HOSTNAME_SNIPPED> charon[13522]: 08[IKE] EAP-MS-CHAPv2 succeeded: '(null)'
Aug 10 12:13:25 <HOSTNAME_SNIPPED> charon[13522]: 08[IKE] reinitiating already active tasks
Aug 10 12:13:25 <HOSTNAME_SNIPPED> charon[13522]: 08[IKE] IKE_AUTH task
Aug 10 12:13:25 <HOSTNAME_SNIPPED> charon[13522]: 08[ENC] generating IKE_AUTH request 5 [ EAP/RES/MSCHAPV2 ]
Aug 10 12:13:25 <HOSTNAME_SNIPPED> charon[13522]: 08[NET] sending packet: from 1.0.0.6[4500] to 64.7.137.180[4500] (80 bytes)
Aug 10 12:13:25 <HOSTNAME_SNIPPED> charon[13522]: 09[NET] received packet: from 64.7.137.180[4500] to 1.0.0.6[4500] (80 bytes)
Aug 10 12:13:25 <HOSTNAME_SNIPPED> charon[13522]: 09[ENC] parsed IKE_AUTH response 5 [ EAP/SUCC ]
Aug 10 12:13:25 <HOSTNAME_SNIPPED> charon[13522]: 09[IKE] EAP method EAP_MSCHAPV2 succeeded, MSK established
Aug 10 12:13:25 <HOSTNAME_SNIPPED> charon[13522]: 09[IKE] reinitiating already active tasks
Aug 10 12:13:25 <HOSTNAME_SNIPPED> charon[13522]: 09[IKE] IKE_AUTH task
Aug 10 12:13:25 <HOSTNAME_SNIPPED> charon[13522]: 09[IKE] authentication of '<USER_SNIPPED>' (myself) with EAP
Aug 10 12:13:25 <HOSTNAME_SNIPPED> charon[13522]: 09[ENC] generating IKE_AUTH request 6 [ AUTH ]
Aug 10 12:13:25 <HOSTNAME_SNIPPED> charon[13522]: 09[NET] sending packet: from 1.0.0.6[4500] to 64.7.137.180[4500] (112 bytes)
Aug 10 12:13:25 <HOSTNAME_SNIPPED> charon[13522]: 04[NET] received packet: from 64.7.137.180[4500] to 1.0.0.6[4500] (336 bytes)
Aug 10 12:13:25 <HOSTNAME_SNIPPED> charon[13522]: 04[ENC] parsed IKE_AUTH response 6 [ IDr AUTH CPRP(ADDR DNS DNS) SA TSi TSr ]
Aug 10 12:13:25 <HOSTNAME_SNIPPED> charon[13522]: 04[IKE] authentication of 'OU=Domain Control Validated, CN=<SNIPPED>.com' with EAP successful
Aug 10 12:13:25 <HOSTNAME_SNIPPED> charon[13522]: 04[IKE] IKE_SA <SITE_SNIPPED>secondary[1] established between 1.0.0.6[<USER_SNIPPED>]...64.7.137.180[OU=Domain Control Validated, CN=<SNIPPED>.com]
Aug 10 12:13:25 <HOSTNAME_SNIPPED> charon[13522]: 04[IKE] IKE_SA <SITE_SNIPPED>secondary[1] established between 1.0.0.6[<USER_SNIPPED>]...64.7.137.180[OU=Domain Control Validated, CN=<SNIPPED>.com]
Aug 10 12:13:25 <HOSTNAME_SNIPPED> charon[13522]: 04[IKE] IKE_SA <SITE_SNIPPED>secondary[1] state change: CONNECTING => ESTABLISHED
Aug 10 12:13:25 <HOSTNAME_SNIPPED> charon[13522]: 04[IKE] scheduling reauthentication in 56374s
Aug 10 12:13:25 <HOSTNAME_SNIPPED> charon[13522]: 04[IKE] maximum IKE_SA lifetime 56554s
Aug 10 12:13:25 <HOSTNAME_SNIPPED> charon[13522]: 04[IKE] processing INTERNAL_IP4_ADDRESS attribute
Aug 10 12:13:25 <HOSTNAME_SNIPPED> charon[13522]: 04[IKE] processing INTERNAL_IP4_DNS attribute
Aug 10 12:13:25 <HOSTNAME_SNIPPED> charon[13522]: 04[IKE] installing DNS server 192.168.194.20 via resolvconf
Aug 10 12:13:25 <HOSTNAME_SNIPPED> charon[13522]: 04[IKE] processing INTERNAL_IP4_DNS attribute
Aug 10 12:13:25 <HOSTNAME_SNIPPED> charon[13522]: 04[IKE] installing DNS server 192.168.196.20 via resolvconf
<<HANGS>> no output
Some time later I saw a few extra logs:
Aug 10 12:16:09 <HOSTNAME_SNIPPED> charon[13522]: 12[KNL] creating delete job for CHILD_SA ESP/0xc875fa8e/1.0.0.6
of note, left it there for 15mins, no new logs or output from the command
#5 Updated by Ferm ulator about 7 years ago
PS: RE the concern about incomplete configuration -- the "primary" and "secondary" configurations are the exact same just for a few IPs change (company has primary/secondary for backup reasons) - nothing to see there ;o
#6 Updated by Ferm ulator about 7 years ago
For comparison, these are the logs that come for a successful connection. It's quite clear to me that strongswan is hanging trying to install a virtual IP, as that is the next log entry which is missing in the failure case.
Aug 16 10:19:34 <HOSTNAME_SNIPPED> charon[3698]: 11[IKE] installing DNS server 192.168.194.20 via resolvconf
Aug 16 10:19:35 <HOSTNAME_SNIPPED> charon[3698]: 11[IKE] processing INTERNAL_IP4_DNS attribute
Aug 16 10:19:35 <HOSTNAME_SNIPPED> charon[3698]: 11[IKE] installing DNS server 192.168.196.20 via resolvconf
Aug 16 10:19:35 <HOSTNAME_SNIPPED> charon[3698]: 11[IKE] installing new virtual IP 192.168.130.4
Aug 16 10:19:35 <HOSTNAME_SNIPPED> charon[3698]: 11[IKE] CHILD_SA <SITE_SNIPPED>secondary{70} established with SPIs cc2aa958_i 9ae56424_o and TS 192.168.130.4/32 === 10.0.0.0/8 172.16.0.0/12 192.168.128.0/17
Aug 16 10:19:35 <HOSTNAME_SNIPPED> charon[3698]: 11[IKE] CHILD_SA <SITE_SNIPPED>secondary{70} established with SPIs cc2aa958_i 9ae56424_o and TS 192.168.130.4/32 === 10.0.0.0/8 172.16.0.0/12 192.168.128.0/17
Aug 16 10:19:35 <HOSTNAME_SNIPPED> charon[3698]: 11[IKE] activating new tasks
Aug 16 10:19:35 <HOSTNAME_SNIPPED> charon[3698]: 11[IKE] nothing to initiate
Aug 16 10:19:47 <HOSTNAME_SNIPPED> charon[3698]: 11[NET] received packet: from 64.7.137.180[4500] to 1.0.0.6[4500] (80 bytes)
Aug 16 10:19:47 <HOSTNAME_SNIPPED> charon[3698]: 11[ENC] parsed INFORMATIONAL request 0 [ ]
Aug 16 10:19:47 <HOSTNAME_SNIPPED> charon[3698]: 11[ENC] generating INFORMATIONAL response 0 [ ]
Aug 16 10:19:47 <HOSTNAME_SNIPPED> charon[3698]: 11[NET] sending packet: from 1.0.0.6[4500] to 64.7.137.180[4500] (80 bytes)
Aug 16 10:19:56 <HOSTNAME_SNIPPED> charon[3698]: 05[NET] received packet: from 64.7.137.180[4500] to 1.0.0.6[4500] (80 bytes)
Aug 16 10:19:56 <HOSTNAME_SNIPPED> charon[3698]: 05[ENC] parsed INFORMATIONAL request 1 [ ]
Aug 16 10:19:56 <HOSTNAME_SNIPPED> charon[3698]: 05[ENC] generating INFORMATIONAL response 1 [ ]
Aug 16 10:19:56 <HOSTNAME_SNIPPED> charon[3698]: 05[NET] sending packet: from 1.0.0.6[4500] to 64.7.137.180[4500] (80 bytes)
Aug 16 10:20:01 <HOSTNAME_SNIPPED> charon[3698]: 06[NET] received packet: from 64.7.137.180[4500] to 1.0.0.6[4500] (80 bytes)
Aug 16 10:20:01 <HOSTNAME_SNIPPED> charon[3698]: 06[ENC] parsed INFORMATIONAL request 2 [ ]
Aug 16 10:20:01 <HOSTNAME_SNIPPED> charon[3698]: 06[ENC] generating INFORMATIONAL response 2 [ ]
Aug 16 10:20:01 <HOSTNAME_SNIPPED> charon[3698]: 06[NET] sending packet: from 1.0.0.6[4500] to 64.7.137.180[4500] (80 bytes)
...
(and of course the packet heartbeats continue)
as in, THIS entry is what doesn't come in the failure case
Aug 16 10:19:35 <HOSTNAME_SNIPPED> charon[3698]: 11[IKE] installing new virtual IP 192.168.130.4
#7 Updated by Ferm ulator about 7 years ago
FYI:
as per https://bugs.launchpad.net/ubuntu/+source/strongswan/+bug/1786261/comments/7, we have uncovered that this bug is due to an interaction with resolvconf
(not sure as of yet if this is the fault of strongswan making an invalid/incorrect call to the system, or if the systemd resolvconf/avahi-daemon is at fault)
#8 Updated by Ferm ulator about 7 years ago
PS: from strongswan's perspective,
we MAY desire to look into the system util call that is having issues
1. decide that it should work, let systems upstream fix it, users suffer
2. decide that the util invocation is NOT guaranteed to work, and augment it to be more robust (alternative? add timeout? etc)
#9 Updated by Tobias Brunner almost 7 years ago
- Category set to interoperability
- Status changed from Feedback to Closed
- Assignee set to Tobias Brunner
- Resolution set to No change required