[Openswan Users] Tunnel didn't renegociate

Luc Paulin paulinster at gmail.com
Tue Oct 26 12:25:12 EDT 2010


Sorry for late response,
I did look again at the logs and the only thing that I found is the
following...

- The first time the rekey start having issue
Oct 19 16:17:03 fwny-01 pluto[14450]: "nyctomtl" #1082: initiating Quick
Mode PSK+ENCRYPT+TUNNEL+PFS+UP+IKEv2ALLOW to replace #1078 {using
isakmp#1081 msgid:
9d32925c proposal=AES(12)_128-SHA1(2)_160 pfsgroup=OAKLEY_GROUP_MODP2048}
Oct 19 16:17:03 fwny-01 pluto[14450]: pluto_do_crypto: helper (-1) is
exiting
Oct 19 16:18:13 fwny-01 pluto[14450]: "nyctomtl" #1082: max number of
retransmissions (2) reached STATE_QUICK_I1
Oct 19 16:18:13 fwny-01 pluto[14450]: "nyctomtl" #1082: starting keying
attempt 2 of an unlimited number
Oct 19 16:18:13 fwny-01 pluto[14450]: "nyctomtl" #1083: initiating Quick
Mode PSK+ENCRYPT+TUNNEL+PFS+UP+IKEv2ALLOW to replace #1082 {using
isakmp#1081 msgid:
b28a638a proposal=AES(12)_128-SHA1(2)_160 pfsgroup=OAKLEY_GROUP_MODP2048}
Oct 19 16:18:13 fwny-01 pluto[14450]: pluto_do_crypto: helper (-1) is
exiting
Oct 19 16:19:23 fwny-01 pluto[14450]: "nyctomtl" #1083: max number of
retransmissions (2) reached STATE_QUICK_I1

- Then later on it look like it did rekey successfully
Oct 19 16:28:59 fwny-01 pluto[14450]: "nyctomtl" #1081: the peer proposed:
5.6.7.2/32:0/0 -> 1.2.3.176/32:0/0
Oct 19 16:28:59 fwny-01 pluto[14450]: packet from 1.2.3.176:500:
pluto_do_crypto: helper (-1) is  exiting
Oct 19 16:28:59 fwny-01 pluto[14450]: packet from 1.2.3.176:500:
pluto_do_crypto: helper (-1) is  exiting
Oct 19 16:28:59 fwny-01 pluto[14450]: "nyctomtl" #1093: responding to Quick
Mode proposal {msgid:489be973}
Oct 19 16:28:59 fwny-01 pluto[14450]: "nyctomtl" #1093:     us:
5.6.7.2<5.6.7.2>[+S=C]---5.6.7.1
Oct 19 16:28:59 fwny-01 pluto[14450]: "nyctomtl" #1093:   them:
1.2.3.161---1.2.3.176<1.2.3.176>[+S=C]
Oct 19 16:28:59 fwny-01 pluto[14450]: "nyctomtl" #1093: keeping
refhim=4294901761 during rekey
Oct 19 16:28:59 fwny-01 pluto[14450]: "nyctomtl" #1093: transition from
state STATE_QUICK_R0 to state STATE_QUICK_R1
Oct 19 16:28:59 fwny-01 pluto[14450]: "nyctomtl" #1093: STATE_QUICK_R1: sent
QR1, inbound IPsec SA installed, expecting QI2
Oct 19 16:28:59 fwny-01 pluto[14450]: "nyctomtl" #1093: transition from
state STATE_QUICK_R1 to state STATE_QUICK_R2
Oct 19 16:28:59 fwny-01 pluto[14450]: "nyctomtl" #1093: STATE_QUICK_R2:
IPsec SA established tunnel mode {ESP=>0x131f16c4 <0xf0ec3aea
xfrm=AES_128-HMAC_SHA1 NATOA=none NATD=none DPD=none}

- Then I got the following error
Oct 19 16:29:13 fwny-01 pluto[14450]: packet from 1.2.3.176:500:
pluto_do_crypto: helper (-1) is  exiting
Oct 19 16:29:13 fwny-01 pluto[14450]: "nyctomtl" #1092: ERROR: netlink
response for Add SA esp.fe9f0294 at 5.6.7.2 included errno 3: No such process

- Followed by another successful rekey
Oct 19 16:29:23 fwny-01 pluto[14450]: "nyctomtl" #1092: discarding duplicate
packet; already STATE_QUICK_I1
Oct 19 16:29:43 fwny-01 pluto[14450]: "nyctomtl" #1092: discarding duplicate
packet; already STATE_QUICK_I1
Oct 19 16:29:53 fwny-01 pluto[14450]: "nyctomtl" #1092: max number of
retransmissions (2) reached STATE_QUICK_I1
Oct 19 16:29:53 fwny-01 pluto[14450]: "nyctomtl" #1092: starting keying
attempt 12 of an unlimited number
Oct 19 16:29:53 fwny-01 pluto[14450]: "nyctomtl" #1094: initiating Quick
Mode PSK+ENCRYPT+TUNNEL+PFS+UP+IKEv2ALLOW to replace #1092 {using
isakmp#1081 msgid:1db0213c proposal=AES(12)_128-SHA1(2)_160
pfsgroup=OAKLEY_GROUP_MODP2048}
Oct 19 16:29:53 fwny-01 pluto[14450]: pluto_do_crypto: helper (-1) is
exiting
Oct 19 16:29:53 fwny-01 pluto[14450]: packet from 1.2.3.176:500:
pluto_do_crypto: helper (-1) is  exiting
Oct 19 16:29:53 fwny-01 pluto[14450]: "nyctomtl" #1094: transition from
state STATE_QUICK_I1 to state STATE_QUICK_I2
Oct 19 16:29:53 fwny-01 pluto[14450]: "nyctomtl" #1094: STATE_QUICK_I2: sent
QI2, IPsec SA established tunnel mode {ESP=>0xfe19fa23 <0xd356a43e
xfrm=AES_128-HMAC_SHA1 NATOA=none NATD=none DPD=none}

- After that a series of the following PAYLOAD MALFORMED show every 40 sec
for 11 minutes dans then stop
Oct 19 16:30:23 fwny-01 pluto[14450]: "nyctomtl" #1081: byte 2 of ISAKMP
Hash Payload must be zero, but is not
Oct 19 16:30:23 fwny-01 pluto[14450]: "nyctomtl" #1081: malformed payload in
packet
Oct 19 16:30:23 fwny-01 pluto[14450]: | payload malformed after IV
Oct 19 16:30:23 fwny-01 pluto[14450]: |   7b dc cc 64  50 a7 f7 59  cb f2 c9
85  34 40 a3 ec
Oct 19 16:30:23 fwny-01 pluto[14450]: "nyctomtl" #1081: sending notification
PAYLOAD_MALFORMED to 1.2.3.176:500
<-- same messages every 40sec -->
Oct 19 16:41:03 fwny-01 pluto[14450]: "nyctomtl" #1081: byte 2 of ISAKMP
Hash Payload must be zero, but is not
Oct 19 16:41:03 fwny-01 pluto[14450]: "nyctomtl" #1081: malformed payload in
packet
Oct 19 16:41:03 fwny-01 pluto[14450]: "nyctomtl" #1081: too many (17)
malformed payloads. Deleting state
Oct 19 16:41:03 fwny-01 pluto[14450]: packet from 1.2.3.176:500:
Informational Exchange is for an unknown (expired?) SA with MSGID:0x004c46ad
Oct 19 16:41:43 fwny-01 pluto[14450]: packet from 1.2.3.176:500: Quick Mode
message is for a non-existent (expired?) ISAKMP SA

- Then nothing happen until the SA expire and no more connection was show to
be active
Oct 20 04:29:53 fwny-01 pluto[14450]: "nyctomtl" #1094: IPsec SA expired
(LATEST!)

For the past couples of month the vpn was'nt very stable. We would really
like to know what happen to prevent other vpn issues. If this can help
here's the connection config

conn nyc
        authby=secret
        pfs=yes
        left=1.2.3.176
        leftnexthop=1.2.3.161
        right=5.6.7.2
        rightnexthop=5.6.7.1
        auto=start
        esp=aes128-sha1
    salifetime=12h
    ikelifetime=4h






2010/10/20 Luc Paulin <paulinster at gmail.com>

>
>
> 2010/10/20 Paul Wouters <paul at xelerance.com>
>
> On Wed, 20 Oct 2010, Luc Paulin wrote:
>>
>>  a lots of error a the last key exchange that happen before the tunnel
>>> went down.
>>>
>>> Oct 19 16:17:03 fwny-01 pluto[14450]: "nyctomtl" #1082: initiating Quick
>>> Mode PSK+ENCRYPT+TUNNEL+PFS+UP+IKEv2ALLOW to replace #1078
>>> {using isakmp#1081 msgid:9d32925c proposal=AES(12)_128-SHA1(2)_160
>>> pfsgroup=OAKLEY_GROUP_MODP2048}
>>> Oct 19 16:17:03 fwny-01 pluto[14450]: pluto_do_crypto: helper (-1) is
>>> exiting
>>> Oct 19 16:18:13 fwny-01 pluto[14450]: "nyctomtl" #1082: max number of
>>> retransmissions (2) reached STATE_QUICK_I1
>>> Oct 19 16:18:13 fwny-01 pluto[14450]: "nyctomtl" #1082: starting keying
>>> attempt 2 of an unlimited number
>>>
>>>
>>> Oct 19 16:29:13 fwny-01 pluto[14450]: packet from 1.2.3.4:500:
>>> pluto_do_crypto: helper (-1) is  exiting
>>> ATOA=none NATD=none DPD=none}
>>> Oct 19 16:29:13 fwny-01 pluto[14450]: packet from 1.2.3.4:500:
>>> pluto_do_crypto: helper (-1) is  exiting
>>> Oct 19 16:29:13 fwny-01 pluto[14450]: "nyctomtl" #1092: ERROR: netlink
>>> response for Add SA esp.fe9f0294 at 4.3.2.1 included errno 3: No
>>> such process
>>>
>>
>> Did you run out of memory?
>>
>>
> No .. logs show nothing wrong and cacti do not show anything wrong with
> memory and/or cpu...
>
>
>
>>
>>  I am trying to understand what happen but since this was working fine for
>>> the past 2-3 month I am not to understand why the rekey
>>> would have fail this time. I can provide a more detail log as well as the
>>> configuration info if needed.
>>>
>>
>> I am not entirely sure. Perhaps other log messages show a problem?
>>
>>
> I'll give another look at the logs, but so far I didn't catch anything
> which would explain the issue..
>
>    -Luc
>
>
> --
>                          !!!!!
>                        ( o o )
>  --------------oOO----(_)----OOo--------------
> Luc Paulin  |  paulinster(at)gmail.com
>
>
>


-- 
                         !!!!!
                       ( o o )
 --------------oOO----(_)----OOo--------------
Luc Paulin  |  paulinster(at)gmail.com
-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://lists.openswan.org/pipermail/users/attachments/20101026/43e19863/attachment.html 


More information about the Users mailing list