[Openswan Users] Tunnel negotiation fails after dynamic IP changes, with NAT-T

Gonçalo Cruz goncalo at mrna.ist.utl.pt
Sat Oct 24 10:21:46 EDT 2009


Hello. I'm using OpenSwan to to build VPN tunnels from several small 
networks to a linux server on a central location. The linux server to 
which these small networks connect to is an Opensuse 11.0 with Openswan 
2.4.7-130.2. It has a static public IP address. I'll simply call it the 
"server" below.

Each separate network has several data collection equipment behind a linux 
gateway (OpenSuse 11.1 x86, OpenSwan 2.6.16-1.49.3). The existing offers 
from local ISPs force me to use ADSL routers with dynamic public IP 
addresses for those small networks. Those routers must do NAT (I cannot 
disable that), and the linux gateway has a private IP address. The NAT 
part is not a problem, as NAT-T works and a tunnel can be established. The 
dymanic address part, however, is is causing me some headaches, and the 
reason why I'm now asking for help.

Whenever the dynamic public IP on the ADSL gateway changes, the IPSec SA 
for the tunnel is torn down, as I'd expect. But all following attempts at 
renegotiating a new one fail. I'm not familiar with the details of the 
IPSec negotiation, but what I see is that after the step "STATE_MAIN_R2: 
sent MR2, expecting MI" the process simply does not advance.
I have noticed that a new tunnel can only be estabelished after the ipsec 
service is restarted in the systems on both ends of the tunnel (the 
"server" and the "gateway", as I've been calling them).
While I can write a script to force the restart of the ipsec service when 
a connection is lost, that causes some very inconvenient data losses for a 
few seconds. Can the tunnel be reestablished after these IP changes 
without a need to restart the IPSec service?

I'm using the options below for the connections (in the linux server):

config setup
     nat_traversal=yes
     virtual_private=%v4:10.0.0.0/8,%v4:!10.10.10.0/24
     strictcrlpolicy=yes
     plutowait=yes
     nhelpers=0
     protostack=netkey
conn %default
     leftrsasigkey=%cert
     rightrsasigkey=%cert
include /etc/ipsec.d/examples/no_oe.conf
conn porto
     authby=rsasig
     type=tunnel
     rekey=no
     #auto=ignore
     auto=add
     pfs=no
     ike=3des-sha1
     esp=3des-sha1
     ikelifetime=240m
     keylife=60m
     #aggrmode yes causes crash in pluto...
     aggrmode=no
     dpddelay=30
     dpdtimeout=120
     dpdaction=clear
     left=%defaultroute
     leftsubnet=10.10.10.0/24
     leftsourceip=10.10.10.2
     leftcert=lisboa.pem
     right=%any
     rightcert=palmela.pem
     rightsubnet=10.10.11.0/24

For the "porto" connection, the corresponding gateway has:

conn porto
     authby=rsasig
     type=tunnel
     rekey=yes
     #auto=ignore
     auto=start
     pfs=no
     ike=3des-sha1
     esp=3des-sha1
     ikelifetime=240m
     keylife=60m
     aggrmode=no
     dpddelay=30
     dpdtimeout=120
     dpdaction=clear
     left=%defaultroute
     leftsubnet=10.10.11.0/24
     leftsourceip=10.10.11.1
     leftcert=palmela.pem
     right=[SERVER_PUBLIC_IP]
     rightid="[CERTIFICATE_DETAILS]"
     rightcert=lisboa.pem
     rightsubnet=10.10.10.0/24


Below are the logs from the "server", for the different circumstances. I 
must note that I'm restarting the IPSec service on the linux gateways once 
every hour already, due to some occasional failures with the renegotiation 
of the SAs when the keylife expired, so the gateways' logs are not very 
useful.

Successful connection from "client" behind a nat gateway with 
[GATEWAY_IP], to "server" with [PUBLIC_IP]:

Oct 20 11:28:04 sismo01 pluto[9499]: "porto"[646] [GATEWAY_IP] #23668: 
received Delete SA payload: deleting ISAKMP State #23668
Oct 20 11:28:04 sismo01 pluto[9499]: "porto"[646] [GATEWAY_IP]: deleting 
connection "porto" instance with peer [GATEWAY_IP] {isakmp=#0/ipsec=#0}
Oct 20 11:28:04 sismo01 pluto[9499]: packet from [GATEWAY_IP]:4500: 
received and ignored informational message
Oct 20 11:28:08 sismo01 pluto[9499]: packet from [GATEWAY_IP]:500: 
ignoring unknown Vendor ID payload [4f456a7d637357765a5c7b63]
Oct 20 11:28:08 sismo01 pluto[9499]: packet from [GATEWAY_IP]:500: 
received Vendor ID payload [Dead Peer Detection]
Oct 20 11:28:08 sismo01 pluto[9499]: packet from [GATEWAY_IP]:500: 
received Vendor ID payload [RFC 3947] method set to=110
Oct 20 11:28:08 sismo01 pluto[9499]: packet from [GATEWAY_IP]:500: 
received Vendor ID payload [draft-ietf-ipsec-nat-t-ike-03] meth=108, but 
already using method 110
Oct 20 11:28:08 sismo01 pluto[9499]: packet from [GATEWAY_IP]:500: 
received Vendor ID payload [draft-ietf-ipsec-nat-t-ike-02_n] meth=106, but 
already using method 110
Oct 20 11:28:08 sismo01 pluto[9499]: packet from [GATEWAY_IP]:500: 
received Vendor ID payload [draft-ietf-ipsec-nat-t-ike-02] meth=107, but 
already using method 110
Oct 20 11:28:08 sismo01 pluto[9499]: "porto"[647] [GATEWAY_IP] #23670: 
responding to Main Mode from unknown peer [GATEWAY_IP]
Oct 20 11:28:08 sismo01 pluto[9499]: "porto"[647] [GATEWAY_IP] #23670: 
transition from state STATE_MAIN_R0 to state STATE_MAIN_R1
Oct 20 11:28:24 sismo01 pluto[9499]: "porto"[647] [GATEWAY_IP] #23670: 
STATE_MAIN_R1: sent MR1, expecting MI2
Oct 20 11:28:24 sismo01 pluto[9499]: packet from [GATEWAY_IP]:500: 
ignoring unknown Vendor ID payload [4f456a7d637357765a5c7b63]
Oct 20 11:28:24 sismo01 pluto[9499]: packet from [GATEWAY_IP]:500: 
received Vendor ID payload [Dead Peer Detection]
Oct 20 11:28:24 sismo01 pluto[9499]: packet from [GATEWAY_IP]:500: 
received Vendor ID payload [RFC 3947] method set to=110
Oct 20 11:28:24 sismo01 pluto[9499]: packet from [GATEWAY_IP]:500: 
received Vendor ID payload [draft-ietf-ipsec-nat-t-ike-03] meth=108, but 
already using method 110
Oct 20 11:28:24 sismo01 pluto[9499]: packet from [GATEWAY_IP]:500: 
received Vendor ID payload [draft-ietf-ipsec-nat-t-ike-02_n] meth=106, but 
already using method 110
Oct 20 11:28:24 sismo01 pluto[9499]: packet from [GATEWAY_IP]:500: 
received Vendor ID payload [draft-ietf-ipsec-nat-t-ike-02] meth=107, but 
already using method 110
Oct 20 11:28:24 sismo01 pluto[9499]: "porto"[647] [GATEWAY_IP] #23671: 
responding to Main Mode from unknown peer [GATEWAY_IP]
Oct 20 11:28:24 sismo01 pluto[9499]: "porto"[647] [GATEWAY_IP] #23671: 
transition from state STATE_MAIN_R0 to state STATE_MAIN_R1
Oct 20 11:28:24 sismo01 pluto[9499]: "porto"[647] [GATEWAY_IP] #23671: 
STATE_MAIN_R1: sent MR1, expecting MI2
Oct 20 11:28:24 sismo01 pluto[9499]: "porto"[647] [GATEWAY_IP] #23670: 
NAT-Traversal: Result using RFC 3947 (NAT-Traversal): peer is NATed
Oct 20 11:28:24 sismo01 pluto[9499]: "porto"[647] [GATEWAY_IP] #23670: 
transition from state STATE_MAIN_R1 to state STATE_MAIN_R2
Oct 20 11:28:24 sismo01 pluto[9499]: "porto"[647] [GATEWAY_IP] #23670: 
STATE_MAIN_R2: sent MR2, expecting MI3
Oct 20 11:28:24 sismo01 pluto[9499]: "porto"[647] [GATEWAY_IP] #23670: 
Main mode peer ID is ID_DER_ASN1_DN: '[CERTIFICATE_DETAILS]'
Oct 20 11:28:24 sismo01 pluto[9499]: "porto"[647] [GATEWAY_IP] #23670: I 
am sending my cert
Oct 20 11:28:24 sismo01 pluto[9499]: "porto"[647] [GATEWAY_IP] #23670: 
transition from state STATE_MAIN_R2 to state STATE_MAIN_R3
Oct 20 11:28:24 sismo01 pluto[9499]: | NAT-T: new mapping 
[GATEWAY_IP]:500/4500)
Oct 20 11:28:24 sismo01 pluto[9499]: "porto"[647] [GATEWAY_IP] #23670: 
STATE_MAIN_R3: sent MR3, ISAKMP SA established {auth=OAKLEY_RSA_SIG 
cipher=oakley_3des_cbc_192 prf=oakley_sha group=modp1536}
Oct 20 11:28:24 sismo01 pluto[9499]: "porto"[647] [GATEWAY_IP] #23670: 
Dead Peer Detection (RFC 3706): enabled
Oct 20 11:28:24 sismo01 pluto[9499]: "porto"[647] [GATEWAY_IP] #23672: 
responding to Quick Mode {msgid:42109be0}
Oct 20 11:28:24 sismo01 pluto[9499]: "porto"[647] [GATEWAY_IP] #23672: 
transition from state STATE_QUICK_R0 to state STATE_QUICK_R1
Oct 20 11:28:24 sismo01 pluto[9499]: "porto"[647] [GATEWAY_IP] #23672: 
STATE_QUICK_R1: sent QR1, inbound IPsec SA installed, expecting QI2
Oct 20 11:28:43 sismo01 pluto[9499]: "porto"[647] [GATEWAY_IP] #23672: 
Dead Peer Detection (RFC 3706): enabled
Oct 20 11:28:43 sismo01 pluto[9499]: "porto"[647] [GATEWAY_IP] #23672: 
transition from state STATE_QUICK_R1 to state STATE_QUICK_R2
Oct 20 11:28:43 sismo01 pluto[9499]: "porto"[647] [GATEWAY_IP] #23672: 
STATE_QUICK_R2: IPsec SA established {ESP=>0x77ab2433 <0x7ce05656 
xfrm=3DES_0-HMAC_SHA1 NATD=[GATEWAY_IP]:4500 DPD=enabled}
Oct 20 11:28:43 sismo01 pluto[9499]: "porto"[647] [GATEWAY_IP] #23672: 
discarding duplicate packet; already STATE_QUICK_R2
Oct 20 11:29:43 sismo01 pluto[9499]: "porto"[647] [GATEWAY_IP] #23671: max 
number of retransmissions (2) reached STATE_MAIN_R1

After [GATEWAY_IP] changes to [GATEWAY_IP_NEW], new attempts at 
estabelishing a tunnel fail:

Oct 20 12:15:25 sismo01 pluto[9499]: "porto"[647] [GATEWAY_IP] #23670: 
DPD: Info: No response from peer - declaring peer dead
Oct 20 12:15:25 sismo01 pluto[9499]: "porto"[647] [GATEWAY_IP] #23670: 
DPD: Info: Putting connection into %trap
Oct 20 12:15:25 sismo01 pluto[9499]: "porto" #23672: deleting state 
(STATE_QUICK_R2)
Oct 20 12:15:25 sismo01 pluto[9499]: "porto" #23670: deleting state 
(STATE_MAIN_R3)
Oct 20 12:15:25 sismo01 pluto[9499]: "porto"[647] [GATEWAY_IP]: deleting 
connection "porto" instance with peer [GATEWAY_IP] {isakmp=#0/ipsec=#0}
Oct 20 12:28:09 sismo01 pluto[9499]: packet from [GATEWAY_IP_NEW]:500: 
ignoring unknown Vendor ID payload [4f456a7d637357765a5c7b63]
Oct 20 12:28:09 sismo01 pluto[9499]: packet from [GATEWAY_IP_NEW]:500: 
received Vendor ID payload [Dead Peer Detection]
Oct 20 12:28:09 sismo01 pluto[9499]: packet from [GATEWAY_IP_NEW]:500: 
received Vendor ID payload [RFC 3947] method set to=110
Oct 20 12:28:09 sismo01 pluto[9499]: packet from [GATEWAY_IP_NEW]:500: 
received Vendor ID payload [draft-ietf-ipsec-nat-t-ike-03] meth=108, but 
already using method 110
Oct 20 12:28:09 sismo01 pluto[9499]: packet from [GATEWAY_IP_NEW]:500: 
received Vendor ID payload [draft-ietf-ipsec-nat-t-ike-02_n] meth=106, but 
already using method 110
Oct 20 12:28:09 sismo01 pluto[9499]: packet from [GATEWAY_IP_NEW]:500: 
received Vendor ID payload [draft-ietf-ipsec-nat-t-ike-02] meth=107, but 
already using method 110
Oct 20 12:28:09 sismo01 pluto[9499]: "porto"[648] [GATEWAY_IP_NEW] #23673: 
responding to Main Mode from unknown peer [GATEWAY_IP_NEW]
Oct 20 12:28:09 sismo01 pluto[9499]: "porto"[648] [GATEWAY_IP_NEW] #23673: 
transition from state STATE_MAIN_R0 to state STATE_MAIN_R1
Oct 20 12:28:09 sismo01 pluto[9499]: "porto"[648] [GATEWAY_IP_NEW] #23673: 
STATE_MAIN_R1: sent MR1, expecting MI2
Oct 20 12:28:09 sismo01 pluto[9499]: "porto"[648] [GATEWAY_IP_NEW] #23673: 
NAT-Traversal: Result using RFC 3947 (NAT-Traversal): peer is NATed
Oct 20 12:28:09 sismo01 pluto[9499]: "porto"[648] [GATEWAY_IP_NEW] #23673: 
transition from state STATE_MAIN_R1 to state STATE_MAIN_R2
Oct 20 12:28:09 sismo01 pluto[9499]: "porto"[648] [GATEWAY_IP_NEW] #23673: 
STATE_MAIN_R2: sent MR2, expecting MI3
Oct 20 12:29:19 sismo01 pluto[9499]: "porto"[648] [GATEWAY_IP_NEW] #23673: 
max number of retransmissions (2) reached STATE_MAIN_R2
Oct 20 12:29:19 sismo01 pluto[9499]: "porto"[648] [GATEWAY_IP_NEW]: 
deleting connection "porto" instance with peer [GATEWAY_IP_NEW] 
{isakmp=#0/ipsec=#0}
Oct 20 12:29:19 sismo01 pluto[9499]: packet from [GATEWAY_IP_NEW]:500: 
ignoring unknown Vendor ID payload [4f456a7d637357765a5c7b63]
Oct 20 12:29:19 sismo01 pluto[9499]: packet from [GATEWAY_IP_NEW]:500: 
received Vendor ID payload [Dead Peer Detection]
Oct 20 12:29:19 sismo01 pluto[9499]: packet from [GATEWAY_IP_NEW]:500: 
received Vendor ID payload [RFC 3947] method set to=110
Oct 20 12:29:19 sismo01 pluto[9499]: packet from [GATEWAY_IP_NEW]:500: 
received Vendor ID payload [draft-ietf-ipsec-nat-t-ike-03] meth=108, but 
already using method 110
Oct 20 12:29:19 sismo01 pluto[9499]: packet from [GATEWAY_IP_NEW]:500: 
received Vendor ID payload [draft-ietf-ipsec-nat-t-ike-02_n] meth=106, but 
already using method 110
Oct 20 12:29:19 sismo01 pluto[9499]: packet from [GATEWAY_IP_NEW]:500: 
received Vendor ID payload [draft-ietf-ipsec-nat-t-ike-02] meth=107, but 
already using method 110
Oct 20 12:29:19 sismo01 pluto[9499]: "porto"[649] [GATEWAY_IP_NEW] #23674: 
responding to Main Mode from unknown peer [GATEWAY_IP_NEW]
Oct 20 12:29:19 sismo01 pluto[9499]: "porto"[649] [GATEWAY_IP_NEW] #23674: 
transition from state STATE_MAIN_R0 to state STATE_MAIN_R1
Oct 20 12:29:19 sismo01 pluto[9499]: "porto"[649] [GATEWAY_IP_NEW] #23674: 
STATE_MAIN_R1: sent MR1, expecting MI2
Oct 20 12:29:19 sismo01 pluto[9499]: "porto"[649] [GATEWAY_IP_NEW] #23674: 
NAT-Traversal: Result using RFC 3947 (NAT-Traversal): peer is NATed
Oct 20 12:29:19 sismo01 pluto[9499]: "porto"[649] [GATEWAY_IP_NEW] #23674: 
transition from state STATE_MAIN_R1 to state STATE_MAIN_R2
Oct 20 12:29:19 sismo01 pluto[9499]: "porto"[649] [GATEWAY_IP_NEW] #23674: 
STATE_MAIN_R2: sent MR2, expecting MI3
Oct 20 12:30:28 sismo01 pluto[9499]: packet from [GATEWAY_IP_NEW]:500: 
ignoring unknown Vendor ID payload [4f456a7d637357765a5c7b63]

After the IPSec service is restarted on the "server" also, a new tunned 
can be negotiated successfully:

Oct 20 18:25:10 sismo01 pluto[9499]: shutting down
Oct 20 18:25:10 sismo01 pluto[9499]: forgetting secrets
Oct 20 18:25:10 sismo01 pluto[9499]: "porto"[812] [GATEWAY_IP_NEW]: 
deleting connection "porto" instance with peer [GATEWAY_IP_NEW] 
{isakmp=#0/ipsec=#0}
Oct 20 18:25:10 sismo01 pluto[9499]: "porto" #24023: deleting state 
(STATE_MAIN_R2)
Oct 20 18:25:10 sismo01 pluto[9499]: "coimbra": deleting connection
Oct 20 18:25:10 sismo01 pluto[9499]: "madeira": deleting connection
Oct 20 18:25:10 sismo01 pluto[9499]: "porto": deleting connection
Oct 20 18:25:10 sismo01 pluto[9499]: shutting down interface lo/lo 
127.0.0.1:4500
Oct 20 18:25:10 sismo01 pluto[9499]: shutting down interface lo/lo 
127.0.0.1:500
Oct 20 18:25:10 sismo01 pluto[9499]: shutting down interface lo/lo 
127.0.0.2:4500
Oct 20 18:25:10 sismo01 pluto[9499]: shutting down interface lo/lo 
127.0.0.2:500
Oct 20 18:25:10 sismo01 pluto[9499]: shutting down interface eth0/eth0 
[PUBLIC_IP]:4500
Oct 20 18:25:10 sismo01 pluto[9499]: shutting down interface eth0/eth0 
[PUBLIC_IP]:500
Oct 20 18:25:27 sismo01 pluto[9499]: shutting down interface eth0/eth0 
10.10.10.2:4500
Oct 20 18:25:27 sismo01 pluto[9499]: shutting down interface eth0/eth0 
10.10.10.2:500
Oct 20 18:25:30 sismo01 kernel: NET: Unregistered protocol family 15
Oct 20 18:25:31 sismo01 ipsec_setup: ...Openswan IPsec stopped
Oct 20 18:25:31 sismo01 ipsec_setup: Stopping Openswan IPsec...
Oct 20 18:25:37 sismo01 kernel: NET: Registered protocol family 15
Oct 20 18:25:37 sismo01 kernel: padlock: VIA PadLock Hash Engine not 
detected.
Oct 20 18:25:37 sismo01 kernel: padlock: VIA PadLock Hash Engine not 
detected.
Oct 20 18:25:38 sismo01 kernel: padlock: VIA PadLock not detected.
Oct 20 18:25:39 sismo01 kernel: Initializing XFRM netlink socket
Oct 20 18:25:39 sismo01 ipsec_setup: NETKEY on eth0 
[PUBLIC_IP]/255.255.255.0 broadcast xxx.xxx.xxx.255
Oct 20 18:25:40 sismo01 ipsec__plutorun: Starting Pluto subsystem...
Oct 20 18:25:40 sismo01 ipsec_setup: ...Openswan IPsec started
Oct 20 18:25:40 sismo01 ipsec_setup: Starting Openswan IPsec 2.4.7...
Oct 20 18:25:40 sismo01 pluto[29587]: Starting Pluto (Openswan Version 
2.4.7 PLUTO_SENDS_VENDORID PLUTO_USES_KEYRR; Vendor ID OEZ~BaB]r\134p_)
Oct 20 18:25:48 sismo01 pluto[29587]: Setting NAT-Traversal port-4500 
floating to on
Oct 20 18:25:48 sismo01 pluto[29587]:    port floating activation criteria 
nat_t=1/port_fload=1
Oct 20 18:25:48 sismo01 pluto[29587]:   including NAT-Traversal patch 
(Version 0.6c)
Oct 20 18:25:49 sismo01 pluto[29587]: ike_alg_register_enc(): Activating 
OAKLEY_AES_CBC: Ok (ret=0)
Oct 20 18:25:49 sismo01 pluto[29587]: no helpers will be started, all 
cryptographic operations will be done inline
Oct 20 18:25:49 sismo01 pluto[29587]: Using NETKEY IPsec interface code on 
2.6.25.5-1.1-pae
Oct 20 18:25:49 sismo01 pluto[29587]: Changing to directory 
'/etc/ipsec.d/cacerts'
Oct 20 18:25:50 sismo01 pluto[29587]:   loaded CA cert file 'cacert.pem' 
(3248 bytes)
Oct 20 18:25:50 sismo01 pluto[29587]: Could not change to directory 
'/etc/ipsec.d/aacerts'
Oct 20 18:25:50 sismo01 pluto[29587]: Could not change to directory 
'/etc/ipsec.d/ocspcerts'
Oct 20 18:25:50 sismo01 pluto[29587]: Changing to directory 
'/etc/ipsec.d/crls'
Oct 20 18:25:50 sismo01 pluto[29587]:   loaded crl file 'crl.pem' (524 
bytes)
Oct 20 18:25:50 sismo01 pluto[29587]:   loaded crl file 'crl.old.pem' (524 
bytes)
Oct 20 18:25:50 sismo01 pluto[29587]:   loaded host cert file 
'/etc/ipsec.d/certs/lisboa.pem' (3232 bytes)
Oct 20 18:25:50 sismo01 pluto[29587]:   loaded host cert file 
'/etc/ipsec.d/certs/palmela.pem' (3233 bytes)
Oct 20 18:26:07 sismo01 pluto[29587]: added connection description "porto"
Oct 20 18:26:07 sismo01 pluto[29587]:   loaded host cert file 
'/etc/ipsec.d/certs/lisboa.pem' (3232 bytes)
Oct 20 18:26:08 sismo01 pluto[29587]:   loaded host cert file 
'/etc/ipsec.d/certs/madeira.pem' (3245 bytes)
Oct 20 18:26:08 sismo01 pluto[29587]: added connection description 
"madeira"
Oct 20 18:26:08 sismo01 pluto[29587]:   loaded host cert file 
'/etc/ipsec.d/certs/lisboa.pem' (3232 bytes)
Oct 20 18:26:08 sismo01 pluto[29587]:   loaded host cert file 
'/etc/ipsec.d/certs/coimbra.pem' (3244 bytes)
Oct 20 18:26:08 sismo01 pluto[29587]: added connection description 
"coimbra"
Oct 20 18:26:08 sismo01 pluto[29587]: listening for IKE messages
Oct 20 18:26:08 sismo01 pluto[29587]: adding interface eth0/eth0 
10.10.10.2:500
Oct 20 18:26:08 sismo01 pluto[29587]: adding interface eth0/eth0 
10.10.10.2:4500
Oct 20 18:26:08 sismo01 pluto[29587]: adding interface eth0/eth0 
[PUBLIC_IP]:500
Oct 20 18:26:26 sismo01 pluto[29587]: adding interface eth0/eth0 
[PUBLIC_IP]:4500
Oct 20 18:26:26 sismo01 pluto[29587]: adding interface lo/lo 127.0.0.2:500
Oct 20 18:26:26 sismo01 pluto[29587]: adding interface lo/lo 
127.0.0.2:4500
Oct 20 18:26:26 sismo01 pluto[29587]: adding interface lo/lo 127.0.0.1:500
Oct 20 18:26:26 sismo01 pluto[29587]: adding interface lo/lo 
127.0.0.1:4500
Oct 20 18:26:26 sismo01 pluto[29587]: loading secrets from 
"/etc/ipsec.secrets"
Oct 20 18:26:26 sismo01 pluto[29587]:   loaded private key file 
'/etc/ipsec.d/private/lisboa.key' (963 bytes)
Oct 20 18:26:26 sismo01 pluto[29587]: packet from [GATEWAY_IP_NEW]:500: 
ignoring unknown Vendor ID payload [4f456a7d637357765a5c7b63]
Oct 20 18:26:26 sismo01 pluto[29587]: packet from [GATEWAY_IP_NEW]:500: 
received Vendor ID payload [Dead Peer Detection]
Oct 20 18:26:26 sismo01 pluto[29587]: packet from [GATEWAY_IP_NEW]:500: 
received Vendor ID payload [RFC 3947] method set to=110
Oct 20 18:26:26 sismo01 pluto[29587]: packet from [GATEWAY_IP_NEW]:500: 
received Vendor ID payload [draft-ietf-ipsec-nat-t-ike-03] meth=108, but 
already using method 110
Oct 20 18:26:46 sismo01 pluto[29587]: packet from [GATEWAY_IP_NEW]:500: 
received Vendor ID payload [draft-ietf-ipsec-nat-t-ike-02_n] meth=106, but 
already using method 110
Oct 20 18:26:46 sismo01 pluto[29587]: packet from [GATEWAY_IP_NEW]:500: 
received Vendor ID payload [draft-ietf-ipsec-nat-t-ike-02] meth=107, but 
already using method 110
Oct 20 18:26:46 sismo01 pluto[29587]: "porto"[1] [GATEWAY_IP_NEW] #1: 
responding to Main Mode from unknown peer [GATEWAY_IP_NEW]
Oct 20 18:26:46 sismo01 pluto[29587]: "porto"[1] [GATEWAY_IP_NEW] #1: 
transition from state STATE_MAIN_R0 to state STATE_MAIN_R1
Oct 20 18:26:46 sismo01 pluto[29587]: "porto"[1] [GATEWAY_IP_NEW] #1: 
STATE_MAIN_R1: sent MR1, expecting MI2
Oct 20 18:26:46 sismo01 pluto[29587]: packet from [GATEWAY_IP_NEW]:500: 
ignoring unknown Vendor ID payload [4f456a7d637357765a5c7b63]
Oct 20 18:26:46 sismo01 pluto[29587]: packet from [GATEWAY_IP_NEW]:500: 
received Vendor ID payload [Dead Peer Detection]
Oct 20 18:26:46 sismo01 pluto[29587]: packet from [GATEWAY_IP_NEW]:500: 
received Vendor ID payload [RFC 3947] method set to=110
Oct 20 18:26:46 sismo01 pluto[29587]: packet from [GATEWAY_IP_NEW]:500: 
received Vendor ID payload [draft-ietf-ipsec-nat-t-ike-03] meth=108, but 
already using method 110
Oct 20 18:26:46 sismo01 pluto[29587]: packet from [GATEWAY_IP_NEW]:500: 
received Vendor ID payload [draft-ietf-ipsec-nat-t-ike-02_n] meth=106, but 
already using method 110
Oct 20 18:26:46 sismo01 pluto[29587]: packet from [GATEWAY_IP_NEW]:500: 
received Vendor ID payload [draft-ietf-ipsec-nat-t-ike-02] meth=107, but 
already using method 110
Oct 20 18:27:06 sismo01 pluto[29587]: "porto"[1] [GATEWAY_IP_NEW] #2: 
responding to Main Mode from unknown peer [GATEWAY_IP_NEW]
Oct 20 18:27:06 sismo01 pluto[29587]: "porto"[1] [GATEWAY_IP_NEW] #2: 
transition from state STATE_MAIN_R0 to state STATE_MAIN_R1
Oct 20 18:27:06 sismo01 pluto[29587]: "porto"[1] [GATEWAY_IP_NEW] #2: 
STATE_MAIN_R1: sent MR1, expecting MI2
Oct 20 18:27:06 sismo01 pluto[29587]: "porto"[1] [GATEWAY_IP_NEW] #1: 
NAT-Traversal: Result using RFC 3947 (NAT-Traversal): peer is NATed
Oct 20 18:27:06 sismo01 pluto[29587]: "porto"[1] [GATEWAY_IP_NEW] #1: 
transition from state STATE_MAIN_R1 to state STATE_MAIN_R2
Oct 20 18:27:06 sismo01 pluto[29587]: "porto"[1] [GATEWAY_IP_NEW] #1: 
STATE_MAIN_R2: sent MR2, expecting MI3
Oct 20 18:27:06 sismo01 pluto[29587]: "porto"[1] [GATEWAY_IP_NEW] #1: 
discarding duplicate packet; already STATE_MAIN_R2
Oct 20 18:27:06 sismo01 pluto[29587]: "porto"[1] [GATEWAY_IP_NEW] #1: Main 
mode peer ID is ID_DER_ASN1_DN: '[CERTIFICATE_DETAILS]'
Oct 20 18:27:06 sismo01 pluto[29587]: "porto"[1] [GATEWAY_IP_NEW] #1: I am 
sending my cert
Oct 20 18:27:06 sismo01 pluto[29587]: "porto"[1] [GATEWAY_IP_NEW] #1: 
transition from state STATE_MAIN_R2 to state STATE_MAIN_R3
Oct 20 18:27:06 sismo01 pluto[29587]: | NAT-T: new mapping 
[GATEWAY_IP_NEW]:500/4500)
Oct 20 18:27:06 sismo01 pluto[29587]: "porto"[1] [GATEWAY_IP_NEW] #1: 
STATE_MAIN_R3: sent MR3, ISAKMP SA established {auth=OAKLEY_RSA_SIG 
cipher=oakley_3des_cbc_192 prf=oakley_sha group=modp1536}
Oct 20 18:27:25 sismo01 pluto[29587]: "porto"[1] [GATEWAY_IP_NEW] #1: Dead 
Peer Detection (RFC 3706): enabled
Oct 20 18:27:25 sismo01 pluto[29587]: "porto"[1] [GATEWAY_IP_NEW] #3: 
responding to Quick Mode {msgid:ca574dd1}
Oct 20 18:27:25 sismo01 pluto[29587]: "porto"[1] [GATEWAY_IP_NEW] #3: 
transition from state STATE_QUICK_R0 to state STATE_QUICK_R1
Oct 20 18:27:25 sismo01 pluto[29587]: "porto"[1] [GATEWAY_IP_NEW] #3: 
STATE_QUICK_R1: sent QR1, inbound IPsec SA installed, expecting QI2
Oct 20 18:27:25 sismo01 pluto[29587]: "porto"[1] [GATEWAY_IP_NEW] #3: 
discarding duplicate packet; already STATE_QUICK_R1
Oct 20 18:27:26 sismo01 pluto[29587]: "porto"[1] [GATEWAY_IP_NEW] #3: Dead 
Peer Detection (RFC 3706): enabled
Oct 20 18:27:26 sismo01 pluto[29587]: "porto"[1] [GATEWAY_IP_NEW] #3: 
transition from state STATE_QUICK_R1 to state STATE_QUICK_R2
Oct 20 18:27:26 sismo01 pluto[29587]: "porto"[1] [GATEWAY_IP_NEW] #3: 
STATE_QUICK_R2: IPsec SA established {ESP=>0x6fd93f87 <0xdf82d5d4 
xfrm=3DES_0-HMAC_SHA1 NATD=[GATEWAY_IP_NEW]:4500 DPD=enabled}
Oct 20 18:28:04 sismo01 pluto[29587]: "porto"[1] [GATEWAY_IP_NEW] #1: 
received Delete SA(0x6fd93f87) payload: deleting IPSEC State #3
Oct 20 18:28:04 sismo01 pluto[29587]: "porto"[1] [GATEWAY_IP_NEW] #1: 
received and ignored informational message
Oct 20 18:28:04 sismo01 pluto[29587]: "porto"[1] [GATEWAY_IP_NEW] #1: 
received Delete SA payload: deleting ISAKMP State #1
Oct 20 18:28:04 sismo01 pluto[29587]: packet from [GATEWAY_IP_NEW]:4500: 
received and ignored informational message
Oct 20 18:28:08 sismo01 pluto[29587]: packet from [GATEWAY_IP_NEW]:500: 
ignoring unknown Vendor ID payload [4f456a7d637357765a5c7b63]
Oct 20 18:28:08 sismo01 pluto[29587]: packet from [GATEWAY_IP_NEW]:500: 
received Vendor ID payload [Dead Peer Detection]
Oct 20 18:28:08 sismo01 pluto[29587]: packet from [GATEWAY_IP_NEW]:500: 
received Vendor ID payload [RFC 3947] method set to=110
Oct 20 18:28:08 sismo01 pluto[29587]: packet from [GATEWAY_IP_NEW]:500: 
received Vendor ID payload [draft-ietf-ipsec-nat-t-ike-03] meth=108, but 
already using method 110
Oct 20 18:28:08 sismo01 pluto[29587]: packet from [GATEWAY_IP_NEW]:500: 
received Vendor ID payload [draft-ietf-ipsec-nat-t-ike-02_n] meth=106, but 
already using method 110
Oct 20 18:28:08 sismo01 pluto[29587]: packet from [GATEWAY_IP_NEW]:500: 
received Vendor ID payload [draft-ietf-ipsec-nat-t-ike-02] meth=107, but 
already using method 110
Oct 20 18:28:08 sismo01 pluto[29587]: "porto"[1] [GATEWAY_IP_NEW] #4: 
responding to Main Mode from unknown peer [GATEWAY_IP_NEW]
Oct 20 18:28:08 sismo01 pluto[29587]: "porto"[1] [GATEWAY_IP_NEW] #4: 
transition from state STATE_MAIN_R0 to state STATE_MAIN_R1
Oct 20 18:28:08 sismo01 pluto[29587]: "porto"[1] [GATEWAY_IP_NEW] #4: 
STATE_MAIN_R1: sent MR1, expecting MI2
Oct 20 18:28:08 sismo01 pluto[29587]: "porto"[1] [GATEWAY_IP_NEW] #4: 
NAT-Traversal: Result using RFC 3947 (NAT-Traversal): peer is NATed
Oct 20 18:28:08 sismo01 pluto[29587]: "porto"[1] [GATEWAY_IP_NEW] #4: 
transition from state STATE_MAIN_R1 to state STATE_MAIN_R2
Oct 20 18:28:08 sismo01 pluto[29587]: "porto"[1] [GATEWAY_IP_NEW] #4: 
STATE_MAIN_R2: sent MR2, expecting MI3
Oct 20 18:28:24 sismo01 pluto[29587]: "porto"[1] [GATEWAY_IP_NEW] #4: Main 
mode peer ID is ID_DER_ASN1_DN: '[CERTIFICATE_DETAILS]'
Oct 20 18:28:24 sismo01 pluto[29587]: "porto"[1] [GATEWAY_IP_NEW] #4: I am 
sending my cert
Oct 20 18:28:24 sismo01 pluto[29587]: "porto"[1] [GATEWAY_IP_NEW] #4: 
transition from state STATE_MAIN_R2 to state STATE_MAIN_R3
Oct 20 18:28:24 sismo01 pluto[29587]: | NAT-T: new mapping 
[GATEWAY_IP_NEW]:500/4500)
Oct 20 18:28:24 sismo01 pluto[29587]: "porto"[1] [GATEWAY_IP_NEW] #4: 
STATE_MAIN_R3: sent MR3, ISAKMP SA established {auth=OAKLEY_RSA_SIG 
cipher=oakley_3des_cbc_192 prf=oakley_sha group=modp1536}
Oct 20 18:28:24 sismo01 pluto[29587]: "porto"[1] [GATEWAY_IP_NEW] #4: Dead 
Peer Detection (RFC 3706): enabled
Oct 20 18:28:24 sismo01 pluto[29587]: "porto"[1] [GATEWAY_IP_NEW] #4: 
retransmitting in response to duplicate packet; already STATE_MAIN_R3
Oct 20 18:28:24 sismo01 pluto[29587]: "porto"[1] [GATEWAY_IP_NEW] #5: 
responding to Quick Mode {msgid:216e18cd}
Oct 20 18:28:24 sismo01 pluto[29587]: "porto"[1] [GATEWAY_IP_NEW] #5: 
transition from state STATE_QUICK_R0 to state STATE_QUICK_R1
Oct 20 18:28:24 sismo01 pluto[29587]: "porto"[1] [GATEWAY_IP_NEW] #5: 
STATE_QUICK_R1: sent QR1, inbound IPsec SA installed, expecting QI2
Oct 20 18:28:24 sismo01 pluto[29587]: "porto"[1] [GATEWAY_IP_NEW] #5: Dead 
Peer Detection (RFC 3706): enabled
Oct 20 18:28:24 sismo01 pluto[29587]: "porto"[1] [GATEWAY_IP_NEW] #5: 
transition from state STATE_QUICK_R1 to state STATE_QUICK_R2
Oct 20 18:28:45 sismo01 pluto[29587]: "porto"[1] [GATEWAY_IP_NEW] #5: 
STATE_QUICK_R2: IPsec SA established {ESP=>0x23d6c11c <0x1ca6ce85 
xfrm=3DES_0-HMAC_SHA1 NATD=[GATEWAY_IP_NEW]:4500 DPD=enabled}
Oct 20 18:28:45 sismo01 pluto[29587]: "porto"[1] [GATEWAY_IP_NEW] #2: max 
number of retransmissions (2) reached STATE_MAIN_R1

Thanks in advance for any help. And sorry if the message is too long.


Goncalo Cruz


More information about the Users mailing list