[Openswan Users] DPD and ERROR: netlink response for Add SA esp.xxxxxxxx at y.y.y.y included errno 17: File exists

L Felgr lfelgr at ymail.com
Tue Jul 19 05:03:50 EDT 2011 

Hello,
 
I've got 2 devices with embedded Linux:
Dev1: kernel 2.6.23, OpenSWAN 2.6.25 (I have tried kernel 2.6.17 (uClinux) and OpenSWAN 2.4.5 with the same result on Dev1)
Dev2: kernel 2.6.27, OpenSWAN 2.6.34
 
Devices are connected via GSM network (GPRS/EDGE)
 
Situation:
192.168.2.0/24==Dev1==10.0.2.125 <-> GSM network <-> 10.0.3.114==Dev2==192.168.3.0/24
 
Starting IPsec directly (example is from Dev2):
1) pluto --nofork --nhelpers 0 --uniqueids --adns /usr/sbin/_pluto_adns --secretsfile /etc/ipsec.d/ipsec.secrets
2) whack --name ipsec1 --encrypt --tunnel --psk --host 10.0.3.114 --client 192.168.3.0/255.255.255.0 --nexthop %direct --updown /etc/scripts/updown --to --host 10.0.2.125 --client 192.168.2.0/255.255.255.0 --nexthop %direct --updown /etc/scripts/updown --ikelifetime 3600 --ipseclifetime 3600 --rekeymargin 540 --rekeyfuzz 100 --keyingtries 0 --dpdaction=restart_by_peer --dpddelay=120 --dpdtimeout=20
 
Problem with DPD:
If I switch Dev2 off for more than dpddelay then Dev1 correctly recognizes Dev2 as dead and after switching Dev2 on the IPsec tunnel is reestablished without any problem. If I restart Dev2 (switching it off and on again or rebooting) just after keep-alive packets are exchanged so there is enough time for Dev2 to be ready for communication before dpddelay expires then the error 17: File exists (see in the syslog listing) appears in 50 % cases and tunnel reestablishment freezes for 40 minutes or thereabouts. Evidently, it is the problem of Dev1 which is not able to recognize that Dev2 went through reset meanwhile. Dev1 and Dev2 are interchangeable regarding this problem.
 
I am aware of:
1) This problem can be solved by using dpddelay as short as possible. 10 sec would be fair value for my purposes. But I can't use values under 1 min beacuse of the price of exchanging keep-alive messages over GSM network. There can be hundreds of such devices in the network.
2) The problem maybe comes from the fact there is not enough time for pluto to disconnect tunnel before rebooting. Anyway, If anybody switches supply voltage off on Dev2 (it's OK with embedded system - nothing is damaged) then there surely is not enough time to do anything. And this can happen in real situation quite often.
 
So what can I do? Should I find critical code and try to change something? That is not probably good idea because either IPsec stack in the kernel or IKE deamon are written according to RFC's and if I change anything then I can loose interoperability with other systems (Cisco, Windows etc). 
 
Thanks for help in advance.
 
L. Felgr
 
========================================
Dev1 syslog listing
========================================
2011-07-18 11:38:02 pluto[431]: Starting Pluto (Openswan Version 2.6.25) pid:431
2011-07-18 11:38:02 pluto[431]: Setting NAT-Traversal port-4500 floating to off
2011-07-18 11:38:02 pluto[431]:    port floating activation criteria nat_t=0/port_float=1
2011-07-18 11:38:02 pluto[431]:    NAT-Traversal support  [disabled]
2011-07-18 11:38:02 pluto[431]: using /dev/urandom as source of random entropy
2011-07-18 11:38:02 pluto[431]: no helpers will be started, all cryptographic operations will be done inline
2011-07-18 11:38:03 pluto[431]: Using Linux 2.6 IPsec interface code on 2.6.23 (experimental code)
2011-07-18 11:38:03 pluto[431]: Changed path to directory '/etc/ipsec.d/cacerts'
2011-07-18 11:38:03 pluto[431]: added connection description "ipsec1"
2011-07-18 11:38:04 pluto[431]: listening for IKE messages
2011-07-18 11:38:04 pluto[431]: adding interface ppp0/ppp0 10.0.2.125:500
2011-07-18 11:38:04 pluto[431]: adding interface eth0/eth0 192.168.2.149:500
2011-07-18 11:38:04 pluto[431]: loading secrets from "/etc/ipsec.d/ipsec.secrets"
2011-07-18 11:38:04 pluto[431]: "ipsec1" #1: initiating Main Mode
2011-07-18 11:38:04 pppd[371]: Script /etc/scripts/ip-up finished (pid 392), status = 0x0
2011-07-18 11:38:07 pluto[431]: "ipsec1" #1: received Vendor ID payload [Dead Peer Detection]
2011-07-18 11:38:07 pluto[431]: "ipsec1" #1: transition from state STATE_MAIN_I1 to state STATE_MAIN_I2
2011-07-18 11:38:07 pluto[431]: "ipsec1" #1: STATE_MAIN_I2: sent MI2, expecting MR2
2011-07-18 11:38:09 pluto[431]: "ipsec1" #1: transition from state STATE_MAIN_I2 to state STATE_MAIN_I3
2011-07-18 11:38:09 pluto[431]: "ipsec1" #1: STATE_MAIN_I3: sent MI3, expecting MR3
2011-07-18 11:38:10 pluto[431]: "ipsec1" #1: Main mode peer ID is ID_IPV4_ADDR: '10.0.3.114'
2011-07-18 11:38:10 pluto[431]: "ipsec1" #1: transition from state STATE_MAIN_I3 to state STATE_MAIN_I4
2011-07-18 11:38:10 pluto[431]: "ipsec1" #1: STATE_MAIN_I4: ISAKMP SA established {auth=OAKLEY_PRESHARED_KEY cipher=aes_128 prf=oakley_sha group=modp2048}
2011-07-18 11:38:10 pluto[431]: "ipsec1" #1: Dead Peer Detection (RFC 3706): enabled
2011-07-18 11:38:10 pluto[431]: "ipsec1" #2: initiating Quick Mode PSK+ENCRYPT+TUNNEL+UP {using isakmp#1 msgid:4cf964f1 proposal=defaults pfsgroup=no-pfs}
2011-07-18 11:38:10 pluto[431]: packet from 10.0.3.114:500: received Vendor ID payload [Dead Peer Detection]
2011-07-18 11:38:10 pluto[431]: "ipsec1" #3: responding to Main Mode
2011-07-18 11:38:10 pluto[431]: "ipsec1" #3: transition from state STATE_MAIN_R0 to state STATE_MAIN_R1
2011-07-18 11:38:10 pluto[431]: "ipsec1" #3: STATE_MAIN_R1: sent MR1, expecting MI2
2011-07-18 11:38:11 pluto[431]: "ipsec1" #2: Dead Peer Detection (RFC 3706): enabled
2011-07-18 11:38:11 pluto[431]: "ipsec1" #2: transition from state STATE_QUICK_I1 to state STATE_QUICK_I2
2011-07-18 11:38:11 pluto[431]: "ipsec1" #2: STATE_QUICK_I2: sent QI2, IPsec SA established tunnel mode {ESP=0xbd885898 0x982ea68a xfrm=AES_128-HMAC_SHA1 NATOA=none NATD=none DPD=enabled}
2011-07-18 11:38:12 pluto[431]: "ipsec1" #3: transition from state STATE_MAIN_R1 to state STATE_MAIN_R2
2011-07-18 11:38:12 pluto[431]: "ipsec1" #3: STATE_MAIN_R2: sent MR2, expecting MI3
2011-07-18 11:38:23 pluto[431]: "ipsec1" #3: discarding duplicate packet; already STATE_MAIN_R2
2011-07-18 11:38:23 pluto[431]: "ipsec1" #3: Main mode peer ID is ID_IPV4_ADDR: '10.0.3.114'
2011-07-18 11:38:23 pluto[431]: "ipsec1" #3: transition from state STATE_MAIN_R2 to state STATE_MAIN_R3
2011-07-18 11:38:23 pluto[431]: "ipsec1" #3: STATE_MAIN_R3: sent MR3, ISAKMP SA established {auth=OAKLEY_PRESHARED_KEY cipher=aes_128 prf=oakley_sha group=modp2048}
2011-07-18 11:38:24 pluto[431]: "ipsec1" #3: Dead Peer Detection (RFC 3706): enabled
2011-07-18 11:38:24 pluto[431]: "ipsec1" #3: the peer proposed: 192.168.2.0/24:0/0 - 192.168.3.0/24:0/0
2011-07-18 11:38:24 pluto[431]: "ipsec1" #4: responding to Quick Mode proposal {msgid:55efdddf}
2011-07-18 11:38:24 pluto[431]: "ipsec1" #4:     us: 192.168.2.0/24===10.0.2.125
2011-07-18 11:38:24 pluto[431]: "ipsec1" #4:   them: 10.0.3.114===192.168.3.0/24
2011-07-18 11:38:24 pluto[431]: | NAT-OA: 0 tunnel: 0  
2011-07-18 11:38:24 pluto[431]: "ipsec1" #4: keeping refhim=4294901761 during rekey
2011-07-18 11:38:24 pluto[431]: "ipsec1" #4: transition from state STATE_QUICK_R0 to state STATE_QUICK_R1
2011-07-18 11:38:24 pluto[431]: "ipsec1" #4: STATE_QUICK_R1: sent QR1, inbound IPsec SA installed, expecting QI2
2011-07-18 11:38:24 pluto[431]: "ipsec1" #4: Dead Peer Detection (RFC 3706): enabled
2011-07-18 11:38:24 pluto[431]: "ipsec1" #4: transition from state STATE_QUICK_R1 to state STATE_QUICK_R2
2011-07-18 11:38:24 pluto[431]: "ipsec1" #4: STATE_QUICK_R2: IPsec SA established tunnel mode {ESP=0x3b859493 0xecbb3010 xfrm=AES_128-HMAC_SHA1 NATOA=none NATD=none DPD=enabled}
****************************************
State: IPsec tunnel established - OK
Action: Dev2 - power off
****************************************
2011-07-18 11:40:21 pluto[431]: "ipsec1" #3: DPD: No response from peer - declaring peer dead
2011-07-18 11:40:21 pluto[431]: "ipsec1" #3: DPD: Restarting all connections that share this peer
2011-07-18 11:40:21 pluto[431]: "ipsec1" #3: terminating SAs using this connection
2011-07-18 11:40:21 pluto[431]: "ipsec1" #4: deleting state (STATE_QUICK_R2)
2011-07-18 11:40:21 pluto[431]: "ipsec1" #3: deleting state (STATE_MAIN_R3)
2011-07-18 11:40:21 pluto[431]: "ipsec1" #2: deleting state (STATE_QUICK_I2)
2011-07-18 11:40:21 pluto[431]: "ipsec1" #1: deleting state (STATE_MAIN_I4)
2011-07-18 11:40:21 pluto[431]: "ipsec1" #5: initiating Main Mode
****************************************
State: Dead peer detected - OK
****************************************
2011-07-18 11:42:02 pluto[431]: pending Quick Mode with 10.0.3.114 "ipsec1" took too long -- replacing phase 1
2011-07-18 11:42:02 pluto[431]: "ipsec1" #6: initiating Main Mode to replace #5
****************************************
Action: Dev2 - power on
****************************************
2011-07-18 11:42:57 pluto[431]: packet from 10.0.3.114:500: received Vendor ID payload [Dead Peer Detection]
2011-07-18 11:42:57 pluto[431]: "ipsec1" #7: responding to Main Mode
2011-07-18 11:42:57 pluto[431]: "ipsec1" #7: transition from state STATE_MAIN_R0 to state STATE_MAIN_R1
2011-07-18 11:42:57 pluto[431]: "ipsec1" #7: STATE_MAIN_R1: sent MR1, expecting MI2
2011-07-18 11:42:57 pluto[431]: ERROR: asynchronous network error report on ppp0 (sport=500) for message to 10.0.3.114 port 500, complainant 10.1.0.21: No route to host [errno 113, origin ICMP type 3 code 1 (not authenticated)]
2011-07-18 11:43:07 pluto[431]: packet from 10.0.3.114:500: received Vendor ID payload [Dead Peer Detection]
2011-07-18 11:43:07 pluto[431]: "ipsec1" #8: responding to Main Mode
2011-07-18 11:43:07 pluto[431]: "ipsec1" #8: transition from state STATE_MAIN_R0 to state STATE_MAIN_R1
2011-07-18 11:43:07 pluto[431]: "ipsec1" #8: STATE_MAIN_R1: sent MR1, expecting MI2
2011-07-18 11:43:08 pluto[431]: "ipsec1" #8: transition from state STATE_MAIN_R1 to state STATE_MAIN_R2
2011-07-18 11:43:08 pluto[431]: "ipsec1" #8: STATE_MAIN_R2: sent MR2, expecting MI3
2011-07-18 11:43:09 pluto[431]: "ipsec1" #8: Main mode peer ID is ID_IPV4_ADDR: '10.0.3.114'
2011-07-18 11:43:09 pluto[431]: "ipsec1" #8: transition from state STATE_MAIN_R2 to state STATE_MAIN_R3
2011-07-18 11:43:09 pluto[431]: "ipsec1" #8: STATE_MAIN_R3: sent MR3, ISAKMP SA established {auth=OAKLEY_PRESHARED_KEY cipher=aes_128 prf=oakley_sha group=modp2048}
2011-07-18 11:43:09 pluto[431]: "ipsec1" #8: Dead Peer Detection (RFC 3706): enabled
2011-07-18 11:43:09 pluto[431]: "ipsec1" #8: the peer proposed: 192.168.2.0/24:0/0 - 192.168.3.0/24:0/0
2011-07-18 11:43:09 pluto[431]: "ipsec1" #9: responding to Quick Mode proposal {msgid:7db4f7aa}
2011-07-18 11:43:09 pluto[431]: "ipsec1" #9:     us: 192.168.2.0/24===10.0.2.125
2011-07-18 11:43:09 pluto[431]: "ipsec1" #9:   them: 10.0.3.114===192.168.3.0/24
2011-07-18 11:43:09 pluto[431]: | NAT-OA: 0 tunnel: 0  
2011-07-18 11:43:09 pluto[431]: "ipsec1" #9: transition from state STATE_QUICK_R0 to state STATE_QUICK_R1
2011-07-18 11:43:09 pluto[431]: "ipsec1" #9: STATE_QUICK_R1: sent QR1, inbound IPsec SA installed, expecting QI2
2011-07-18 11:43:09 pluto[431]: "ipsec1" #9: Dead Peer Detection (RFC 3706): enabled
2011-07-18 11:43:09 pluto[431]: "ipsec1" #9: transition from state STATE_QUICK_R1 to state STATE_QUICK_R2
2011-07-18 11:43:10 pluto[431]: "ipsec1" #9: STATE_QUICK_R2: IPsec SA established tunnel mode {ESP=0x0b056df3 0x17354389 xfrm=AES_128-HMAC_SHA1 NATOA=none NATD=none DPD=enabled}
2011-07-18 11:43:12 pluto[431]: "ipsec1" #6: received Vendor ID payload [Dead Peer Detection]
2011-07-18 11:43:12 pluto[431]: "ipsec1" #6: transition from state STATE_MAIN_I1 to state STATE_MAIN_I2
2011-07-18 11:43:12 pluto[431]: "ipsec1" #6: STATE_MAIN_I2: sent MI2, expecting MR2
2011-07-18 11:43:13 pluto[431]: "ipsec1" #6: transition from state STATE_MAIN_I2 to state STATE_MAIN_I3
2011-07-18 11:43:13 pluto[431]: "ipsec1" #6: STATE_MAIN_I3: sent MI3, expecting MR3
2011-07-18 11:43:14 pluto[431]: "ipsec1" #6: Main mode peer ID is ID_IPV4_ADDR: '10.0.3.114'
2011-07-18 11:43:14 pluto[431]: "ipsec1" #6: transition from state STATE_MAIN_I3 to state STATE_MAIN_I4
2011-07-18 11:43:14 pluto[431]: "ipsec1" #6: STATE_MAIN_I4: ISAKMP SA established {auth=OAKLEY_PRESHARED_KEY cipher=aes_128 prf=oakley_sha group=modp2048}
2011-07-18 11:43:14 pluto[431]: "ipsec1" #6: Dead Peer Detection (RFC 3706): enabled
2011-07-18 11:43:14 pluto[431]: "ipsec1" #10: initiating Quick Mode PSK+ENCRYPT+TUNNEL+UP {using isakmp#6 msgid:46478d55 proposal=defaults pfsgroup=no-pfs}
2011-07-18 11:43:14 pluto[431]: "ipsec1" #10: Dead Peer Detection (RFC 3706): enabled
2011-07-18 11:43:14 pluto[431]: "ipsec1" #10: transition from state STATE_QUICK_I1 to state STATE_QUICK_I2
2011-07-18 11:43:14 pluto[431]: "ipsec1" #10: STATE_QUICK_I2: sent QI2, IPsec SA established tunnel mode {ESP=0x14b49ae2 0x2d1cc833 xfrm=AES_128-HMAC_SHA1 NATOA=none NATD=none DPD=enabled}
****************************************
State: IPsec tunnel reestablished - OK
****************************************
2011-07-18 11:44:07 pluto[431]: "ipsec1" #7: max number of retransmissions (2) reached STATE_MAIN_R1
****************************************
Action: Dev2 - reboot
****************************************
2011-07-18 11:47:57 pluto[431]: packet from 10.0.3.114:500: received Vendor ID payload [Dead Peer Detection]
2011-07-18 11:47:57 pluto[431]: "ipsec1" #11: responding to Main Mode
2011-07-18 11:47:57 pluto[431]: "ipsec1" #11: transition from state STATE_MAIN_R0 to state STATE_MAIN_R1
2011-07-18 11:47:57 pluto[431]: "ipsec1" #11: STATE_MAIN_R1: sent MR1, expecting MI2
2011-07-18 11:47:58 pluto[431]: "ipsec1" #11: transition from state STATE_MAIN_R1 to state STATE_MAIN_R2
2011-07-18 11:47:58 pluto[431]: "ipsec1" #11: STATE_MAIN_R2: sent MR2, expecting MI3
2011-07-18 11:47:59 pluto[431]: "ipsec1" #11: Main mode peer ID is ID_IPV4_ADDR: '10.0.3.114'
2011-07-18 11:47:59 pluto[431]: "ipsec1" #11: transition from state STATE_MAIN_R2 to state STATE_MAIN_R3
2011-07-18 11:47:59 pluto[431]: "ipsec1" #11: STATE_MAIN_R3: sent MR3, ISAKMP SA established {auth=OAKLEY_PRESHARED_KEY cipher=aes_128 prf=oakley_sha group=modp2048}
2011-07-18 11:47:59 pluto[431]: "ipsec1" #11: Dead Peer Detection (RFC 3706): enabled
2011-07-18 11:47:59 pluto[431]: "ipsec1" #11: the peer proposed: 192.168.2.0/24:0/0 - 192.168.3.0/24:0/0
2011-07-18 11:47:59 pluto[431]: "ipsec1" #12: responding to Quick Mode proposal {msgid:fee93b6a}
2011-07-18 11:47:59 pluto[431]: "ipsec1" #12:     us: 192.168.2.0/24===10.0.2.125
2011-07-18 11:47:59 pluto[431]: "ipsec1" #12:   them: 10.0.3.114===192.168.3.0/24
2011-07-18 11:47:59 pluto[431]: | NAT-OA: 0 tunnel: 0  
2011-07-18 11:47:59 pluto[431]: "ipsec1" #12: keeping refhim=4294901761 during rekey
2011-07-18 11:47:59 pluto[431]: "ipsec1" #12: transition from state STATE_QUICK_R0 to state STATE_QUICK_R1
2011-07-18 11:47:59 pluto[431]: "ipsec1" #12: STATE_QUICK_R1: sent QR1, inbound IPsec SA installed, expecting QI2
2011-07-18 11:47:59 pluto[431]: "ipsec1" #12: Dead Peer Detection (RFC 3706): enabled
2011-07-18 11:47:59 pluto[431]: "ipsec1" #12: transition from state STATE_QUICK_R1 to state STATE_QUICK_R2
2011-07-18 11:47:59 pluto[431]: "ipsec1" #12: STATE_QUICK_R2: IPsec SA established tunnel mode {ESP=0xf05a1802 0x32e9fe4f xfrm=AES_128-HMAC_SHA1 NATOA=none NATD=none DPD=enabled}
****************************************
State: IPsec tunnel reestablished - OK
Action: Dev2 - another reboot
****************************************
2011-07-18 11:54:53 pluto[431]: packet from 10.0.3.114:500: received Vendor ID payload [Dead Peer Detection]
2011-07-18 11:54:53 pluto[431]: "ipsec1" #13: responding to Main Mode
2011-07-18 11:54:53 pluto[431]: "ipsec1" #13: transition from state STATE_MAIN_R0 to state STATE_MAIN_R1
2011-07-18 11:54:53 pluto[431]: "ipsec1" #13: STATE_MAIN_R1: sent MR1, expecting MI2
2011-07-18 11:54:54 pluto[431]: "ipsec1" #13: transition from state STATE_MAIN_R1 to state STATE_MAIN_R2
2011-07-18 11:54:55 pluto[431]: "ipsec1" #13: STATE_MAIN_R2: sent MR2, expecting MI3
2011-07-18 11:54:55 pluto[431]: "ipsec1" #13: Main mode peer ID is ID_IPV4_ADDR: '10.0.3.114'
2011-07-18 11:54:55 pluto[431]: "ipsec1" #13: transition from state STATE_MAIN_R2 to state STATE_MAIN_R3
2011-07-18 11:54:55 pluto[431]: "ipsec1" #13: STATE_MAIN_R3: sent MR3, ISAKMP SA established {auth=OAKLEY_PRESHARED_KEY cipher=aes_128 prf=oakley_sha group=modp2048}
2011-07-18 11:54:55 pluto[431]: "ipsec1" #13: Dead Peer Detection (RFC 3706): enabled
2011-07-18 11:54:55 pluto[431]: "ipsec1" #13: the peer proposed: 192.168.2.0/24:0/0 - 192.168.3.0/24:0/0
2011-07-18 11:54:55 pluto[431]: "ipsec1" #14: responding to Quick Mode proposal {msgid:579b2969}
2011-07-18 11:54:55 pluto[431]: "ipsec1" #14:     us: 192.168.2.0/24===10.0.2.125
2011-07-18 11:54:55 pluto[431]: "ipsec1" #14:   them: 10.0.3.114===192.168.3.0/24
2011-07-18 11:54:55 pluto[431]: | NAT-OA: 0 tunnel: 0  
2011-07-18 11:54:55 pluto[431]: "ipsec1" #14: keeping refhim=4294901761 during rekey
2011-07-18 11:54:55 pluto[431]: "ipsec1" #14: transition from state STATE_QUICK_R0 to state STATE_QUICK_R1
2011-07-18 11:54:55 pluto[431]: "ipsec1" #14: STATE_QUICK_R1: sent QR1, inbound IPsec SA installed, expecting QI2
2011-07-18 11:54:56 pluto[431]: "ipsec1" #14: Dead Peer Detection (RFC 3706): enabled
2011-07-18 11:54:56 pluto[431]: "ipsec1" #14: transition from state STATE_QUICK_R1 to state STATE_QUICK_R2
2011-07-18 11:54:56 pluto[431]: "ipsec1" #14: STATE_QUICK_R2: IPsec SA established tunnel mode {ESP=0xbd885898 0x1b084a6f xfrm=AES_128-HMAC_SHA1 NATOA=none NATD=none DPD=enabled}
2011-07-18 11:58:54 pluto[431]: packet from 10.0.3.114:500: received Vendor ID payload [Dead Peer Detection]
2011-07-18 11:58:54 pluto[431]: "ipsec1" #15: responding to Main Mode
2011-07-18 11:58:54 pluto[431]: "ipsec1" #15: transition from state STATE_MAIN_R0 to state STATE_MAIN_R1
2011-07-18 11:58:54 pluto[431]: "ipsec1" #15: STATE_MAIN_R1: sent MR1, expecting MI2
2011-07-18 11:58:54 pluto[431]: ERROR: asynchronous network error report on ppp0 (sport=500) for message to 10.0.3.114 port 500, complainant 10.1.0.21: No route to host [errno 113, origin ICMP type 3 code 1 (not authenticated)]
2011-07-18 11:59:04 pluto[431]: packet from 10.0.3.114:500: received Vendor ID payload [Dead Peer Detection]
2011-07-18 11:59:04 pluto[431]: "ipsec1" #16: responding to Main Mode
2011-07-18 11:59:04 pluto[431]: "ipsec1" #16: transition from state STATE_MAIN_R0 to state STATE_MAIN_R1
2011-07-18 11:59:04 pluto[431]: "ipsec1" #16: STATE_MAIN_R1: sent MR1, expecting MI2
2011-07-18 11:59:06 pluto[431]: "ipsec1" #15: transition from state STATE_MAIN_R1 to state STATE_MAIN_R2
2011-07-18 11:59:06 pluto[431]: "ipsec1" #15: STATE_MAIN_R2: sent MR2, expecting MI3
2011-07-18 11:59:07 pluto[431]: "ipsec1" #15: Main mode peer ID is ID_IPV4_ADDR: '10.0.3.114'
2011-07-18 11:59:07 pluto[431]: "ipsec1" #15: transition from state STATE_MAIN_R2 to state STATE_MAIN_R3
2011-07-18 11:59:07 pluto[431]: "ipsec1" #15: STATE_MAIN_R3: sent MR3, ISAKMP SA established {auth=OAKLEY_PRESHARED_KEY cipher=aes_128 prf=oakley_sha group=modp2048}
2011-07-18 11:59:07 pluto[431]: "ipsec1" #15: Dead Peer Detection (RFC 3706): enabled
2011-07-18 11:59:07 pluto[431]: "ipsec1" #15: the peer proposed: 192.168.2.0/24:0/0 - 192.168.3.0/24:0/0
2011-07-18 11:59:07 pluto[431]: "ipsec1" #17: responding to Quick Mode proposal {msgid:56b0ce8b}
2011-07-18 11:59:07 pluto[431]: "ipsec1" #17:     us: 192.168.2.0/24===10.0.2.125
2011-07-18 11:59:07 pluto[431]: "ipsec1" #17:   them: 10.0.3.114===192.168.3.0/24
2011-07-18 11:59:07 pluto[431]: | NAT-OA: 0 tunnel: 0  
2011-07-18 11:59:07 pluto[431]: "ipsec1" #17: keeping refhim=4294901761 during rekey
2011-07-18 11:59:07 pluto[431]: "ipsec1" #17: transition from state STATE_QUICK_R0 to state STATE_QUICK_R1
2011-07-18 11:59:07 pluto[431]: "ipsec1" #17: STATE_QUICK_R1: sent QR1, inbound IPsec SA installed, expecting QI2
2011-07-18 11:59:07 pluto[431]: "ipsec1" #17: ERROR: netlink response for Add SA esp.b056df3 at 10.0.3.114 included errno 17: File exists
****************************************
State: error encountered, nothing important happens for next 45 minutes
****************************************
2011-07-18 11:59:17 pluto[431]: "ipsec1" #17: discarding duplicate packet; already STATE_QUICK_R1
2011-07-18 11:59:38 last message repeated 1 time
2011-07-18 12:00:14 pluto[431]: "ipsec1" #16: max number of retransmissions (2) reached STATE_MAIN_R1
2011-07-18 12:12:17 pluto[431]: "ipsec1" #17: max number of retransmissions (20) reached STATE_QUICK_R1
2011-07-18 12:44:07 pluto[431]: packet from 10.0.3.114:500: received Vendor ID payload [Dead Peer Detection]
2011-07-18 12:44:07 pluto[431]: "ipsec1" #18: responding to Main Mode
2011-07-18 12:44:07 pluto[431]: "ipsec1" #18: transition from state STATE_MAIN_R0 to state STATE_MAIN_R1
2011-07-18 12:44:07 pluto[431]: "ipsec1" #18: STATE_MAIN_R1: sent MR1, expecting MI2
2011-07-18 12:44:09 pluto[431]: "ipsec1" #18: transition from state STATE_MAIN_R1 to state STATE_MAIN_R2
2011-07-18 12:44:09 pluto[431]: "ipsec1" #18: STATE_MAIN_R2: sent MR2, expecting MI3
2011-07-18 12:44:09 pluto[431]: "ipsec1" #18: Main mode peer ID is ID_IPV4_ADDR: '10.0.3.114'
2011-07-18 12:44:09 pluto[431]: "ipsec1" #18: transition from state STATE_MAIN_R2 to state STATE_MAIN_R3
2011-07-18 12:44:09 pluto[431]: "ipsec1" #18: STATE_MAIN_R3: sent MR3, ISAKMP SA established {auth=OAKLEY_PRESHARED_KEY cipher=aes_128 prf=oakley_sha group=modp2048}
2011-07-18 12:44:09 pluto[431]: "ipsec1" #18: Dead Peer Detection (RFC 3706): enabled
2011-07-18 12:45:44 pluto[431]: "ipsec1" #18: the peer proposed: 192.168.2.0/24:0/0 - 192.168.3.0/24:0/0
2011-07-18 12:45:44 pluto[431]: "ipsec1" #19: responding to Quick Mode proposal {msgid:4ae48898}
2011-07-18 12:45:44 pluto[431]: "ipsec1" #19:     us: 192.168.2.0/24===10.0.2.125
2011-07-18 12:45:44 pluto[431]: "ipsec1" #19:   them: 10.0.3.114===192.168.3.0/24
2011-07-18 12:45:44 pluto[431]: | NAT-OA: 0 tunnel: 0  
2011-07-18 12:45:44 pluto[431]: "ipsec1" #19: keeping refhim=4294901761 during rekey
2011-07-18 12:45:44 pluto[431]: "ipsec1" #19: transition from state STATE_QUICK_R0 to state STATE_QUICK_R1
2011-07-18 12:45:44 pluto[431]: "ipsec1" #19: STATE_QUICK_R1: sent QR1, inbound IPsec SA installed, expecting QI2
2011-07-18 12:45:45 pluto[431]: "ipsec1" #19: Dead Peer Detection (RFC 3706): enabled
2011-07-18 12:45:45 pluto[431]: "ipsec1" #19: transition from state STATE_QUICK_R1 to state STATE_QUICK_R2
2011-07-18 12:45:45 pluto[431]: "ipsec1" #19: STATE_QUICK_R2: IPsec SA established tunnel mode {ESP=0xe8a79ed2 0xa13d3474 xfrm=AES_128-HMAC_SHA1 NATOA=none NATD=none DPD=enabled}
****************************************
State: IPsec tunnel reestablished - OK
****************************************
2011-07-18 12:59:09 pluto[431]: "ipsec1" #18: ignoring Delete SA payload: PROTO_IPSEC_ESP SA(0x0b056df3) not found (maybe expired)
2011-07-18 12:59:09 pluto[431]: "ipsec1" #18: received and ignored informational message
2011-07-18 12:59:09 pluto[431]: packet from 10.0.3.114:500: Informational Exchange is for an unknown (expired?) SA with MSGID:0xcbbeb8a1
 
 

========================================
Dev2 syslog listing (after last reboot)
========================================
2011-07-18 11:59:12 pluto[562]: Starting Pluto (Openswan Version 2.6.34) pid:562
2011-07-18 11:59:12 pluto[562]: LEAK_DETECTIVE support [disabled]
2011-07-18 11:59:12 pluto[562]: OCF support for IKE [disabled]
2011-07-18 11:59:12 pluto[562]: NSS support [disabled]
2011-07-18 11:59:12 pluto[562]: HAVE_STATSD notification support not compiled in
2011-07-18 11:59:12 pluto[562]: Setting NAT-Traversal port-4500 floating to off
2011-07-18 11:59:12 pluto[562]:    port floating activation criteria nat_t=0/port_float=1
2011-07-18 11:59:12 pluto[562]:    NAT-Traversal support  [disabled]
2011-07-18 11:59:12 pluto[562]: using /dev/urandom as source of random entropy
2011-07-18 11:59:12 pluto[562]: ike_alg_register_enc(): Activating OAKLEY_AES_CBC: Ok (ret=0)
2011-07-18 11:59:12 pluto[562]: no helpers will be started, all cryptographic operations will be done inline
2011-07-18 11:59:12 pluto[562]: Kernel interface auto-pick
2011-07-18 11:59:12 pluto[562]: Using Linux 2.6 IPsec interface code on 2.6.27_stm23_004 (experimental code)
2011-07-18 11:59:12 pluto[562]: ike_alg_register_enc(): Activating aes_ccm_8: Ok (ret=0)
2011-07-18 11:59:12 pluto[562]: ike_alg_add(): ERROR: Algorithm already exists
2011-07-18 11:59:12 pluto[562]: ike_alg_register_enc(): Activating aes_ccm_12: FAILED (ret=-17)
2011-07-18 11:59:12 pluto[562]: ike_alg_add(): ERROR: Algorithm already exists
2011-07-18 11:59:12 pluto[562]: ike_alg_register_enc(): Activating aes_ccm_16: FAILED (ret=-17)
2011-07-18 11:59:12 pluto[562]: ike_alg_add(): ERROR: Algorithm already exists
2011-07-18 11:59:12 pluto[562]: ike_alg_register_enc(): Activating aes_gcm_8: FAILED (ret=-17)
2011-07-18 11:59:12 pluto[562]: ike_alg_add(): ERROR: Algorithm already exists
2011-07-18 11:59:12 pluto[562]: ike_alg_register_enc(): Activating aes_gcm_12: FAILED (ret=-17)
2011-07-18 11:59:12 pluto[562]: ike_alg_add(): ERROR: Algorithm already exists
2011-07-18 11:59:12 pluto[562]: ike_alg_register_enc(): Activating aes_gcm_16: FAILED (ret=-17)
2011-07-18 11:59:12 pluto[562]: Changed path to directory '/etc/ipsec.d/cacerts'
2011-07-18 11:59:12 pluto[562]: Could not change to directory '/etc/ipsec.d/aacerts': /
2011-07-18 11:59:12 pluto[562]: Could not change to directory '/etc/ipsec.d/ocspcerts': /
2011-07-18 11:59:12 pluto[562]: Could not change to directory '/etc/ipsec.d/crls'
2011-07-18 11:59:13 pluto[562]: added connection description "ipsec1"
2011-07-18 11:59:13 pluto[562]: listening for IKE messages
2011-07-18 11:59:13 pluto[562]: adding interface ppp0/ppp0 10.0.3.114:500
2011-07-18 11:59:13 pluto[562]: adding interface eth0:1/eth0:1 192.168.2.151:500
2011-07-18 11:59:13 pluto[562]: adding interface eth0/eth0 192.168.3.151:500
2011-07-18 11:59:13 pluto[562]: loading secrets from "/etc/ipsec.d/ipsec.secrets"
2011-07-18 11:59:13 pluto[562]: "ipsec1" #1: initiating Main Mode
2011-07-18 11:59:13 pppd[528]: Script /etc/scripts/ip-up finished (pid 532), status = 0x0
2011-07-18 11:59:25 pluto[562]: "ipsec1" #1: received Vendor ID payload [Dead Peer Detection]
2011-07-18 11:59:25 pluto[562]: "ipsec1" #1: transition from state STATE_MAIN_I1 to state STATE_MAIN_I2
2011-07-18 11:59:25 pluto[562]: "ipsec1" #1: STATE_MAIN_I2: sent MI2, expecting MR2
2011-07-18 11:59:25 pluto[562]: packet from 10.0.2.125:500: phase 1 message is part of an unknown exchange
2011-07-18 11:59:27 pluto[562]: "ipsec1" #1: transition from state STATE_MAIN_I2 to state STATE_MAIN_I3
2011-07-18 11:59:27 pluto[562]: "ipsec1" #1: STATE_MAIN_I3: sent MI3, expecting MR3
2011-07-18 11:59:28 pluto[562]: "ipsec1" #1: Main mode peer ID is ID_IPV4_ADDR: '10.0.2.125'
2011-07-18 11:59:28 pluto[562]: "ipsec1" #1: transition from state STATE_MAIN_I3 to state STATE_MAIN_I4
2011-07-18 11:59:28 pluto[562]: "ipsec1" #1: STATE_MAIN_I4: ISAKMP SA established {auth=OAKLEY_PRESHARED_KEY cipher=aes_128 prf=oakley_sha group=modp2048}
2011-07-18 11:59:28 pluto[562]: "ipsec1" #1: Dead Peer Detection (RFC 3706): enabled
2011-07-18 11:59:28 pluto[562]: "ipsec1" #2: initiating Quick Mode PSK+ENCRYPT+TUNNEL+UP {using isakmp#1 msgid:8bceb056 proposal=defaults pfsgroup=no-pfs}
2011-07-18 11:59:28 pluto[562]: "ipsec1" #2: Dead Peer Detection (RFC 3706): enabled
2011-07-18 11:59:28 pluto[562]: "ipsec1" #2: transition from state STATE_QUICK_I1 to state STATE_QUICK_I2
2011-07-18 11:59:28 pluto[562]: "ipsec1" #2: STATE_QUICK_I2: sent QI2, IPsec SA established tunnel mode {ESP=0x6dce16fa 0x0b056df3 xfrm=AES_128-HMAC_SHA1 NATOA=none NATD=none DPD=enabled}
2011-07-18 11:59:38 pluto[562]: packet from 10.0.2.125:500: phase 1 message is part of an unknown exchange
2011-07-18 11:59:38 pluto[562]: "ipsec1" #2: retransmitting in response to duplicate packet; already STATE_QUICK_I2
2011-07-18 11:59:57 pluto[562]: packet from 10.0.2.125:500: phase 1 message is part of an unknown exchange
2011-07-18 11:59:58 pluto[562]: "ipsec1" #2: retransmitting in response to duplicate packet; already STATE_QUICK_I2
2011-07-18 12:00:40 pluto[562]: "ipsec1" #2: discarding duplicate packet -- exhausted retransmission; already STATE_QUICK_I2
2011-07-18 12:12:00 last message repeated 17 times
2011-07-18 12:43:30 pluto[562]: packet from 10.0.2.125:500: Informational Exchange is for an unknown (expired?) SA with MSGID:0xda76b0f3
2011-07-18 12:43:31 pluto[562]: "ipsec1" #1: ignoring Delete SA payload: PROTO_IPSEC_ESP SA(0x17354389) not found (maybe expired)
2011-07-18 12:43:31 pluto[562]: "ipsec1" #1: received and ignored informational message
2011-07-18 12:43:36 pluto[562]: "ipsec1" #1: ignoring Delete SA payload: PROTO_IPSEC_ESP SA(0x2d1cc833) not found (maybe expired)
2011-07-18 12:43:36 pluto[562]: "ipsec1" #1: received and ignored informational message
2011-07-18 12:43:36 pluto[562]: packet from 10.0.2.125:500: Informational Exchange is for an unknown (expired?) SA with MSGID:0xbc92b9a4
2011-07-18 12:44:26 pluto[562]: "ipsec1" #3: initiating Main Mode to replace #1
2011-07-18 12:44:28 pluto[562]: "ipsec1" #3: received Vendor ID payload [Dead Peer Detection]
2011-07-18 12:44:28 pluto[562]: "ipsec1" #3: transition from state STATE_MAIN_I1 to state STATE_MAIN_I2
2011-07-18 12:44:28 pluto[562]: "ipsec1" #3: STATE_MAIN_I2: sent MI2, expecting MR2
2011-07-18 12:44:30 pluto[562]: "ipsec1" #3: transition from state STATE_MAIN_I2 to state STATE_MAIN_I3
2011-07-18 12:44:30 pluto[562]: "ipsec1" #3: STATE_MAIN_I3: sent MI3, expecting MR3
2011-07-18 12:44:30 pluto[562]: "ipsec1" #3: Main mode peer ID is ID_IPV4_ADDR: '10.0.2.125'
2011-07-18 12:44:30 pluto[562]: "ipsec1" #3: transition from state STATE_MAIN_I3 to state STATE_MAIN_I4
2011-07-18 12:44:30 pluto[562]: "ipsec1" #3: STATE_MAIN_I4: ISAKMP SA established {auth=OAKLEY_PRESHARED_KEY cipher=aes_128 prf=oakley_sha group=modp2048}
2011-07-18 12:44:30 pluto[562]: "ipsec1" #3: Dead Peer Detection (RFC 3706): enabled
2011-07-18 12:46:03 pluto[562]: "ipsec1" #4: initiating Quick Mode PSK+ENCRYPT+TUNNEL+UP to replace #2 {using isakmp#3 msgid:9888e44a proposal=defaults pfsgroup=no-pfs}
2011-07-18 12:46:05 pluto[562]: "ipsec1" #4: Dead Peer Detection (RFC 3706): enabled
2011-07-18 12:46:05 pluto[562]: "ipsec1" #4: transition from state STATE_QUICK_I1 to state STATE_QUICK_I2
2011-07-18 12:46:05 pluto[562]: "ipsec1" #4: STATE_QUICK_I2: sent QI2, IPsec SA established tunnel mode {ESP=0xa13d3474 0xe8a79ed2 xfrm=AES_128-HMAC_SHA1 NATOA=none NATD=none DPD=enabled}
2011-07-18 12:48:21 pluto[562]: packet from 10.0.2.125:500: Informational Exchange is for an unknown (expired?) SA with MSGID:0x88fdae94
2011-07-18 12:48:21 pluto[562]: "ipsec1" #3: ignoring Delete SA payload: PROTO_IPSEC_ESP SA(0x32e9fe4f) not found (maybe expired)
2011-07-18 12:48:21 pluto[562]: "ipsec1" #3: received and ignored informational message
2011-07-18 12:55:18 pluto[562]: packet from 10.0.2.125:500: Informational Exchange is for an unknown (expired?) SA with MSGID:0x1dd8ee22
2011-07-18 12:55:18 pluto[562]: "ipsec1" #3: ignoring Delete SA payload: PROTO_IPSEC_ESP SA(0x1b084a6f) not found (maybe expired)
2011-07-18 12:55:18 pluto[562]: "ipsec1" #3: received and ignored informational message
2011-07-18 12:59:29 pluto[562]: packet from 10.0.2.125:500: Informational Exchange is for an unknown (expired?) SA with MSGID:0x7a8c1104
-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://lists.openswan.org/pipermail/users/attachments/20110719/fd812e91/attachment-0001.html

More information about the Users mailing list