[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 12:53:19 EDT 2011


> 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).

Q: If the powercycled unit comes back on, and reconnects to the other unit, the IPsec SA should be re-established
and the older SA on the unit that did not get power cycled should get replaced. Are you not seeing that
happening?
 
R: I am not sure. If I select appropriate lines from syslog listing from Dev1 then I can see this:
****************************************
Action: Dev2 - power on
****************************************
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}
****************************************
Action: Dev2 - reboot
****************************************
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}
****************************************
Action: Dev2 - another reboot
****************************************
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
 
IPsec SA probably gets replaced on Dev1 after first reboot but another reboot results in error. I suppose the reason is SPI 0b056df3 which is the same as after power on. So the file (whatever it means in this case) really exists and must not be replaced.
 
Q: Are you using our initscripts or are you starting pluto manually? If manually do you start pluto
with --uniqueids ?
 
R: I am starting pluto manually with --uniqueids as you can see in my first email.
 
Do you think I should use one of --debug-* options? Would it help to solve the problem?
 
L. Felgr
 
> 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/7e799cbc/attachment-0001.html 


More information about the Users mailing list