[Openswan Users] Mac OS X - Openswan - L2TP - NAT-T problems

Danilo Godec danilo.godec at agenda.si
Wed Nov 14 03:59:49 EST 2007


Hello,

I've been trying to get Mac OS X to connect to our Linux OpenSwan based
L2TP gateway - with no success. In the process I updated our gateway
from OpenSwan 1.0.10 to the latest stable version 2.4.10, but it changed
nothing.

I followed instructions from
http://www.jacco2.dds.nl/networking/freeswan-panther.html and Mac OS
does connect if using a public IP (i.e. without NAT-T), so I think the
certificates and general stuff is OK. Windows XP clients also work even
with NAT-T.

A bug when using 'right=%any' and NAT-T is mentioned on that page, but
following that link (http://bugs.xelerance.com/view.php?id=773) and
reading through it doesn't look like my problem. But anyway - is this
bug still present in 2.4.10 ?

Here are my config files on the server side (server and client public
IP's have been replaced by 'SERVER.PUBLIC.IP' and 'CLIENT.PUBLIC.IP 
respectively, while domain name has been replaced by 'SERVER.DOMAIN'):
> # /etc/ipsec.conf - FreeS/WAN IPsec configuration file
>
> version 2.0
>
> # basic configuration
> config setup
>         # THIS SETTING MUST BE CORRECT or almost nothing will work;
>         # %defaultroute is okay for most simple cases.
>         interfaces=%defaultroute
>         # Debug-logging controls:  "none" for (almost) none, "all" for
> lots.
>         klipsdebug=none
>         plutodebug=control
>         # Use auto= parameters in conn descriptions to control startup
> actions.
>         #plutoload=%search
>         #plutostart=%search
>         # Close down old connection when new one using same ID shows up.
>         uniqueids=yes
>         nat_traversal=yes
>
>
> # defaults for subsequent connection descriptions
> # (these defaults will soon go away)
> conn %default
>         # Default: %forever (try forever)
>         keyingtries=0
>         # Sig keys (default: %dnsondemand)
>         #leftrsasigkey=%cert
>         #rightrsasigkey=%cert
>         # Lifetimes, defaults are 1h/8hrs
>         #ikelifetime=20m
>         keylife=1h
>         compress=no
>         disablearrivalcheck=no
>         auto=route
>         #rekeymargin=8m
>         authby=rsasig
>
> include /etc/ipsec.d/examples/no_oe.conf
> include /etc/ipsec.d/road.certs.mac
> include /etc/ipsec.d/mobitel
And here is 'road.certs.mac':
> conn rwmac-net
>         #
>         # Use a certificate. Disable Perfect Forward Secrecy.
>         #
>         authby=rsasig
>         pfs=no
>         auto=add
>         rekey=no
>         left=%defaultroute
>         leftrsasigkey=%cert
>         leftcert=fw.SERVER.DOMAIN-cert.pem
>         leftupdown=/lib/ipsec/_updown_x509
>         leftprotoport=udp/1701
>         right=%any
>         #rightca=%same
>         rightrsasigkey=%cert
>         rightprotoport=udp/%any
>         #rightsubnet=vhost:%priv,%no
Note that this configuration works with Windows XP SP2 clients behj

Here is what I get in my logs:

> Nov 13 15:52:17 fw pluto[30413]: "rwmac-net"[2] CLIENT.PUBLIC.IP #1:
> cannot respond to IPsec SA request because no connection is known for
> SERVER.PUBLIC.IP[C=SI, ST=Slovenia, L=Ljubljana, O=Delo Tiskarna,
> OU=IT, CN=fw.SERVER.DOMAIN,
> E=root at SERVER.DOMAIN]:17/1701...CLIENT.PUBLIC.IP[C=SI, ST=Slovenia,
> L=Ljubljana, O=Delo Tiskarna, OU=IT, CN=Sebastijan Silec,
> E=sebastijan.silec at CLIENT.DOMAIN]:17/%any===172.16.0.106/32

And here is whole of the log regarding OpenSwan and this connection:


> Nov 13 15:52:05 fw ipsec_setup: ...Openswan IPsec started
> Nov 13 15:52:05 fw pluto[30413]: Starting Pluto (Openswan Version
> 2.4.10 PLUTO_SENDS_VENDORID PLUTO_USES_KEYRR; Vendor ID OEtq^eUwVz_A)
> Nov 13 15:52:05 fw pluto[30413]: Setting NAT-Traversal port-4500
> floating to on
> Nov 13 15:52:05 fw pluto[30413]:    port floating activation criteria
> nat_t=1/port_fload=1
> Nov 13 15:52:05 fw pluto[30413]:   including NAT-Traversal patch
> (Version 0.6c)
> Nov 13 15:52:05 fw pluto[30413]: | opening /dev/urandom
> Nov 13 15:52:05 fw pluto[30413]: | inserting event
> EVENT_REINIT_SECRET, timeout in 3600 seconds
> Nov 13 15:52:05 fw pluto[30413]: | inserting event
> EVENT_PENDING_PHASE2, timeout in 120 seconds
> Nov 13 15:52:05 fw pluto[30413]: ike_alg_register_enc(): Activating
> OAKLEY_AES_CBC: Ok (ret=0)
> Nov 13 15:52:05 fw pluto[30413]: starting up 1 cryptographic helpers
> Nov 13 15:52:05 fw pluto[30413]: started helper pid=30417 (fd:6)
> Nov 13 15:52:05 fw pluto[30417]: | opening /dev/urandom
> Nov 13 15:52:05 fw pluto[30417]: ! helper 0 waiting on fd: 7
> Nov 13 15:52:05 fw pluto[30413]: Using KLIPS IPsec interface code on
> 2.4.34
> Nov 13 15:52:05 fw pluto[30413]: | inserting event EVENT_SHUNT_SCAN,
> timeout in 120 seconds
> Nov 13 15:52:05 fw pluto[30413]: Changing to directory
> '/etc/ipsec.d/cacerts'
> Nov 13 15:52:05 fw pluto[30413]:   loaded CA cert file
> 'DELO-TISKARNA-cacert.pem' (2553 bytes)
> Nov 13 15:52:05 fw pluto[30413]: Could not change to directory
> '/etc/ipsec.d/aacerts'
> Nov 13 15:52:05 fw pluto[30413]: Could not change to directory
> '/etc/ipsec.d/ocspcerts'
> Nov 13 15:52:05 fw pluto[30413]: Changing to directory '/etc/ipsec.d/crls'
> Nov 13 15:52:05 fw pluto[30413]:   loaded crl file
> 'DELO-TISKARNA-crl.pem' (1210 bytes)
> Nov 13 15:52:05 fw pluto[30413]: | inserting event EVENT_LOG_DAILY,
> timeout in 29173 seconds
> Nov 13 15:52:05 fw pluto[30413]: | next event EVENT_SHUNT_SCAN in 120
> seconds
> Nov 13 15:52:06 fw pluto[30413]: |  
> Nov 13 15:52:06 fw pluto[30413]: | *received whack message
> Nov 13 15:52:06 fw pluto[30413]: | Added new connection rwmac-net with
> policy RSASIG+ENCRYPT+TUNNEL+DONTREKEY
> Nov 13 15:52:06 fw pluto[30413]:   loaded host cert file
> '/etc/ipsec.d/certs/fw.SERVER.DOMAIN-cert.pem' (2561 bytes)
> Nov 13 15:52:06 fw pluto[30413]: | certificate is valid
> Nov 13 15:52:06 fw pluto[30413]: | counting wild cards for C=SI,
> ST=Slovenia, L=Ljubljana, O=Delo Tiskarna, OU=IT, CN=fw.SERVER.DOMAIN,
> E=root at SERVER.DOMAIN is 0
> Nov 13 15:52:06 fw pluto[30413]: | counting wild cards for (none) is 15
> Nov 13 15:52:06 fw pluto[30413]: | based upon policy, the connection
> is a template.
> Nov 13 15:52:06 fw pluto[30413]: added connection description "rwmac-net"
> Nov 13 15:52:06 fw pluto[30413]: | SERVER.PUBLIC.IP[C=SI, ST=Slovenia,
> L=Ljubljana, O=Delo Tiskarna, OU=IT, CN=fw.SERVER.DOMAIN,
> E=root at SERVER.DOMAIN]:17/1701...%virtual:17/%any===?
> Nov 13 15:52:06 fw pluto[30413]: | ike_life: 3600s; ipsec_life: 3600s;
> rekey_margin: 540s; rekey_fuzz: 100%; keyingtries: 0; policy:
> RSASIG+ENCRYPT+TUNNEL+DONTREKEY
> Nov 13 15:52:06 fw pluto[30413]: | next event EVENT_SHUNT_SCAN in 119
> seconds
> Nov 13 15:52:07 fw pluto[30413]: |  
> Nov 13 15:52:07 fw pluto[30413]: | *received whack message
> Nov 13 15:52:07 fw pluto[30413]: | Added new connection rw-net with
> policy RSASIG+ENCRYPT+TUNNEL+DONTREKEY
> Nov 13 15:52:07 fw pluto[30413]:   loaded host cert file
> '/etc/ipsec.d/certs/fw.SERVER.DOMAIN-cert.pem' (2561 bytes)
> Nov 13 15:52:07 fw pluto[30413]: | certificate is valid
> Nov 13 15:52:07 fw pluto[30413]: | counting wild cards for C=SI,
> ST=Slovenia, L=Ljubljana, O=Delo Tiskarna, OU=IT, CN=fw.SERVER.DOMAIN,
> E=root at SERVER.DOMAIN is 0
> Nov 13 15:52:07 fw pluto[30413]: | counting wild cards for (none) is 15
> Nov 13 15:52:07 fw pluto[30413]: | based upon policy, the connection
> is a template.
> Nov 13 15:52:07 fw pluto[30413]: added connection description "rw-net"
> Nov 13 15:52:07 fw pluto[30413]: | SERVER.PUBLIC.IP[C=SI, ST=Slovenia,
> L=Ljubljana, O=Delo Tiskarna, OU=IT, CN=fw.SERVER.DOMAIN,
> E=root at SERVER.DOMAIN]:17/0...%virtual:17/1701===?
> Nov 13 15:52:07 fw pluto[30413]: | ike_life: 3600s; ipsec_life: 3600s;
> rekey_margin: 540s; rekey_fuzz: 100%; keyingtries: 0; policy:
> RSASIG+ENCRYPT+TUNNEL+DONTREKEY
> Nov 13 15:52:07 fw pluto[30413]: | next event EVENT_SHUNT_SCAN in 118
> seconds
> Nov 13 15:52:07 fw pluto[30413]: |  
> Nov 13 15:52:07 fw pluto[30413]: | *received whack message
> Nov 13 15:52:07 fw pluto[30413]: listening for IKE messages
> Nov 13 15:52:07 fw pluto[30413]: | found lo with address 127.0.0.1
> Nov 13 15:52:07 fw pluto[30413]: | found eth0 with address 192.168.10.1
> Nov 13 15:52:07 fw pluto[30413]: | found eth1 with address 192.168.1.1
> Nov 13 15:52:07 fw pluto[30413]: | found ppp0 with address
> SERVER.PUBLIC.IP
> Nov 13 15:52:07 fw pluto[30413]: | found ipsec0 with address
> SERVER.PUBLIC.IP
> Nov 13 15:52:07 fw pluto[30413]: adding interface ipsec0/ppp0
> SERVER.PUBLIC.IP:500
> Nov 13 15:52:07 fw pluto[30413]: adding interface ipsec0/ppp0
> SERVER.PUBLIC.IP:4500
> Nov 13 15:52:07 fw pluto[30413]: | IP interface eth1 192.168.1.1 has
> no matching ipsec* interface -- ignored
> Nov 13 15:52:07 fw pluto[30413]: | IP interface eth0 192.168.10.1 has
> no matching ipsec* interface -- ignored
> Nov 13 15:52:07 fw pluto[30413]: | IP interface lo 127.0.0.1 has no
> matching ipsec* interface -- ignored
> Nov 13 15:52:07 fw pluto[30413]: | could not open /proc/net/if_inet6
> Nov 13 15:52:07 fw pluto[30413]: loading secrets from "/etc/ipsec.secrets"
> Nov 13 15:52:07 fw pluto[30413]:   loaded private key file
> '/etc/ipsec.d/private/fw.SERVER.DOMAIN-key.pem' (3311 bytes)
> Nov 13 15:52:07 fw pluto[30413]: | loaded private key for keyid:
> PPK_RSA:AwEAAcLus
> Nov 13 15:52:07 fw pluto[30413]: | loaded private key for keyid:
> PPK_RSA:AQOQmchef
> Nov 13 15:52:07 fw pluto[30413]:   loaded private key file
> '/etc/ipsec.d/private/fw.SERVER.DOMAIN-key.pem' (3311 bytes)
> Nov 13 15:52:07 fw pluto[30413]: | loaded private key for keyid:
> PPK_RSA:AwEAAcLus
> Nov 13 15:52:07 fw pluto[30413]: | next event EVENT_SHUNT_SCAN in 118
> seconds
> Nov 13 15:52:14 fw pluto[30413]: |  
> Nov 13 15:52:14 fw pluto[30413]: | *received 160 bytes from
> CLIENT.PUBLIC.IP:2 on ppp0 (port=500)
> Nov 13 15:52:14 fw pluto[30413]: |  processing packet with exchange
> type=ISAKMP_XCHG_IDPROT (2)
> Nov 13 15:52:14 fw pluto[30413]: packet from CLIENT.PUBLIC.IP:2:
> received Vendor ID payload [RFC 3947] method set to=111
> Nov 13 15:52:14 fw pluto[30413]: packet from CLIENT.PUBLIC.IP:2:
> received Vendor ID payload [draft-ietf-ipsec-nat-t-ike] meth=110, but
> already using method 111
> Nov 13 15:52:14 fw pluto[30413]: packet from CLIENT.PUBLIC.IP:2:
> received Vendor ID payload [draft-ietf-ipsec-nat-t-ike-02] meth=107,
> but already using method 111
> Nov 13 15:52:14 fw pluto[30413]: packet from CLIENT.PUBLIC.IP:2:
> received Vendor ID payload [draft-ietf-ipsec-nat-t-ike-02_n] meth=106,
> but already using method 111
> Nov 13 15:52:14 fw pluto[30413]: | instantiated "rwmac-net" for
> CLIENT.PUBLIC.IP
> Nov 13 15:52:14 fw pluto[30413]: | creating state object #1 at 0x80f4588
> Nov 13 15:52:14 fw pluto[30413]: | processing connection rwmac-net[1]
> CLIENT.PUBLIC.IP
> Nov 13 15:52:14 fw pluto[30413]: | ICOOKIE:  f4 d7 49 f2  a3 13 a5 58
> Nov 13 15:52:14 fw pluto[30413]: | RCOOKIE:  68 31 bd 78  66 eb 2e e7
> Nov 13 15:52:14 fw pluto[30413]: | peer:  59 d4 41 21
> Nov 13 15:52:14 fw pluto[30413]: | state hash entry 16
> Nov 13 15:52:14 fw pluto[30413]: | inserting event EVENT_SO_DISCARD,
> timeout in 0 seconds for #1
> Nov 13 15:52:14 fw pluto[30413]: "rwmac-net"[1] CLIENT.PUBLIC.IP #1:
> responding to Main Mode from unknown peer CLIENT.PUBLIC.IP
> Nov 13 15:52:14 fw pluto[30413]: | complete state transition with STF_OK
> Nov 13 15:52:14 fw pluto[30413]: "rwmac-net"[1] CLIENT.PUBLIC.IP #1:
> transition from state STATE_MAIN_R0 to state STATE_MAIN_R1
> Nov 13 15:52:14 fw pluto[30413]: | sending reply packet to
> CLIENT.PUBLIC.IP:2 (from port=500)
> Nov 13 15:52:14 fw pluto[30413]: | sending 136 bytes for STATE_MAIN_R0
> through ppp0:500 to CLIENT.PUBLIC.IP:2:
> Nov 13 15:52:14 fw pluto[30413]: | inserting event EVENT_RETRANSMIT,
> timeout in 10 seconds for #1
> Nov 13 15:52:14 fw pluto[30413]: "rwmac-net"[1] CLIENT.PUBLIC.IP #1:
> STATE_MAIN_R1: sent MR1, expecting MI2
> Nov 13 15:52:14 fw pluto[30413]: | modecfg pull: noquirk policy:push
> not-client
> Nov 13 15:52:14 fw pluto[30413]: | phase 1 is done, looking for phase
> 1 to unpend
> Nov 13 15:52:14 fw pluto[30413]: | next event EVENT_RETRANSMIT in 10
> seconds for #1
> Nov 13 15:52:15 fw pluto[30413]: |  
> Nov 13 15:52:15 fw pluto[30413]: | *received 248 bytes from
> CLIENT.PUBLIC.IP:2 on ppp0 (port=500)
> Nov 13 15:52:15 fw pluto[30413]: |  processing packet with exchange
> type=ISAKMP_XCHG_IDPROT (2)
> Nov 13 15:52:15 fw pluto[30413]: | ICOOKIE:  f4 d7 49 f2  a3 13 a5 58
> Nov 13 15:52:15 fw pluto[30413]: | RCOOKIE:  68 31 bd 78  66 eb 2e e7
> Nov 13 15:52:15 fw pluto[30413]: | peer:  59 d4 41 21
> Nov 13 15:52:15 fw pluto[30413]: | state hash entry 16
> Nov 13 15:52:15 fw pluto[30413]: | peer and cookies match on #1,
> provided msgid 00000000 vs 00000000
> Nov 13 15:52:15 fw pluto[30413]: | state object #1 found, in STATE_MAIN_R1
> Nov 13 15:52:15 fw pluto[30413]: | processing connection rwmac-net[1]
> CLIENT.PUBLIC.IP
> Nov 13 15:52:15 fw pluto[30413]: "rwmac-net"[1] CLIENT.PUBLIC.IP #1:
> ignoring Vendor ID payload [KAME/racoon]
> Nov 13 15:52:15 fw pluto[30413]: "rwmac-net"[1] CLIENT.PUBLIC.IP #1:
> NAT-Traversal: Result using draft-ietf-ipsec-nat-t-ike (MacOS X): peer
> is NATed
> Nov 13 15:52:15 fw pluto[30413]: | inserting event
> EVENT_NAT_T_KEEPALIVE, timeout in 20 seconds
> Nov 13 15:52:15 fw pluto[30413]: | 0: w->pcw_dead: 0 w->pcw_work: 0 cnt: 1
> Nov 13 15:52:15 fw pluto[30413]: | asking helper 0 to do build_kenonce
> op on seq: 1
> Nov 13 15:52:15 fw pluto[30413]: | inserting event
> EVENT_CRYPTO_FAILED, timeout in 300 seconds for #1
> Nov 13 15:52:15 fw pluto[30413]: | complete state transition with
> STF_SUSPEND
> Nov 13 15:52:15 fw pluto[30413]: | next event EVENT_NAT_T_KEEPALIVE in
> 20 seconds
> Nov 13 15:52:15 fw pluto[30417]: ! helper 0 doing build_kenonce op id: 1
> Nov 13 15:52:15 fw pluto[30413]: | processing connection rwmac-net[1]
> CLIENT.PUBLIC.IP
> Nov 13 15:52:15 fw pluto[30413]: | started looking for secret for
> C=SI, ST=Slovenia, L=Ljubljana, O=Delo Tiskarna, OU=IT,
> CN=fw.SERVER.DOMAIN, E=root at SERVER.DOMAIN->CLIENT.PUBLIC.IP of kind
> PPK_PSK
> Nov 13 15:52:15 fw pluto[30413]: | instantiating him to 0.0.0.0
> Nov 13 15:52:15 fw pluto[30413]: | actually looking for secret for
> C=SI, ST=Slovenia, L=Ljubljana, O=Delo Tiskarna, OU=IT,
> CN=fw.SERVER.DOMAIN, E=root at SERVER.DOMAIN->0.0.0.0 of kind PPK_PSK
> Nov 13 15:52:15 fw pluto[30413]: | 1: compared PSK 213.229.192.66 to
> C=SI, ST=Slovenia, L=Ljubljana, O=Delo Tiskarna, OU=IT,
> CN=fw.SERVER.DOMAIN, E=root at SERVER.DOMAIN / CLIENT.PUBLIC.IP -> 0
> Nov 13 15:52:15 fw pluto[30413]: | 2: compared PSK SERVER.PUBLIC.IP to
> C=SI, ST=Slovenia, L=Ljubljana, O=Delo Tiskarna, OU=IT,
> CN=fw.SERVER.DOMAIN, E=root at SERVER.DOMAIN / CLIENT.PUBLIC.IP -> 0
> Nov 13 15:52:15 fw pluto[30413]: | concluding with best_match=0
> best=(nil) (lineno=-1)
> Nov 13 15:52:15 fw pluto[30413]: | complete state transition with STF_OK
> Nov 13 15:52:15 fw pluto[30413]: "rwmac-net"[1] CLIENT.PUBLIC.IP #1:
> transition from state STATE_MAIN_R1 to state STATE_MAIN_R2
> Nov 13 15:52:15 fw pluto[30413]: | sending reply packet to
> CLIENT.PUBLIC.IP:2 (from port=500)
> Nov 13 15:52:15 fw pluto[30413]: | sending 228 bytes for STATE_MAIN_R1
> through ppp0:500 to CLIENT.PUBLIC.IP:2:
> Nov 13 15:52:15 fw pluto[30413]: | inserting event EVENT_RETRANSMIT,
> timeout in 10 seconds for #1
> Nov 13 15:52:15 fw pluto[30413]: "rwmac-net"[1] CLIENT.PUBLIC.IP #1:
> STATE_MAIN_R2: sent MR2, expecting MI3
> Nov 13 15:52:15 fw pluto[30413]: | modecfg pull: noquirk policy:push
> not-client
> Nov 13 15:52:15 fw pluto[30413]: | phase 1 is done, looking for phase
> 1 to unpend
> Nov 13 15:52:15 fw pluto[30413]: | next event EVENT_RETRANSMIT in 10
> seconds for #1
> Nov 13 15:52:15 fw pluto[30413]: |  
> Nov 13 15:52:15 fw pluto[30413]: | *received 1820 bytes from
> CLIENT.PUBLIC.IP:4500 on ppp0 (port=4500)
> Nov 13 15:52:15 fw pluto[30413]: |  processing packet with exchange
> type=ISAKMP_XCHG_IDPROT (2)
> Nov 13 15:52:15 fw pluto[30413]: | ICOOKIE:  f4 d7 49 f2  a3 13 a5 58
> Nov 13 15:52:15 fw pluto[30413]: | RCOOKIE:  68 31 bd 78  66 eb 2e e7
> Nov 13 15:52:15 fw pluto[30413]: | peer:  59 d4 41 21
> Nov 13 15:52:15 fw pluto[30413]: | state hash entry 16
> Nov 13 15:52:15 fw pluto[30413]: | peer and cookies match on #1,
> provided msgid 00000000 vs 00000000
> Nov 13 15:52:15 fw pluto[30413]: | state object #1 found, in STATE_MAIN_R2
> Nov 13 15:52:15 fw pluto[30413]: | processing connection rwmac-net[1]
> CLIENT.PUBLIC.IP
> Nov 13 15:52:15 fw pluto[30413]: "rwmac-net"[1] CLIENT.PUBLIC.IP #1:
> Main mode peer ID is ID_DER_ASN1_DN: 'C=SI, ST=Slovenia, L=Ljubljana,
> O=Delo Tiskarna, OU=IT, CN=Sebastijan Silec,
> E=sebastijan.silec at CLIENT.DOMAIN'
> Nov 13 15:52:15 fw pluto[30413]: | reached self-signed root ca
> Nov 13 15:52:15 fw pluto[30413]: | requested CA: '%any'
> Nov 13 15:52:15 fw pluto[30413]: | started looking for secret for
> C=SI, ST=Slovenia, L=Ljubljana, O=Delo Tiskarna, OU=IT,
> CN=fw.SERVER.DOMAIN, E=root at SERVER.DOMAIN->(none) of kind PPK_RSA
> Nov 13 15:52:15 fw pluto[30413]: | searching for certificate
> PPK_PSK:N/A vs PPK_RSA:AwEAAcLus
> Nov 13 15:52:15 fw pluto[30413]: | searching for certificate
> PPK_RSA:AwEAAcLus vs PPK_RSA:AwEAAcLus
> Nov 13 15:52:15 fw pluto[30413]: | started looking for secret for
> C=SI, ST=Slovenia, L=Ljubljana, O=Delo Tiskarna, OU=IT,
> CN=fw.SERVER.DOMAIN, E=root at SERVER.DOMAIN->(none) of kind PPK_RSA
> Nov 13 15:52:15 fw pluto[30413]: | searching for certificate
> PPK_PSK:N/A vs PPK_RSA:AwEAAcLus
> Nov 13 15:52:15 fw pluto[30413]: | searching for certificate
> PPK_RSA:AwEAAcLus vs PPK_RSA:AwEAAcLus
> Nov 13 15:52:15 fw pluto[30413]: | offered CA: 'C=SI, ST=Slovenia,
> L=Ljubljana, O=Delo Tiskarna, OU=IT, CN=DELOTISKARNACA,
> E=ca at SERVER.DOMAIN'
> Nov 13 15:52:15 fw pluto[30413]: "rwmac-net"[1] CLIENT.PUBLIC.IP #1:
> switched from "rwmac-net" to "rwmac-net"
> Nov 13 15:52:15 fw pluto[30413]: | instantiated "rwmac-net" for
> CLIENT.PUBLIC.IP
> Nov 13 15:52:15 fw pluto[30413]: | processing connection rwmac-net[2]
> CLIENT.PUBLIC.IP
> Nov 13 15:52:15 fw pluto[30413]: | processing connection rwmac-net[1]
> CLIENT.PUBLIC.IP
> Nov 13 15:52:15 fw pluto[30413]: "rwmac-net"[2] CLIENT.PUBLIC.IP #1:
> deleting connection "rwmac-net" instance with peer CLIENT.PUBLIC.IP
> {isakmp=#0/ipsec=#0}
> Nov 13 15:52:15 fw pluto[30413]: | required CA is '%any'
> Nov 13 15:52:15 fw pluto[30413]: | key issuer CA is 'C=SI,
> ST=Slovenia, L=Ljubljana, O=Delo Tiskarna, OU=IT, CN=DELOTISKARNACA,
> E=ca at SERVER.DOMAIN'
> Nov 13 15:52:15 fw pluto[30413]: | an RSA Sig check passed with
> *AwEAAbx7O [preloaded key]
> Nov 13 15:52:15 fw pluto[30413]: | thinking about whether to send my
> certificate:
> Nov 13 15:52:15 fw pluto[30413]: |   I have RSA key: OAKLEY_RSA_SIG
> cert.type: CERT_X509_SIGNATURE
> Nov 13 15:52:15 fw pluto[30413]: |   sendcert: CERT_ALWAYSSEND and I
> did not get a certificate request
> Nov 13 15:52:15 fw pluto[30413]: |   so send cert.
> Nov 13 15:52:15 fw pluto[30413]: "rwmac-net"[2] CLIENT.PUBLIC.IP #1: I
> am sending my cert
> Nov 13 15:52:15 fw pluto[30413]: | started looking for secret for
> C=SI, ST=Slovenia, L=Ljubljana, O=Delo Tiskarna, OU=IT,
> CN=fw.SERVER.DOMAIN, E=root at SERVER.DOMAIN->C=SI, ST=Slovenia,
> L=Ljubljana, O=Delo Tiskarna, OU=IT, CN=Sebastijan Silec,
> E=sebastijan.silec at CLIENT.DOMAIN of kind PPK_RSA
> Nov 13 15:52:15 fw pluto[30413]: | searching for certificate
> PPK_PSK:N/A vs PPK_RSA:AwEAAcLus
> Nov 13 15:52:15 fw pluto[30413]: | searching for certificate
> PPK_RSA:AwEAAcLus vs PPK_RSA:AwEAAcLus
> Nov 13 15:52:15 fw pluto[30413]: | signing hash with RSA Key *AwEAAcLus
> Nov 13 15:52:16 fw pluto[30413]: | complete state transition with STF_OK
> Nov 13 15:52:16 fw pluto[30413]: "rwmac-net"[2] CLIENT.PUBLIC.IP #1:
> transition from state STATE_MAIN_R2 to state STATE_MAIN_R3
> Nov 13 15:52:16 fw pluto[30413]: | sending reply packet to
> CLIENT.PUBLIC.IP:2 (from port=500)
> Nov 13 15:52:16 fw pluto[30413]: | processing connection rwmac-net[2]
> CLIENT.PUBLIC.IP
> Nov 13 15:52:16 fw pluto[30413]: | sending 2572 bytes for
> STATE_MAIN_R2 through ppp0:4500 to CLIENT.PUBLIC.IP:4500:
> Nov 13 15:52:16 fw pluto[30413]: | inserting event EVENT_SA_EXPIRE,
> timeout in 3600 seconds for #1
> Nov 13 15:52:16 fw pluto[30413]: "rwmac-net"[2] CLIENT.PUBLIC.IP #1:
> STATE_MAIN_R3: sent MR3, ISAKMP SA established {auth=OAKLEY_RSA_SIG
> cipher=oakley_3des_cbc_192 prf=oakley_sha group=modp1024}
> Nov 13 15:52:16 fw pluto[30413]: | modecfg pull: noquirk policy:push
> not-client
> Nov 13 15:52:16 fw pluto[30413]: | phase 1 is done, looking for phase
> 1 to unpend
> Nov 13 15:52:16 fw pluto[30413]: | next event EVENT_NAT_T_KEEPALIVE in
> 19 seconds
> Nov 13 15:52:17 fw pluto[30413]: |  
> Nov 13 15:52:17 fw pluto[30413]: | *received 252 bytes from
> CLIENT.PUBLIC.IP:4500 on ppp0 (port=4500)
> Nov 13 15:52:17 fw pluto[30413]: |  processing packet with exchange
> type=ISAKMP_XCHG_QUICK (32)
> Nov 13 15:52:17 fw pluto[30413]: | ICOOKIE:  f4 d7 49 f2  a3 13 a5 58
> Nov 13 15:52:17 fw pluto[30413]: | RCOOKIE:  68 31 bd 78  66 eb 2e e7
> Nov 13 15:52:17 fw pluto[30413]: | peer:  59 d4 41 21
> Nov 13 15:52:17 fw pluto[30413]: | state hash entry 16
> Nov 13 15:52:17 fw pluto[30413]: | peer and cookies match on #1,
> provided msgid eadf6de2 vs 00000000
> Nov 13 15:52:17 fw pluto[30413]: | state object not found
> Nov 13 15:52:17 fw pluto[30413]: | ICOOKIE:  f4 d7 49 f2  a3 13 a5 58
> Nov 13 15:52:17 fw pluto[30413]: | RCOOKIE:  68 31 bd 78  66 eb 2e e7
> Nov 13 15:52:17 fw pluto[30413]: | peer:  59 d4 41 21
> Nov 13 15:52:17 fw pluto[30413]: | state hash entry 16
> Nov 13 15:52:17 fw pluto[30413]: | peer and cookies match on #1,
> provided msgid 00000000 vs 00000000
> Nov 13 15:52:17 fw pluto[30413]: | state object #1 found, in STATE_MAIN_R3
> Nov 13 15:52:17 fw pluto[30413]: | processing connection rwmac-net[2]
> CLIENT.PUBLIC.IP
> Nov 13 15:52:17 fw pluto[30413]: | peer client is 172.16.0.106
> Nov 13 15:52:17 fw pluto[30413]: | peer client protocol/port is 17/49269
> Nov 13 15:52:17 fw pluto[30413]: | our client is SERVER.PUBLIC.IP
> Nov 13 15:52:17 fw pluto[30413]: | our client protocol/port is 17/1701
> Nov 13 15:52:17 fw pluto[30413]: "rwmac-net"[2] CLIENT.PUBLIC.IP #1:
> cannot respond to IPsec SA request because no connection is known for
> SERVER.PUBLIC.IP[C=SI, ST=Slovenia, L=Ljubljana, O=Delo Tiskarna,
> OU=IT, CN=fw.SERVER.DOMAIN,
> E=root at SERVER.DOMAIN]:17/1701...CLIENT.PUBLIC.IP[C=SI, ST=Slovenia,
> L=Ljubljana, O=Delo Tiskarna, OU=IT, CN=Sebastijan Silec,
> E=sebastijan.silec at CLIENT.DOMAIN]:17/%any===172.16.0.106/32
> Nov 13 15:52:17 fw pluto[30413]: | complete state transition with (null)
> Nov 13 15:52:17 fw pluto[30413]: "rwmac-net"[2] CLIENT.PUBLIC.IP #1:
> sending encrypted notification INVALID_ID_INFORMATION to
> CLIENT.PUBLIC.IP:4500
> Nov 13 15:52:17 fw pluto[30413]: | sending 68 bytes for notification
> packet through ppp0:4500 to CLIENT.PUBLIC.IP:4500:
> Nov 13 15:52:17 fw pluto[30413]: | state transition function for
> STATE_QUICK_R0 failed: INVALID_ID_INFORMATION
> Nov 13 15:52:17 fw pluto[30413]: | next event EVENT_NAT_T_KEEPALIVE in
> 18 seconds
> Nov 13 15:52:19 fw crond[30501]: (root) CMD (/etc/scripts/check_link)
> Nov 13 15:52:20 fw pluto[30413]: |  
> Nov 13 15:52:20 fw pluto[30413]: | *received 252 bytes from
> CLIENT.PUBLIC.IP:4500 on ppp0 (port=4500)
> Nov 13 15:52:20 fw pluto[30413]: |  processing packet with exchange
> type=ISAKMP_XCHG_QUICK (32)
> Nov 13 15:52:20 fw pluto[30413]: | ICOOKIE:  f4 d7 49 f2  a3 13 a5 58
> Nov 13 15:52:20 fw pluto[30413]: | RCOOKIE:  68 31 bd 78  66 eb 2e e7
> Nov 13 15:52:20 fw pluto[30413]: | peer:  59 d4 41 21
> Nov 13 15:52:20 fw pluto[30413]: | state hash entry 16
> Nov 13 15:52:20 fw pluto[30413]: | peer and cookies match on #1,
> provided msgid eadf6de2 vs 00000000
> Nov 13 15:52:20 fw pluto[30413]: | state object not found
> Nov 13 15:52:20 fw pluto[30413]: | ICOOKIE:  f4 d7 49 f2  a3 13 a5 58
> Nov 13 15:52:20 fw pluto[30413]: | RCOOKIE:  68 31 bd 78  66 eb 2e e7
> Nov 13 15:52:20 fw pluto[30413]: | peer:  59 d4 41 21
> Nov 13 15:52:20 fw pluto[30413]: | state hash entry 16
> Nov 13 15:52:20 fw pluto[30413]: | peer and cookies match on #1,
> provided msgid 00000000 vs 00000000
> Nov 13 15:52:20 fw pluto[30413]: | state object #1 found, in STATE_MAIN_R3
> Nov 13 15:52:20 fw pluto[30413]: | processing connection rwmac-net[2]
> CLIENT.PUBLIC.IP
> Nov 13 15:52:20 fw pluto[30413]: "rwmac-net"[2] CLIENT.PUBLIC.IP #1:
> Quick Mode I1 message is unacceptable because it uses a previously
> used Message ID 0xe26ddfea (perhaps this is a duplicated packet)
> Nov 13 15:52:20 fw pluto[30413]: "rwmac-net"[2] CLIENT.PUBLIC.IP #1:
> sending encrypted notification INVALID_MESSAGE_ID to CLIENT.PUBLIC.IP:4500
> Nov 13 15:52:20 fw pluto[30413]: | sending 68 bytes for notification
> packet through ppp0:4500 to CLIENT.PUBLIC.IP:4500:
> Nov 13 15:52:20 fw pluto[30413]: | next event EVENT_NAT_T_KEEPALIVE in
> 14 seconds
> Nov 13 15:52:23 fw pluto[30413]: |  
> Nov 13 15:52:23 fw pluto[30413]: | *received 252 bytes from
> CLIENT.PUBLIC.IP:4500 on ppp0 (port=4500)
> Nov 13 15:52:23 fw pluto[30413]: |  processing packet with exchange
> type=ISAKMP_XCHG_QUICK (32)
> Nov 13 15:52:23 fw pluto[30413]: | ICOOKIE:  f4 d7 49 f2  a3 13 a5 58
> Nov 13 15:52:23 fw pluto[30413]: | RCOOKIE:  68 31 bd 78  66 eb 2e e7
> Nov 13 15:52:23 fw pluto[30413]: | peer:  59 d4 41 21
> Nov 13 15:52:23 fw pluto[30413]: | state hash entry 16
> Nov 13 15:52:23 fw pluto[30413]: | peer and cookies match on #1,
> provided msgid eadf6de2 vs 00000000
> Nov 13 15:52:23 fw pluto[30413]: | state object not found
> Nov 13 15:52:23 fw pluto[30413]: | ICOOKIE:  f4 d7 49 f2  a3 13 a5 58
> Nov 13 15:52:23 fw pluto[30413]: | RCOOKIE:  68 31 bd 78  66 eb 2e e7
> Nov 13 15:52:23 fw pluto[30413]: | peer:  59 d4 41 21
> Nov 13 15:52:23 fw pluto[30413]: | state hash entry 16
> Nov 13 15:52:23 fw pluto[30413]: | peer and cookies match on #1,
> provided msgid 00000000 vs 00000000
> Nov 13 15:52:23 fw pluto[30413]: | state object #1 found, in STATE_MAIN_R3
> Nov 13 15:52:23 fw pluto[30413]: | processing connection rwmac-net[2]
> CLIENT.PUBLIC.IP
> Nov 13 15:52:23 fw pluto[30413]: "rwmac-net"[2] CLIENT.PUBLIC.IP #1:
> Quick Mode I1 message is unacceptable because it uses a previously
> used Message ID 0xe26ddfea (perhaps this is a duplicated packet)
> Nov 13 15:52:23 fw pluto[30413]: "rwmac-net"[2] CLIENT.PUBLIC.IP #1:
> sending encrypted notification INVALID_MESSAGE_ID to CLIENT.PUBLIC.IP:4500
> Nov 13 15:52:23 fw pluto[30413]: | sending 68 bytes for notification
> packet through ppp0:4500 to CLIENT.PUBLIC.IP:4500:
> Nov 13 15:52:23 fw pluto[30413]: | next event EVENT_NAT_T_KEEPALIVE in
> 12 seconds
> Nov 13 15:52:24 fw logger: Network: ADSL OK...
> Nov 13 15:52:26 fw pluto[30413]: |  
> Nov 13 15:52:26 fw pluto[30413]: | *received 252 bytes from
> CLIENT.PUBLIC.IP:4500 on ppp0 (port=4500)
> Nov 13 15:52:26 fw pluto[30413]: |  processing packet with exchange
> type=ISAKMP_XCHG_QUICK (32)
> Nov 13 15:52:26 fw pluto[30413]: | ICOOKIE:  f4 d7 49 f2  a3 13 a5 58
> Nov 13 15:52:26 fw pluto[30413]: | RCOOKIE:  68 31 bd 78  66 eb 2e e7
> Nov 13 15:52:26 fw pluto[30413]: | peer:  59 d4 41 21
> Nov 13 15:52:26 fw pluto[30413]: | state hash entry 16
> Nov 13 15:52:26 fw pluto[30413]: | peer and cookies match on #1,
> provided msgid eadf6de2 vs 00000000
> Nov 13 15:52:26 fw pluto[30413]: | state object not found
> Nov 13 15:52:26 fw pluto[30413]: | ICOOKIE:  f4 d7 49 f2  a3 13 a5 58
> Nov 13 15:52:26 fw pluto[30413]: | RCOOKIE:  68 31 bd 78  66 eb 2e e7
> Nov 13 15:52:26 fw pluto[30413]: | peer:  59 d4 41 21
> Nov 13 15:52:26 fw pluto[30413]: | state hash entry 16
> Nov 13 15:52:26 fw pluto[30413]: | peer and cookies match on #1,
> provided msgid 00000000 vs 00000000
> Nov 13 15:52:26 fw pluto[30413]: | state object #1 found, in STATE_MAIN_R3
> Nov 13 15:52:26 fw pluto[30413]: | processing connection rwmac-net[2]
> CLIENT.PUBLIC.IP
> Nov 13 15:52:26 fw pluto[30413]: "rwmac-net"[2] CLIENT.PUBLIC.IP #1:
> Quick Mode I1 message is unacceptable because it uses a previously
> used Message ID 0xe26ddfea (perhaps this is a duplicated packet)
> Nov 13 15:52:26 fw pluto[30413]: "rwmac-net"[2] CLIENT.PUBLIC.IP #1:
> sending encrypted notification INVALID_MESSAGE_ID to CLIENT.PUBLIC.IP:4500
> Nov 13 15:52:26 fw pluto[30413]: | sending 68 bytes for notification
> packet through ppp0:4500 to CLIENT.PUBLIC.IP:4500:
> Nov 13 15:52:26 fw pluto[30413]: | next event EVENT_NAT_T_KEEPALIVE in
> 9 seconds
> Nov 13 15:52:28 fw ipsec_setup: Stopping Openswan IPsec...
> Nov 13 15:52:28 fw pluto[30413]: |  
> Nov 13 15:52:28 fw pluto[30413]: | *received whack message
> Nov 13 15:52:28 fw pluto[30413]: shutting down
> Nov 13 15:52:28 fw pluto[30413]: forgetting secrets
> Nov 13 15:52:28 fw pluto[30413]: | processing connection rwmac-net[2]
> CLIENT.PUBLIC.IP
> Nov 13 15:52:28 fw pluto[30413]: "rwmac-net"[2] CLIENT.PUBLIC.IP:
> deleting connection "rwmac-net" instance with peer CLIENT.PUBLIC.IP
> {isakmp=#1/ipsec=#0}
> Nov 13 15:52:28 fw pluto[30413]: | processing connection rwmac-net
> Nov 13 15:52:28 fw pluto[30413]: "rwmac-net" #1: deleting state
> (STATE_MAIN_R3)
> Nov 13 15:52:28 fw pluto[30413]: | deleting state #1
> Nov 13 15:52:28 fw pluto[30413]: | processing connection rwmac-net
> Nov 13 15:52:28 fw pluto[30413]: | sending 84 bytes for delete notify
> through ppp0:4500 to CLIENT.PUBLIC.IP:4500:
> Nov 13 15:52:28 fw pluto[30413]: | ICOOKIE:  f4 d7 49 f2  a3 13 a5 58
> Nov 13 15:52:28 fw pluto[30413]: | RCOOKIE:  68 31 bd 78  66 eb 2e e7
> Nov 13 15:52:28 fw pluto[30413]: | peer:  59 d4 41 21
> Nov 13 15:52:28 fw pluto[30413]: | state hash entry 16
> Nov 13 15:52:28 fw pluto[30413]: | processing connection rw-net
> Nov 13 15:52:28 fw pluto[30413]: "rw-net": deleting connection
> Nov 13 15:52:28 fw pluto[30413]: | processing connection rwmac-net
> Nov 13 15:52:28 fw pluto[30413]: "rwmac-net": deleting connection
> Nov 13 15:52:28 fw pluto[30413]: shutting down interface ipsec0/ppp0
> SERVER.PUBLIC.IP:4500
> Nov 13 15:52:28 fw pluto[30413]: shutting down interface ipsec0/ppp0
> SERVER.PUBLIC.IP:500
> Nov 13 15:52:29 fw kernel: IPSEC EVENT: KLIPS device ipsec0 shut down.
> Nov 13 15:52:29 fw kernel:
> Nov 13 15:52:29 fw kernel:
> Nov 13 15:52:29 fw kernel: klips_info:pfkey_cleanup: shutting down
> PF_KEY domain sockets.
> Nov 13 15:52:29 fw kernel: klips_info:cleanup_module: ipsec module
> unloaded.
> Nov 13 15:52:29 fw ipsec_setup: ...Openswan IPsec stopped

Can anyone shed some light on the topic?


 Thanks, Danilo

-------------- next part --------------
A non-text attachment was scrubbed...
Name: danilo.godec.vcf
Type: text/x-vcard
Size: 302 bytes
Desc: not available
Url : http://lists.openswan.org/pipermail/users/attachments/20071114/9293170d/attachment-0001.vcf 


More information about the Users mailing list