[Swan-dev] MacOS both received and not received IKE_AUTH fragments?

[Paul Wouters]

I see the following issue on a MacOS machine (in the middle east):

May 28 00:45:37.326144: | *received 424 bytes from 193.235.62.155:26472 on eth0 (port=500)

May 28 00:45:37.334543: | sending 445 bytes for STATE_IKEv2_BASE through eth0:500 to 193.235.62.155:26472 (using #7)

The first IKE_INIT exchange. Then since the Mac switches to use port
4500 due to NAT it will get assigned a different port on the NAT gateway
from here on:

May 28 00:45:37.554175: | *received 544 bytes from 193.235.62.153:26440 on eth0 (port=4500)

May 28 00:45:37.554964: | Now let's proceed with payload (ISAKMP_NEXT_v2SKF)
May 28 00:45:37.554978: | ***parse IKEv2 Encrypted Fragment:

May 28 00:45:37.555217: | *received 544 bytes from 193.235.62.153:26440 on eth0 (port=4500)

May 28 00:45:37.556066: | *received 544 bytes from 193.235.62.153:26440 on eth0 (port=4500)

May 28 00:45:37.556976: | *received 384 bytes from 193.235.62.153:26440 on eth0 (port=4500)

We received all fragments.

May 28 00:45:37.573734: "ikev2"[4] 193.235.62.155 #7: Authenticated using RSA

We decrypted and authenticated.

May 28 00:45:37.823568: "ikev2"[4] 193.235.62.155 #8: STATE_V2_IPSEC_R: IPsec 
SA established tunnel mode {ESP/NAT=>0x0fb4359e <0x3e838ca8 
xfrm=AES_CBC_128-HMAC_SHA1_96 NATOA=none NATD=193.235.62.155:26440 DPD=passive}

We installed an IPsec SA in the kernel.

May 28 00:45:37.823581: | sending V2 reply packet to 193.235.62.153:26440 (from port 4500)
May 28 00:45:37.823591: | sending fragments ...
May 28 00:45:37.823611: | sending 1204 bytes for STATE_PARENT_R1 through eth0:4500 to 193.235.62.153:26440 (using #7)

May 28 00:45:37.824436: | sending 1204 bytes for STATE_PARENT_R1 through eth0:4500 to 193.235.62.153:26440 (using #7)

May 28 00:45:37.825201: | sending 1204 bytes for STATE_PARENT_R1 through eth0:4500 to 193.235.62.153:26440 (using #7)

May 28 00:45:37.826001: | sending 1204 bytes for STATE_PARENT_R1 through eth0:4500 to 193.235.62.153:26440 (using #7)

May 28 00:45:37.826866: | sending 580 bytes for STATE_PARENT_R1 through eth0:4500 to 193.235.62.153:26440 (using #7)

May 28 00:45:37.827307: | sent 5 fragments

We sent all fragments, but.......

May 28 00:45:38.067663: | rejected packet:
May 28 00:45:38.067720: |   0f b4 35 9e  00 00 00 01  7f bb e0 09  3e 5d 5f 46
May 28 00:45:38.067732: |   8a 87 0e 21  b5 e6 15 33  11 a9 97 8f  14 e4 1f 6e
May 28 00:45:38.067742: |   d4 eb 03 bf  3f 50 21 45  26 f5 39 00  ee 1d 1e 4c
May 28 00:45:38.067751: |   9f f1 2f 61  1b b2 a6 4b  48 ce 48 e4  c0 be 84 00
May 28 00:45:38.067761: |   74 6a e3 26  23 3e 5d e8  95 65 fa 61  43 ad 7d b8
May 28 00:45:38.067772: |   10 8c 1c 2c
May 28 00:45:38.067781: | control:
May 28 00:45:38.067790: |   1c 00 00 00  00 00 00 00  00 00 00 00  08 00 00 00
May 28 00:45:38.067799: |   00 00 00 00  00 00 00 00  5b ef 7c 8e  6f 7f 00 00
May 28 00:45:38.067808: |   30 00 00 00  00 00 00 00  00 00 00 00  0b 00 00 00
May 28 00:45:38.067817: |   6f 00 00 00  02 03 03 00  00 00 00 00  00 00 00 00
May 28 00:45:38.067828: |   02 00 00 00  c1 eb 3e 9b  00 00 00 00  00 00 00 00
May 28 00:45:38.067837: | name:
May 28 00:45:38.067847: |   02 00 67 48  c1 eb 3e 9b  00 00 00 00  00 00 00 00
May 28 00:45:38.067868: | ERROR: asynchronous network error report on eth0 
(sport=4500) for message to 193.235.62.155 port 26440, complainant 
193.235.62.155: Connection refused [errno 111, origin ICMP type 3 code 3 (not 
authenticated)]
May 28 00:45:38.203713: | rejected packet:

[ does this for all fragments ]

It seems to no longer be listening on the IKE port it used. Or the NAT
gateway lost/forgot/dropped the NAT mapping. The reason this is odd, is
that next we see:

May 28 00:45:57.636568: | *received 76 bytes from 193.235.62.153:26440 on eth0 
(port=4500)
May 28 00:45:57.636629: |   d2 70 5b 92  b2 14 63 a4  4f af 0f 60  82 e4 af b8
May 28 00:45:57.636641: |   2e 20 25 08  00 00 00 02  00 00 00 4c  2a 00 00 30
May 28 00:45:57.636670: |   42 3f 6e b9  a6 c7 16 2b  f9 5b 27 ff  fe 53 42 e7
May 28 00:45:57.636681: |   aa b3 f3 8e  21 02 71 9a  a3 65 0e 93  58 0a f2 b5
May 28 00:45:57.636691: |   df af f7 1a  7b 7f 29 5d  4f 97 8b c5

Which is another IKE packet from that same point they just before claimed to 
not listen on!

May 28 00:45:57.636704: | processing: start from 193.235.62.153:26440 (in process_md() at demux.c:391)
May 28 00:45:57.636717: | **parse ISAKMP Message:
May 28 00:45:57.636728: |    initiator cookie:
May 28 00:45:57.636737: |   d2 70 5b 92  b2 14 63 a4
May 28 00:45:57.636747: |    responder cookie:
May 28 00:45:57.636756: |   4f af 0f 60  82 e4 af b8
May 28 00:45:57.636766: |    next payload type: ISAKMP_NEXT_v2SK (0x2e)
May 28 00:45:57.636778: |    ISAKMP version: IKEv2 version 2.0 (rfc4306/rfc5996) (0x20)
May 28 00:45:57.636788: |    exchange type: ISAKMP_v2_INFORMATIONAL (0x25)

And it is an informational exchange, which they could only sent if they
had actually received our fragments, which they claimed not to have
received!

May 28 00:45:57.636988: | Unpacking clear payload for svm: R2: process INFORMATIONAL Request
May 28 00:45:57.636999: | Now let's proceed with payload (ISAKMP_NEXT_v2SK)
May 28 00:45:57.637010: | ***parse IKEv2 Encryption Payload:
May 28 00:45:57.637020: |    next payload type: ISAKMP_NEXT_v2D (0x2a)

And it is a Delete notification, so for whatever reason they didn't like
our AUTH response (but received it?) and deleted the IKE SA?

Pretty weird behaviour.......

Paul