[Swan] Aggressive mode not possible with Juniper Netscreen
Paul Wouters
paul at nohats.ca
Tue Jan 22 17:05:10 EET 2013
On Tue, 22 Jan 2013, Elison Niven wrote:
> No change after setting nhelpers=0.
That is good I guess, not a bug in our helper code.
> What logs are you expecting for in plutodebug=all?
I would expect to see the parsing by in_struct() that would
log all the payloads in the message, even if it is going to
reject it later on based on the fact it was not encrypted.
Possibly, we should continue processing the packet, but only
allow informational payloads about the error, and ignore any
other payloads. That would make diagnostics better.
Paul
> On Tuesday 22 January 2013 08:10 PM, Paul Wouters wrote:
>> On Tue, 22 Jan 2013, Elison Niven wrote:
>>
>>> Also Phase 1 on Libreswan is not complete as ipsec auto --status does
>>> not say that ISAKMP SA established.
>>
>> Yes, you need an acceptable AI2 before your phase 1 is up.
>>
>>> #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
>>
>> If the packet AI2 is rejected, it likely means:
>>
>> - The remote is retransmitting the previous AI1 packet which is not
>> encrypted, possible due to a misconfiguration.
>> - The remote is sending an error in AI2, meaning it failed to agree
>> on the crypto, therefor it cannot be encrypted.
>> - The remote is having a non-RFC compliant implementation (unlikely)
>>
>> In the latter case, you can run with plutodebug=all, and you should see
>> the entire parsing of the payloads, and it will likely contain some kind
>> of notify message.
>>
>> As per RFC, aggressive mode packet AR2/IR2 should be encrypted.
>>
>> The only possibly reason I can come up with, if we assume *swan is the
>> problem (which I am currently thinking is not likely) is a problem with
>> the aggressive mode crypto helpers, so you can try adding nhelpers=0
>> to "config setup" and restart ipsec.
>>
>> Paul
>>
>>> 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
>>>
>>> _______________________________________________
>>> Swan mailing list
>>> Swan at lists.libreswan.org
>>> https://lists.libreswan.org/mailman/listinfo/swan
>>>
>>
>>
>
> --
> Best Regards,
> Elison Niven
>
More information about the Swan
mailing list