On Wed, Nov 09, 2011 at 06:14:05PM +0100, Tobias Brunner wrote:
> Hi Mirko,
> 
> > However, I found another problem, possibly related, which can be
> > reproduced as follows with Strongswan 4.6.0:
> > 
> > - setup the test scenario as in ikev2/net2net-cert (ignoring winnetou)
> > - replace the ethernet link between moon and sun by a serial line,
> >   run PPP on it with the IP addresses that were previously on ethernet
> > - start the IPsec tunnel -> route in table 220 is OK
> > - trigger PPP renegotiation -> route is gone
> > 
> > Charon log: see attachment.
> 
> Hm, I don't see that charon is actually able to find a new route to the
> other host.  The last log entries are
> 
> Nov  9 17:32:55 moon charon: 03[KNL] interface ppp0 activated
> Nov  9 17:32:55 moon charon: 12[KNL] creating roam job due to address/link 
> change
> Nov  9 17:32:55 moon charon: 12[KNL] getting address to reach 192.168.0.2
> 
> Could it be that the log is truncated?

Hi Tobias,

I may be wrong, but I don't think it has been truncated.

Here's the same experiment repeated, adding a few timestamps
and a clean shutdown at the end.

At 18:49:25, the route to 192.168.0.2 does exist,
but charon hasn't noticed it.

Regards,
Mirko

Script started on Mi 09 Nov 2011 18:46:39 CET
root@moon:~# ipsec up net-net
[...]
root@moon:~# date; ip route ls
Mi 9. Nov 18:48:23 CET 2011
192.168.0.2 dev ppp0  proto kernel  scope link  src 192.168.0.1
10.1.0.0/16 dev eth1  proto kernel  scope link  src 10.1.0.1
root@moon:~# ip route ls table 220
10.2.0.0/16 via 192.168.0.2 dev ppp0  proto static  src 10.1.0.1
root@moon:~# killall -HUP pppd
root@moon:~# date; ip route ls
Mi 9. Nov 18:49:25 CET 2011
192.168.0.2 dev ppp0  proto kernel  scope link  src 192.168.0.1
10.1.0.0/16 dev eth1  proto kernel  scope link  src 10.1.0.1
root@moon:~# date; ip route ls table 220
Mi 9. Nov 18:49:29 CET 2011
root@moon:~# ipsec stop
Stopping strongSwan IPsec...
root@moon:~# exit
Script done on Mi 09 Nov 2011 18:50:14 CET
Nov  9 18:41:17 moon charon: 00[DMN] Starting IKEv2 charon daemon (strongSwan 
4.6.0)
Nov  9 18:41:20 moon charon: 00[KNL] listening on interfaces:
Nov  9 18:41:20 moon charon: 00[KNL]   eth1
Nov  9 18:41:20 moon charon: 00[KNL]     10.1.0.1
Nov  9 18:41:20 moon charon: 00[KNL]     fe80::5054:ff:fe71:c0d7
Nov  9 18:41:20 moon charon: 00[CFG] loading ca certificates from 
'/etc/ipsec.d/cacerts'
Nov  9 18:41:20 moon charon: 00[CFG]   loaded ca certificate "C=CH, O=Linux 
strongSwan, CN=strongSwan Root CA" from 
'/etc/ipsec.d/cacerts/strongswanCert.pem'
Nov  9 18:41:20 moon charon: 00[CFG] loading aa certificates from 
'/etc/ipsec.d/aacerts'
Nov  9 18:41:20 moon charon: 00[CFG] loading ocsp signer certificates from 
'/etc/ipsec.d/ocspcerts'
Nov  9 18:41:20 moon charon: 00[CFG] loading attribute certificates from 
'/etc/ipsec.d/acerts'
Nov  9 18:41:20 moon charon: 00[CFG] loading crls from '/etc/ipsec.d/crls'
Nov  9 18:41:20 moon charon: 00[CFG] loading secrets from '/etc/ipsec.secrets'
Nov  9 18:41:20 moon charon: 00[CFG]   loaded RSA private key from 
'/etc/ipsec.d/private/moonKey.pem'
Nov  9 18:41:20 moon charon: 00[CFG] sql plugin: database URI not set
Nov  9 18:41:20 moon charon: 00[LIB] plugin 'sql': failed to load - 
sql_plugin_create returned NULL
Nov  9 18:41:21 moon charon: 00[CFG] loaded 0 RADIUS server configurations
Nov  9 18:41:21 moon charon: 00[LIB] plugin 'eap-tnc' failed to load: 
/usr/lib/ipsec/plugins/libstrongswan-eap-tnc.so: undefined symbol: tnc
Nov  9 18:41:21 moon charon: 00[LIB] plugin 'medsrv' failed to load: 
/usr/lib/ipsec/plugins/libstrongswan-medsrv.so: cannot open shared object file: 
No such file or directory
Nov  9 18:41:21 moon charon: 00[CFG] mediation client database URI not defined, 
skipped
Nov  9 18:41:21 moon charon: 00[LIB] plugin 'medcli': failed to load - 
medcli_plugin_create returned NULL
Nov  9 18:41:21 moon charon: 00[LIB] plugin 'nm' failed to load: 
/usr/lib/ipsec/plugins/libstrongswan-nm.so: cannot open shared object file: No 
such file or directory
Nov  9 18:41:22 moon charon: 00[CFG] HA config misses local/remote address
Nov  9 18:41:22 moon charon: 00[LIB] plugin 'ha': failed to load - 
ha_plugin_create returned NULL
Nov  9 18:41:22 moon charon: 00[LIB] feature PRF:PRF_CAMELLIA128_XCBC in 'xcbc' 
plugin has unsatisfied dependency: CRYPTER:CAMELLIA_CBC-16
Nov  9 18:41:22 moon charon: 00[LIB] feature SIGNER:CAMELLIA_XCBC_96 in 'xcbc' 
plugin has unsatisfied dependency: CRYPTER:CAMELLIA_CBC-16
Nov  9 18:41:22 moon charon: 00[LIB] feature CRYPTER:CAMELLIA_CTR-16 in 'ctr' 
plugin has unsatisfied dependency: CRYPTER:CAMELLIA_CBC-16
Nov  9 18:41:22 moon charon: 00[LIB] feature CRYPTER:CAMELLIA_CTR-24 in 'ctr' 
plugin has unsatisfied dependency: CRYPTER:CAMELLIA_CBC-24
Nov  9 18:41:22 moon charon: 00[LIB] feature CRYPTER:CAMELLIA_CTR-32 in 'ctr' 
plugin has unsatisfied dependency: CRYPTER:CAMELLIA_CBC-32
Nov  9 18:41:22 moon charon: 00[LIB] feature AEAD:CAMELLIA_CCM_8-16 in 'ccm' 
plugin has unsatisfied dependency: CRYPTER:CAMELLIA_CBC-16
Nov  9 18:41:22 moon charon: 00[LIB] feature AEAD:CAMELLIA_CCM_8-24 in 'ccm' 
plugin has unsatisfied dependency: CRYPTER:CAMELLIA_CBC-24
Nov  9 18:41:22 moon charon: 00[LIB] feature AEAD:CAMELLIA_CCM_8-32 in 'ccm' 
plugin has unsatisfied dependency: CRYPTER:CAMELLIA_CBC-32
Nov  9 18:41:22 moon charon: 00[LIB] feature AEAD:CAMELLIA_CCM_12-16 in 'ccm' 
plugin has unsatisfied dependency: CRYPTER:CAMELLIA_CBC-16
Nov  9 18:41:22 moon charon: 00[LIB] feature AEAD:CAMELLIA_CCM_12-24 in 'ccm' 
plugin has unsatisfied dependency: CRYPTER:CAMELLIA_CBC-24
Nov  9 18:41:22 moon charon: 00[LIB] feature AEAD:CAMELLIA_CCM_12-32 in 'ccm' 
plugin has unsatisfied dependency: CRYPTER:CAMELLIA_CBC-32
Nov  9 18:41:22 moon charon: 00[LIB] feature AEAD:CAMELLIA_CCM_16-16 in 'ccm' 
plugin has unsatisfied dependency: CRYPTER:CAMELLIA_CBC-16
Nov  9 18:41:22 moon charon: 00[LIB] feature AEAD:CAMELLIA_CCM_16-24 in 'ccm' 
plugin has unsatisfied dependency: CRYPTER:CAMELLIA_CBC-24
Nov  9 18:41:22 moon charon: 00[LIB] feature AEAD:CAMELLIA_CCM_16-32 in 'ccm' 
plugin has unsatisfied dependency: CRYPTER:CAMELLIA_CBC-32
Nov  9 18:41:22 moon charon: 00[DMN] loaded plugins: test-vectors curl ldap 
pkcs11 aes des sha1 sha2 md5 random x509 revocation constraints pubkey pkcs1 
pgp pem openssl fips-prf gmp agent xcbc hmac ctr ccm gcm attr kernel-netlink 
resolve socket-raw farp stroke updown eap-identity eap-aka eap-md5 eap-gtc 
eap-mschapv2 eap-radius eap-tls eap-ttls dhcp led addrblock 
Nov  9 18:41:22 moon charon: 00[JOB] spawning 16 worker threads
Nov  9 18:41:22 moon charon: 10[CFG] received stroke: add connection 'net-net'
Nov  9 18:41:22 moon charon: 10[KNL] getting interface name for 192.168.0.2
Nov  9 18:41:22 moon charon: 10[KNL] 192.168.0.2 is not a local address
Nov  9 18:41:22 moon charon: 10[KNL] getting interface name for 192.168.0.1
Nov  9 18:41:22 moon charon: 10[KNL] 192.168.0.1 is not a local address
Nov  9 18:41:22 moon charon: 10[CFG] left nor right host is our side, assuming 
left=local
Nov  9 18:41:22 moon charon: 10[CFG]   loaded certificate "C=CH, O=Linux 
strongSwan, CN=moon.strongswan.org" from 'moonCert.pem'
Nov  9 18:41:22 moon charon: 10[CFG] added configuration 'net-net'
Nov  9 18:41:25 moon acpid: starting up with netlink and the input layer
Nov  9 18:41:25 moon acpid: 1 rule loaded
Nov  9 18:41:25 moon acpid: waiting for events: event logging is off
Nov  9 18:47:43 moon charon: 03[KNL] 192.168.0.1 appeared on ppp0
Nov  9 18:47:43 moon charon: 03[KNL] 192.168.0.1 disappeared from ppp0
Nov  9 18:47:43 moon charon: 03[KNL] 192.168.0.1 appeared on ppp0
Nov  9 18:47:43 moon charon: 03[KNL] interface ppp0 activated
Nov  9 18:47:43 moon charon: 12[KNL] creating roam job due to address/link 
change
Nov  9 18:48:04 moon charon: 14[CFG] received stroke: initiate 'net-net'
Nov  9 18:48:04 moon charon: 16[IKE] initiating IKE_SA net-net[1] to 192.168.0.2
Nov  9 18:48:04 moon charon: 16[ENC] generating IKE_SA_INIT request 0 [ SA KE 
No N(NATD_S_IP) N(NATD_D_IP) ]
Nov  9 18:48:04 moon charon: 16[NET] sending packet: from 192.168.0.1[500] to 
192.168.0.2[500]
Nov  9 18:48:05 moon charon: 01[NET] received packet: from 192.168.0.2[500] to 
192.168.0.1[500]
Nov  9 18:48:05 moon charon: 01[ENC] parsed IKE_SA_INIT response 0 [ SA KE No 
N(NATD_S_IP) N(NATD_D_IP) CERTREQ N(MULT_AUTH) ]
Nov  9 18:48:05 moon charon: 01[IKE] received cert request for "C=CH, O=Linux 
strongSwan, CN=strongSwan Root CA"
Nov  9 18:48:05 moon charon: 01[IKE] sending cert request for "C=CH, O=Linux 
strongSwan, CN=strongSwan Root CA"
Nov  9 18:48:05 moon charon: 01[IKE] authentication of 'moon.strongswan.org' 
(myself) with RSA signature successful
Nov  9 18:48:05 moon charon: 01[IKE] sending end entity cert "C=CH, O=Linux 
strongSwan, CN=moon.strongswan.org"
Nov  9 18:48:05 moon charon: 01[IKE] establishing CHILD_SA net-net
Nov  9 18:48:05 moon charon: 01[KNL] getting SPI for reqid {1}
Nov  9 18:48:05 moon charon: 01[KNL] got SPI c60643c9 for reqid {1}
Nov  9 18:48:05 moon charon: 01[ENC] generating IKE_AUTH request 1 [ IDi CERT 
N(INIT_CONTACT) CERTREQ IDr AUTH SA TSi TSr N(MULT_AUTH) N(EAP_ONLY) ]
Nov  9 18:48:05 moon charon: 01[NET] sending packet: from 192.168.0.1[500] to 
192.168.0.2[500]
Nov  9 18:48:05 moon charon: 11[NET] received packet: from 192.168.0.2[500] to 
192.168.0.1[500]
Nov  9 18:48:05 moon charon: 11[ENC] parsed IKE_AUTH response 1 [ IDr CERT AUTH 
SA TSi TSr N(AUTH_LFT) ]
Nov  9 18:48:05 moon charon: 11[IKE] received end entity cert "C=CH, O=Linux 
strongSwan, CN=sun.strongswan.org"
Nov  9 18:48:05 moon charon: 11[CFG]   using certificate "C=CH, O=Linux 
strongSwan, CN=sun.strongswan.org"
Nov  9 18:48:05 moon charon: 11[CFG]   using trusted ca certificate "C=CH, 
O=Linux strongSwan, CN=strongSwan Root CA"
Nov  9 18:48:05 moon charon: 11[CFG] checking certificate status of "C=CH, 
O=Linux strongSwan, CN=sun.strongswan.org"
Nov  9 18:48:05 moon charon: 11[CFG]   fetching crl from 
'http://crl.strongswan.org/strongswan.crl' ...
Nov  9 18:48:05 moon charon: 11[LIB] libcurl http request failed: couldn't 
connect to host
Nov  9 18:48:05 moon charon: 11[CFG] crl fetching failed
Nov  9 18:48:05 moon charon: 11[CFG] certificate status is not available
Nov  9 18:48:05 moon charon: 11[CFG]   reached self-signed root ca with a path 
length of 0
Nov  9 18:48:05 moon charon: 11[IKE] authentication of 'sun.strongswan.org' 
with RSA signature successful
Nov  9 18:48:05 moon charon: 11[IKE] IKE_SA net-net[1] established between 
192.168.0.1[moon.strongswan.org]...192.168.0.2[sun.strongswan.org]
Nov  9 18:48:05 moon charon: 11[IKE] scheduling reauthentication in 3392s
Nov  9 18:48:05 moon charon: 11[IKE] maximum IKE_SA lifetime 3572s
Nov  9 18:48:05 moon charon: 11[KNL] adding SAD entry with SPI c60643c9 and 
reqid {1}
Nov  9 18:48:05 moon charon: 11[KNL]   using encryption algorithm AES_CBC with 
key size 128
Nov  9 18:48:05 moon charon: 11[KNL]   using integrity algorithm HMAC_SHA1_96 
with key size 160
Nov  9 18:48:05 moon charon: 11[KNL] adding SAD entry with SPI c1f0c057 and 
reqid {1}
Nov  9 18:48:05 moon charon: 11[KNL]   using encryption algorithm AES_CBC with 
key size 128
Nov  9 18:48:05 moon charon: 11[KNL]   using integrity algorithm HMAC_SHA1_96 
with key size 160
Nov  9 18:48:05 moon charon: 11[KNL] adding policy 10.1.0.0/16 === 10.2.0.0/16 
out
Nov  9 18:48:05 moon charon: 11[KNL] adding policy 10.2.0.0/16 === 10.1.0.0/16 
in
Nov  9 18:48:05 moon charon: 11[KNL] adding policy 10.2.0.0/16 === 10.1.0.0/16 
fwd
Nov  9 18:48:05 moon charon: 11[KNL] getting a local address in traffic 
selector 10.1.0.0/16
Nov  9 18:48:05 moon charon: 11[KNL] using host 10.1.0.1
Nov  9 18:48:05 moon charon: 11[KNL] getting address to reach 192.168.0.2
Nov  9 18:48:05 moon charon: 11[KNL] getting interface name for 192.168.0.1
Nov  9 18:48:05 moon charon: 11[KNL] 192.168.0.1 is on interface ppp0
Nov  9 18:48:05 moon charon: 11[KNL] installing route: 10.2.0.0/16 via 
192.168.0.2 src 10.1.0.1 dev ppp0
Nov  9 18:48:05 moon charon: 11[KNL] getting iface index for ppp0
Nov  9 18:48:05 moon charon: 11[KNL] policy 10.1.0.0/16 === 10.2.0.0/16 out 
already exists, increasing refcount
Nov  9 18:48:05 moon charon: 11[KNL] updating policy 10.1.0.0/16 === 
10.2.0.0/16 out
Nov  9 18:48:05 moon charon: 11[KNL] policy 10.2.0.0/16 === 10.1.0.0/16 in 
already exists, increasing refcount
Nov  9 18:48:05 moon charon: 11[KNL] updating policy 10.2.0.0/16 === 
10.1.0.0/16 in
Nov  9 18:48:05 moon charon: 11[KNL] policy 10.2.0.0/16 === 10.1.0.0/16 fwd 
already exists, increasing refcount
Nov  9 18:48:05 moon charon: 11[KNL] updating policy 10.2.0.0/16 === 
10.1.0.0/16 fwd
Nov  9 18:48:05 moon charon: 11[KNL] getting a local address in traffic 
selector 10.1.0.0/16
Nov  9 18:48:05 moon charon: 11[KNL] using host 10.1.0.1
Nov  9 18:48:05 moon charon: 11[KNL] getting address to reach 192.168.0.2
Nov  9 18:48:05 moon charon: 11[KNL] getting interface name for 192.168.0.1
Nov  9 18:48:05 moon charon: 11[KNL] 192.168.0.1 is on interface ppp0
Nov  9 18:48:05 moon charon: 11[KNL] getting iface index for ppp0
Nov  9 18:48:05 moon charon: 11[IKE] CHILD_SA net-net{1} established with SPIs 
c60643c9_i c1f0c057_o and TS 10.1.0.0/16 === 10.2.0.0/16 
Nov  9 18:48:05 moon charon: 11[KNL] getting interface name for 192.168.0.1
Nov  9 18:48:05 moon charon: 11[KNL] 192.168.0.1 is on interface ppp0
Nov  9 18:48:06 moon charon: 11[IKE] received AUTH_LIFETIME of 3315s, 
scheduling reauthentication in 3135s
Nov  9 18:49:00 moon charon: 03[KNL] interface ppp0 deactivated
Nov  9 18:49:00 moon charon: 03[KNL] 192.168.0.1 disappeared from ppp0
Nov  9 18:49:00 moon charon: 13[KNL] creating roam job due to address/link 
change
Nov  9 18:49:00 moon charon: 13[KNL] getting address to reach 192.168.0.2
Nov  9 18:49:00 moon charon: 13[IKE] old path is not available anymore, try to 
find another
Nov  9 18:49:00 moon charon: 13[KNL] getting address to reach 192.168.0.2
Nov  9 18:49:00 moon charon: 13[IKE] no route found to reach 192.168.0.2, 
MOBIKE update deferred
Nov  9 18:49:04 moon charon: 03[KNL] 192.168.0.1 appeared on ppp0
Nov  9 18:49:04 moon charon: 03[KNL] 192.168.0.1 disappeared from ppp0
Nov  9 18:49:04 moon charon: 03[KNL] 192.168.0.1 appeared on ppp0
Nov  9 18:49:04 moon charon: 03[KNL] interface ppp0 activated
Nov  9 18:49:04 moon charon: 16[KNL] creating roam job due to address/link 
change
Nov  9 18:49:04 moon charon: 16[KNL] getting address to reach 192.168.0.2
Nov  9 18:49:53 moon charon: 00[DMN] signal of type SIGINT received. Shutting 
down
Nov  9 18:49:53 moon charon: 00[IKE] deleting IKE_SA net-net[1] between 
192.168.0.1[moon.strongswan.org]...192.168.0.2[sun.strongswan.org]
Nov  9 18:49:53 moon charon: 00[IKE] sending DELETE for IKE_SA net-net[1]
Nov  9 18:49:53 moon charon: 00[ENC] generating INFORMATIONAL request 2 [ D ]
Nov  9 18:49:53 moon charon: 00[NET] sending packet: from 192.168.0.1[500] to 
192.168.0.2[500]
Nov  9 18:49:53 moon charon: 00[KNL] deleting SAD entry with SPI c60643c9
Nov  9 18:49:53 moon charon: 00[KNL] deleted SAD entry with SPI c60643c9
Nov  9 18:49:53 moon charon: 00[KNL] deleting SAD entry with SPI c1f0c057
Nov  9 18:49:53 moon charon: 00[KNL] deleted SAD entry with SPI c1f0c057
Nov  9 18:49:53 moon charon: 00[KNL] deleting policy 10.1.0.0/16 === 
10.2.0.0/16 out
Nov  9 18:49:53 moon charon: 00[KNL] policy still used by another CHILD_SA, not 
removed
Nov  9 18:49:53 moon charon: 00[KNL] updating policy 10.1.0.0/16 === 
10.2.0.0/16 out
Nov  9 18:49:53 moon charon: 00[KNL] deleting policy 10.2.0.0/16 === 
10.1.0.0/16 in
Nov  9 18:49:53 moon charon: 00[KNL] policy still used by another CHILD_SA, not 
removed
Nov  9 18:49:53 moon charon: 00[KNL] updating policy 10.2.0.0/16 === 
10.1.0.0/16 in
Nov  9 18:49:53 moon charon: 00[KNL] deleting policy 10.2.0.0/16 === 
10.1.0.0/16 fwd
Nov  9 18:49:53 moon charon: 00[KNL] policy still used by another CHILD_SA, not 
removed
Nov  9 18:49:53 moon charon: 00[KNL] updating policy 10.2.0.0/16 === 
10.1.0.0/16 fwd
Nov  9 18:49:53 moon charon: 00[KNL] getting a local address in traffic 
selector 10.1.0.0/16
Nov  9 18:49:53 moon charon: 00[KNL] using host 10.1.0.1
Nov  9 18:49:53 moon charon: 00[KNL] getting address to reach 192.168.0.2
Nov  9 18:49:53 moon charon: 00[KNL] getting interface name for 192.168.0.1
Nov  9 18:49:53 moon charon: 00[KNL] 192.168.0.1 is on interface ppp0
Nov  9 18:49:53 moon charon: 00[KNL] getting iface index for ppp0
Nov  9 18:49:53 moon charon: 00[KNL] received netlink error: No such process (3)
Nov  9 18:49:53 moon charon: 00[KNL] deleting policy 10.1.0.0/16 === 
10.2.0.0/16 out
Nov  9 18:49:53 moon charon: 00[KNL] deleting policy 10.2.0.0/16 === 
10.1.0.0/16 in
Nov  9 18:49:53 moon charon: 00[KNL] deleting policy 10.2.0.0/16 === 
10.1.0.0/16 fwd
Nov  9 18:49:53 moon charon: 00[KNL] getting iface index for ppp0
Nov  9 18:49:53 moon charon: 00[KNL] received netlink error: No such process (3)
Nov  9 18:49:53 moon charon: 00[KNL] error uninstalling route installed with 
policy 10.2.0.0/16 === 10.1.0.0/16 fwd
Nov  9 18:49:53 moon charon: 00[DMN] thread 0 received 11
Nov  9 18:50:25 moon init: Switching to runlevel: 0
Nov  9 18:50:26 moon acpid: exiting
_______________________________________________
Users mailing list
[email protected]
https://lists.strongswan.org/mailman/listinfo/users

Reply via email to