[Swan] Aggressive mode not possible with Juniper Netscreen
Philippe Vouters
philippe.vouters at laposte.net
Tue Jan 22 13:34:00 EET 2013
Dear Elison,
Reading the code producing this trace (routine process_v1_packet, file:
./libreswan/programs/pluto/ikev1.c):
Jan 21 09:53:51 elisonniven pluto[4299]: "jun" #1: Quick Mode message
is unacceptable because it is for an incomplete ISAKMP SA
which appears AFTER:
Jan 21 09:53:47 elisonniven pluto[4299]: "jun" #1: STATE_AGGR_R1:
sent AR1, expecting AI2
Jan 21 09:53:47 elisonniven pluto[4299]: | modecfg pull: noquirk
policy:push not-client
Jan 21 09:53:47 elisonniven pluto[4299]: | phase 1 is done, looking
for phase 2 to unpend
leads to:
if (!IS_ISAKMP_SA_ESTABLISHED(st->st_state))
{
loglog(RC_LOG_SERIOUS, "Quick Mode message is
unacceptable because"
" it is for an incomplete ISAKMP SA");
SEND_NOTIFICATION(PAYLOAD_MALFORMED /* XXX ? */);
return;
}
In consequence, the message "phase 1 is done, looking
for phase 2 to unpen" apparently seems to be misleading. Anyhow it
confused me.
Those past days I have been changing IS_PHASE1 to
IS_ISAKMP_SA_ESTABLISHED inside the above mentioned routine for a
racoon/iphone issue which highlighted Libreswan not respecting this RFC
you can read at
http://www.ietf.org/proceedings/43/I-D/draft-ietf-ipsec-isakmp-mode-cfg-04.txt
This Libreswan trace draws all my current attention:
Jan 21 09:53:47 elisonniven pluto[4299]: | modecfg pull: noquirk
As you rebuilt Libreswan from sources, would you be so kind as to copy
the original ./libreswan/programs/pluto/ikev1.c file to a safe place,
patch this file in your Libreswan source tree with the attached .diff
and give me news upon how Libreswan now behaves with Netscreen when
running this patch.
Thanks in advance and regards,
Philippe Vouters (Fontainebleau/France)
URL: http://vouters.dyndns.org/
SIP: sip:Vouters at sip.linphone.org
Le 22/01/2013 11:38, Elison Niven a écrit :
> Hi,
>
> Also Phase 1 on Libreswan is not complete as ipsec auto --status does
> not say that ISAKMP SA established.
> #ipsec auto --status | tail
> 000 #527: "jun":500 STATE_AGGR_R1 (sent AR1, expecting AI2);
> EVENT_RETRANSMIT in 22s; nodpd; idle; import:respond to stranger
>
> On Tuesday 22 January 2013 09:28:53 AM IST, Elison Niven wrote:
>> Hi,
>>
>> Thanks.
>> But then libreswan says:
>> Jan 21 09:53:47 elisonniven pluto[4299]: "jun" #1: Quick Mode message
>> is unacceptable because it is for an incomplete ISAKMP SA"
>>
>> On Monday 21 January 2013 06:45:50 PM IST, Philippe Vouters wrote:
>>> I am NOT misleading you at all. Read your traces. Libreswan says this:
>>>
>>> Jan 21 09:53:47 elisonniven pluto[4299]: | phase 1 is done, looking
>>> for phase 2 to unpend
>>> Jan 21 09:53:47 elisonniven pluto[4299]: | complete state transition
>>> with STF_INLINE
>>> Jan 21 09:53:47 elisonniven pluto[4299]: | complete state transition
>>> with STF_INLINE
>>>
>>> So Libreswan is already in phase 2 before it says:
>>>
>>> Jan 21 09:53:47 elisonniven pluto[4299]: "jun" #1: packet rejected:
>>> should have been encrypted
>>> Jan 21 09:53:47 elisonniven pluto[4299]: "jun" #1: sending
>>> notification INVALID_FLAGS to 10.103.2.75:500
>>> Jan 21 09:53:47 elisonniven pluto[4299]: | sending 40 bytes for
>>> notification packet through p18p1:500 to 10.103.2.75:500 (using #1)
>>>
>>> And you should retrieve this INVALID_FLAGS notification from
>>> Libnreswan in your Netscreen traces. Set Netscreen to a more
>>> appropriate log level and you'll find this notification.
>>>
>>> Philippe Vouters (Fontainebleau/France)
>>> URL: http://vouters.dyndns.org/
>>> SIP: sip:Vouters at sip.linphone.org
>>>
>>> Le 21/01/2013 12:01, Elison Niven a écrit :
>>>> No, you are mistaken.
>>>> According to Netscreen, Phase 1 is completed.
>>>> According to Libreswan, Phase 1 is incomplete.
>>>> These logs are of the Netscreen :
>>>> 2013-01-18 21:19:38 info IKE<10.103.6.114> Phase 2: Initiated
>>>> negotiations.
>>>>
>>>> On Monday 21 January 2013 04:26:59 PM IST, Philippe Vouters wrote:
>>>>> Hi,
>>>>>
>>>>> Run Wireshark on the Libreswan side and locate the network packet
>>>>> coming from Netscreen which is not using the ESP protocol when it
>>>>> should. According to your Libreswan traces, you are in phase 2.
>>>>>
>>>>> Philippe Vouters (Fontainebleau/France)
>>>>> URL: http://vouters.dyndns.org/
>>>>> SIP: sip:Vouters at sip.linphone.org
>>>>>
>>>>> Le 21/01/2013 05:25, Elison Niven a écrit :
>>>>>> Hi,
>>>>>>
>>>>>> On Sunday 20 January 2013 04:54:43 AM IST, Paul Wouters wrote:
>>>>>>> On Fri, 18 Jan 2013, Philippe Vouters wrote:
>>>>>>>
>>>>>>>> In summary, it looks to me there are two issues here :
>>>>>>>>
>>>>>>>> 1/ Libreswan could be wrongly issuing the packet rejected message
>>>>>>>> meanwhile taking the corresponding action.
>>>>>>>> 2/ Another problem you seem to face is on your Netscreen side
>>>>>>>> (your
>>>>>>>> traces). At the time of the Libreswan packet rejected message,
>>>>>>>> Netscreen would wrongly assume it is already phase 2 while
>>>>>>>> Libreswan
>>>>>>>> is still keeping in phase 1.
>>>>>>>
>>>>>>> I'm pretty sure this is 2)
>>>>>>>
>>>>>>> There is a mismatch in configuration.
>>>>>>>
>>>>>> I do not see how this is a mismatch in the configuration as when
>>>>>> Libreswan initiates the connection, it is working fine!
>>>>>>
>>>>>> Here are the logs on libreswan with plutodebug=control :
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: |
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: | *received 324 bytes from
>>>>>> 10.103.2.75:500 on p18p1 (port=500)
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: | processing version=1.0
>>>>>> packet with exchange type=ISAKMP_XCHG_AGGR (4)
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: packet from
>>>>>> 10.103.2.75:500:
>>>>>> ignoring unknown Vendor ID payload
>>>>>> [4a4340b543e02b84c88a8b96a8af9ebe77d9accc0000000b00000500]
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: packet from
>>>>>> 10.103.2.75:500:
>>>>>> received Vendor ID payload [draft-ietf-ipsec-nat-t-ike-00]
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: packet from
>>>>>> 10.103.2.75:500:
>>>>>> ignoring Vendor ID payload [HeartBeat Notify 386b0100]
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: | creating state object #1
>>>>>> at 0x988ffc8
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: "jun" #1: Aggressive mode
>>>>>> peer ID is ID_IPV4_ADDR: '10.103.2.75'
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: | started looking for
>>>>>> secret
>>>>>> for 10.103.6.114->10.103.2.75 of kind PPK_PSK
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: | actually looking for
>>>>>> secret for 10.103.6.114->10.103.2.75 of kind PPK_PSK
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: | 1: compared key
>>>>>> 10.103.2.75 to 10.103.6.114 / 10.103.2.75 -> 4
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: | 2: compared key
>>>>>> 10.103.6.114 to 10.103.6.114 / 10.103.2.75 -> 12
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: | line 4: match=12
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: | best_match 0>12
>>>>>> best=0x988cbb0 (line=4)
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: | 1: compared key %any to
>>>>>> 10.103.6.114 / 10.103.2.75 -> 2
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: | 2: compared key
>>>>>> 10.103.6.114 to 10.103.6.114 / 10.103.2.75 -> 10
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: | line 3: match=10
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: | match(10) was not
>>>>>> best_match(12)
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: | 1: compared key
>>>>>> 10.103.7.41 to 10.103.6.114 / 10.103.2.75 -> 0
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: | 2: compared key
>>>>>> 10.103.6.114 to 10.103.6.114 / 10.103.2.75 -> 8
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: | line 2: match=8
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: | 1: compared key
>>>>>> 10.103.7.155 to 10.103.6.114 / 10.103.2.75 -> 0
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: | 2: compared key
>>>>>> 10.103.6.114 to 10.103.6.114 / 10.103.2.75 -> 8
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: | line 1: match=8
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: | concluding with
>>>>>> best_match=12 best=0x988cbb0 (lineno=4)
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: | offered CA: '%none'
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: | processing connection jun
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: | ICOOKIE: 6c 23 d9 65 fa
>>>>>> 87 ba 23
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: | RCOOKIE: 94 46 8a 37 2d
>>>>>> 46 ff 8d
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: | state hash entry 23
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: | inserting state object #1
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: | inserting event
>>>>>> EVENT_SO_DISCARD, timeout in 0 seconds for #1
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: "jun" #1: responding to
>>>>>> Aggressive Mode, state #1, connection "jun" from 10.103.2.75
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: "jun" #1: enabling possible
>>>>>> NAT-traversal with method draft-ietf-ipsec-nat-t-ike-00/01
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: | started looking for
>>>>>> secret
>>>>>> for 10.103.6.114->10.103.2.75 of kind PPK_PSK
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: | actually looking for
>>>>>> secret for 10.103.6.114->10.103.2.75 of kind PPK_PSK
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: | 1: compared key
>>>>>> 10.103.2.75 to 10.103.6.114 / 10.103.2.75 -> 4
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: | 2: compared key
>>>>>> 10.103.6.114 to 10.103.6.114 / 10.103.2.75 -> 12
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: | line 4: match=12
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: | best_match 0>12
>>>>>> best=0x988cbb0 (line=4)
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: | 1: compared key %any to
>>>>>> 10.103.6.114 / 10.103.2.75 -> 2
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: | 2: compared key
>>>>>> 10.103.6.114 to 10.103.6.114 / 10.103.2.75 -> 10
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: | line 3: match=10
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: | match(10) was not
>>>>>> best_match(12)
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: | 1: compared key
>>>>>> 10.103.7.41 to 10.103.6.114 / 10.103.2.75 -> 0
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: | 2: compared key
>>>>>> 10.103.6.114 to 10.103.6.114 / 10.103.2.75 -> 8
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: | line 2: match=8
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: | 1: compared key
>>>>>> 10.103.7.155 to 10.103.6.114 / 10.103.2.75 -> 0
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: | 2: compared key
>>>>>> 10.103.6.114 to 10.103.6.114 / 10.103.2.75 -> 8
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: | line 1: match=8
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: | concluding with
>>>>>> best_match=12 best=0x988cbb0 (lineno=4)
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: | helper -1 doing
>>>>>> build_kenonce op id: 0
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: | processing connection jun
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: | started looking for
>>>>>> secret
>>>>>> for 10.103.6.114->10.103.2.75 of kind PPK_PSK
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: | actually looking for
>>>>>> secret for 10.103.6.114->10.103.2.75 of kind PPK_PSK
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: | 1: compared key
>>>>>> 10.103.2.75 to 10.103.6.114 / 10.103.2.75 -> 4
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: | 2: compared key
>>>>>> 10.103.6.114 to 10.103.6.114 / 10.103.2.75 -> 12
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: | line 4: match=12
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: | best_match 0>12
>>>>>> best=0x988cbb0 (line=4)
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: | 1: compared key %any to
>>>>>> 10.103.6.114 / 10.103.2.75 -> 2
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: | 2: compared key
>>>>>> 10.103.6.114 to 10.103.6.114 / 10.103.2.75 -> 10
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: | line 3: match=10
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: | match(10) was not
>>>>>> best_match(12)
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: | 1: compared key
>>>>>> 10.103.7.41 to 10.103.6.114 / 10.103.2.75 -> 0
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: | 2: compared key
>>>>>> 10.103.6.114 to 10.103.6.114 / 10.103.2.75 -> 8
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: | line 2: match=8
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: | 1: compared key
>>>>>> 10.103.7.155 to 10.103.6.114 / 10.103.2.75 -> 0
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: | 2: compared key
>>>>>> 10.103.6.114 to 10.103.6.114 / 10.103.2.75 -> 8
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: | line 1: match=8
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: | concluding with
>>>>>> best_match=12 best=0x988cbb0 (lineno=4)
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: | parent1 type: 7 group: 2
>>>>>> len: 2680
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: | helper -1 doing compute
>>>>>> dh+iv op id: 0
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: | processing connection jun
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: | thinking about whether to
>>>>>> send my certificate:
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: | I have RSA key:
>>>>>> OAKLEY_PRESHARED_KEY cert.type: CERT_NONE
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: | sendcert:
>>>>>> CERT_ALWAYSSEND and I did not get a certificate request
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: | so do not send cert.
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: | I did not send a
>>>>>> certificate because digital signatures are not being used. (PSK)
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: | I am not sending a
>>>>>> certificate request
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: | started looking for
>>>>>> secret
>>>>>> for 10.103.6.114->10.103.2.75 of kind PPK_PSK
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: | actually looking for
>>>>>> secret for 10.103.6.114->10.103.2.75 of kind PPK_PSK
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: | 1: compared key
>>>>>> 10.103.2.75 to 10.103.6.114 / 10.103.2.75 -> 4
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: | 2: compared key
>>>>>> 10.103.6.114 to 10.103.6.114 / 10.103.2.75 -> 12
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: | line 4: match=12
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: | best_match 0>12
>>>>>> best=0x988cbb0 (line=4)
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: | 1: compared key %any to
>>>>>> 10.103.6.114 / 10.103.2.75 -> 2
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: | 2: compared key
>>>>>> 10.103.6.114 to 10.103.6.114 / 10.103.2.75 -> 10
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: | line 3: match=10
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: | match(10) was not
>>>>>> best_match(12)
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: | 1: compared key
>>>>>> 10.103.7.41 to 10.103.6.114 / 10.103.2.75 -> 0
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: | 2: compared key
>>>>>> 10.103.6.114 to 10.103.6.114 / 10.103.2.75 -> 8
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: | line 2: match=8
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: | 1: compared key
>>>>>> 10.103.7.155 to 10.103.6.114 / 10.103.2.75 -> 0
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: | 2: compared key
>>>>>> 10.103.6.114 to 10.103.6.114 / 10.103.2.75 -> 8
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: | line 1: match=8
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: | concluding with
>>>>>> best_match=12 best=0x988cbb0 (lineno=4)
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: | complete state transition
>>>>>> with STF_OK
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: "jun" #1: transition from
>>>>>> state STATE_AGGR_R0 to state STATE_AGGR_R1
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: | sending reply packet to
>>>>>> 10.103.2.75:500 (from port 500)
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: | sending 356 bytes for
>>>>>> STATE_AGGR_R0 through p18p1:500 to 10.103.2.75:500 (using #1)
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: | inserting event
>>>>>> EVENT_RETRANSMIT, timeout in 10 seconds for #1
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: "jun" #1: STATE_AGGR_R1:
>>>>>> sent AR1, expecting AI2
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: | modecfg pull: noquirk
>>>>>> policy:push not-client
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: | phase 1 is done, looking
>>>>>> for phase 2 to unpend
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: | complete state transition
>>>>>> with STF_INLINE
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: | complete state transition
>>>>>> with STF_INLINE
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: | * processed 0 messages
>>>>>> from cryptographic helpers
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: | next event
>>>>>> EVENT_RETRANSMIT in 10 seconds for #1
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: | next event
>>>>>> EVENT_RETRANSMIT in 10 seconds for #1
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: |
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: | *received 100 bytes from
>>>>>> 10.103.2.75:500 on p18p1 (port=500)
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: | processing version=1.0
>>>>>> packet with exchange type=ISAKMP_XCHG_AGGR (4)
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: | ICOOKIE: 6c 23 d9 65 fa
>>>>>> 87 ba 23
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: | RCOOKIE: 94 46 8a 37 2d
>>>>>> 46 ff 8d
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: | state hash entry 23
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: | v1 peer and cookies match
>>>>>> on #1, provided msgid 00000000 vs 00000000
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: | v1 state object #1 found,
>>>>>> in STATE_AGGR_R1
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: | processing connection jun
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: "jun" #1: packet rejected:
>>>>>> should have been encrypted
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: "jun" #1: sending
>>>>>> notification INVALID_FLAGS to 10.103.2.75:500
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: | sending 40 bytes for
>>>>>> notification packet through p18p1:500 to 10.103.2.75:500 (using #1)
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: | * processed 0 messages
>>>>>> from cryptographic helpers
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: | next event
>>>>>> EVENT_RETRANSMIT in 10 seconds for #1
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: | next event
>>>>>> EVENT_RETRANSMIT in 10 seconds for #1
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: |
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: | *received 348 bytes from
>>>>>> 10.103.2.75:500 on p18p1 (port=500)
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: | processing version=1.0
>>>>>> packet with exchange type=ISAKMP_XCHG_QUICK (32)
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: | ICOOKIE: 6c 23 d9 65 fa
>>>>>> 87 ba 23
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: | RCOOKIE: 94 46 8a 37 2d
>>>>>> 46 ff 8d
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: | state hash entry 23
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: | v1 peer and cookies match
>>>>>> on #1, provided msgid e4c27ed0 vs 00000000
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: | v1 state object not found
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: | ICOOKIE: 6c 23 d9 65 fa
>>>>>> 87 ba 23
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: | RCOOKIE: 94 46 8a 37 2d
>>>>>> 46 ff 8d
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: | state hash entry 23
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: | v1 peer and cookies match
>>>>>> on #1, provided msgid 00000000 vs 00000000
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: | v1 state object #1 found,
>>>>>> in STATE_AGGR_R1
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: | processing connection jun
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: "jun" #1: Quick Mode
>>>>>> message
>>>>>> is unacceptable because it is for an incomplete ISAKMP SA
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: | payload malformed
>>>>>> after IV
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: | 8d 48 d8 bb c7 43
>>>>>> 10 96
>>>>>> a1 f5 f1 52 9d c1 d5 c0
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: | 15 8f be 33
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: "jun" #1: sending
>>>>>> notification PAYLOAD_MALFORMED to 10.103.2.75:500
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: | sending 40 bytes for
>>>>>> notification packet through p18p1:500 to 10.103.2.75:500 (using #1)
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: | * processed 0 messages
>>>>>> from cryptographic helpers
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: | next event
>>>>>> EVENT_RETRANSMIT in 10 seconds for #1
>>>>>> Jan 21 09:53:47 elisonniven pluto[4299]: | next event
>>>>>> EVENT_RETRANSMIT in 10 seconds for #1
>>>>>> Jan 21 09:53:51 elisonniven pluto[4299]: |
>>>>>> Jan 21 09:53:51 elisonniven pluto[4299]: | *received 348 bytes from
>>>>>> 10.103.2.75:500 on p18p1 (port=500)
>>>>>> Jan 21 09:53:51 elisonniven pluto[4299]: | processing version=1.0
>>>>>> packet with exchange type=ISAKMP_XCHG_QUICK (32)
>>>>>> Jan 21 09:53:51 elisonniven pluto[4299]: | ICOOKIE: 6c 23 d9 65 fa
>>>>>> 87 ba 23
>>>>>> Jan 21 09:53:51 elisonniven pluto[4299]: | RCOOKIE: 94 46 8a 37 2d
>>>>>> 46 ff 8d
>>>>>> Jan 21 09:53:51 elisonniven pluto[4299]: | state hash entry 23
>>>>>> Jan 21 09:53:51 elisonniven pluto[4299]: | v1 peer and cookies match
>>>>>> on #1, provided msgid e4c27ed0 vs 00000000
>>>>>> Jan 21 09:53:51 elisonniven pluto[4299]: | v1 state object not found
>>>>>> Jan 21 09:53:51 elisonniven pluto[4299]: | ICOOKIE: 6c 23 d9 65 fa
>>>>>> 87 ba 23
>>>>>> Jan 21 09:53:51 elisonniven pluto[4299]: | RCOOKIE: 94 46 8a 37 2d
>>>>>> 46 ff 8d
>>>>>> Jan 21 09:53:51 elisonniven pluto[4299]: | state hash entry 23
>>>>>> Jan 21 09:53:51 elisonniven pluto[4299]: | v1 peer and cookies match
>>>>>> on #1, provided msgid 00000000 vs 00000000
>>>>>> Jan 21 09:53:51 elisonniven pluto[4299]: | v1 state object #1 found,
>>>>>> in STATE_AGGR_R1
>>>>>> Jan 21 09:53:51 elisonniven pluto[4299]: | processing connection jun
>>>>>> Jan 21 09:53:51 elisonniven pluto[4299]: "jun" #1: Quick Mode
>>>>>> message
>>>>>> is unacceptable because it is for an incomplete ISAKMP SA
>>>>>> Jan 21 09:53:51 elisonniven pluto[4299]: | payload malformed
>>>>>> after IV
>>>>>> Jan 21 09:53:51 elisonniven pluto[4299]: | 8d 48 d8 bb c7 43
>>>>>> 10 96
>>>>>> a1 f5 f1 52 9d c1 d5 c0
>>>>>> Jan 21 09:53:51 elisonniven pluto[4299]: | 15 8f be 33
>>>>>> Jan 21 09:53:51 elisonniven pluto[4299]: "jun" #1: sending
>>>>>> notification PAYLOAD_MALFORMED to 10.103.2.75:500
>>>>>> Jan 21 09:53:51 elisonniven pluto[4299]: | sending 40 bytes for
>>>>>> notification packet through p18p1:500 to 10.103.2.75:500 (using #1)
>>>>>> Jan 21 09:53:51 elisonniven pluto[4299]: | * processed 0 messages
>>>>>> from cryptographic helpers
>>>>>> Jan 21 09:53:51 elisonniven pluto[4299]: | next event
>>>>>> EVENT_RETRANSMIT in 6 seconds for #1
>>>>>> Jan 21 09:53:51 elisonniven pluto[4299]: | next event
>>>>>> EVENT_RETRANSMIT in 6 seconds for #1
>>>>>>
>>>>>> --
>>>>>> Best Regards,
>>>>>> Elison Niven
>>>>>>
>>>>>>
>>>>>
>>>>>
>>>>>
>>>>
>>>> --
>>>> Best Regards,
>>>> Elison Niven
>>>>
>>>>
>>>
>>>
>>>
>>
>> --
>> Best Regards,
>> Elison Niven
>>
>> _______________________________________________
>> Swan mailing list
>> Swan at lists.libreswan.org
>> https://lists.libreswan.org/mailman/listinfo/swan
>
> --
> Best Regards,
> Elison Niven
>
>
-------------- next part --------------
A non-text attachment was scrubbed...
Name: ikev1.c.diff
Type: text/x-patch
Size: 1512 bytes
Desc: not available
URL: <https://lists.libreswan.org/pipermail/swan/attachments/20130122/019f1e5f/attachment-0001.bin>
More information about the Swan
mailing list