[Swan] Cisco IOS XE Interoperability with Libreswan

Reuben Farrelly reuben-libreswan at reub.net
Thu Aug 16 08:20:04 UTC 2018



On 16/08/2018 5:38 am, Paul Wouters wrote:
> On Wed, 15 Aug 2018, Reuben Farrelly wrote:
> 
>>>  You didn't show me what happened next, so I cannot tell. It all looks
>>>  healthy up to here. You can avoid the extra roundtrip by of INVALID_KE
>>>  by using: ike=aes256-sha2_512;dh19
>>
>> Ok here's a complete negotiation run:
> 
> [...]
> 
> It seems the Cisco wrongly retransmits the same IKE_INIT, and forgets to
> update the KE payload. I've pinged one my of Cisco contacts for some
> more information. Is there a chance you can update the firmware on that
> Cisco device just in case it's an old fixed bug?

I'm already running 16.9.1 which is the very latest release that came 
out for that platform (and all other IOS XE devices) only a few weeks ago.
This router is a new hardware platform though so I don't have many code 
options.

After applying the workaround:

ike=aes-sha2_512;dh19

We're getting a little further now, but still not succeeding.

Libreswan debugs:

Aug 16 18:05:12.049488: | netlink_get: XFRM_MSG_DELPOLICY message
Aug 16 18:05:12.049496: | xfrm netlink address change RTM_NEWADDR msg len 72
Aug 16 18:05:14.174401: |  kernel_process_msg_cb process netlink message
Aug 16 18:05:14.174457: | netlink_get: XFRM_MSG_DELPOLICY message
Aug 16 18:05:14.174465: | xfrm netlink address change RTM_NEWADDR msg len 72
Aug 16 18:05:15.143403: |  kernel_process_msg_cb process netlink message
Aug 16 18:05:15.143459: | netlink_get: XFRM_MSG_DELPOLICY message
Aug 16 18:05:15.143468: | xfrm netlink address change RTM_NEWADDR msg len 72
Aug 16 18:05:16.755649: | *received 366 bytes from 1.144.95.124:585 on 
eth0 (port=500)
Aug 16 18:05:16.755693: |   fe e6 d7 65  ca 54 75 3b  00 00 00 00  00 00 
00 00
Aug 16 18:05:16.755699: |   21 20 22 08  00 00 00 00  00 00 01 6e  22 00 
00 58
Aug 16 18:05:16.755704: |   00 00 00 54  01 01 00 09  03 00 00 0c  01 00 
00 0c
Aug 16 18:05:16.755709: |   80 0e 01 00  03 00 00 08  02 00 00 07  03 00 
00 08
Aug 16 18:05:16.755714: |   02 00 00 06  03 00 00 08  03 00 00 0e  03 00 
00 08
Aug 16 18:05:16.755718: |   03 00 00 0d  03 00 00 08  04 00 00 13  03 00 
00 08
Aug 16 18:05:16.755723: |   04 00 00 0e  03 00 00 08  04 00 00 15  00 00 
00 08
Aug 16 18:05:16.755728: |   04 00 00 05  28 00 00 48  00 13 00 00  48 12 
de ee
Aug 16 18:05:16.755733: |   dc 50 dd cf  ad 6b 86 a6  bd fe 04 ee  ea 29 
8e 71
Aug 16 18:05:16.755737: |   a1 15 96 ec  9e c0 63 4e  aa 3c 4e 5b  83 ea 
28 19
Aug 16 18:05:16.755742: |   01 4b 35 07  2c cb 57 8e  ff a6 7b 74  64 84 
60 eb
Aug 16 18:05:16.755747: |   a0 64 89 e9  cf 99 a5 ec  80 79 6f a6  2b 00 
00 24
Aug 16 18:05:16.755751: |   b2 f5 63 a3  ba f9 8b 10  5d 6f ae 01  01 42 
f0 2f
Aug 16 18:05:16.755756: |   7f 49 bc 76  da 9e a8 b2  dd 01 30 df  ea 6e 
da 10
Aug 16 18:05:16.755761: |   2b 00 00 17  43 49 53 43  4f 2d 44 45  4c 45 
54 45
Aug 16 18:05:16.755765: |   2d 52 45 41  53 4f 4e 2b  00 00 13 43  49 53 
43 4f
Aug 16 18:05:16.755770: |   56 50 4e 2d  52 45 56 2d  30 32 2b 00  00 17 
43 49
Aug 16 18:05:16.755775: |   53 43 4f 2d  44 59 4e 41  4d 49 43 2d  52 4f 
55 54
Aug 16 18:05:16.755779: |   45 29 00 00  15 46 4c 45  58 56 50 4e  2d 53 
55 50
Aug 16 18:05:16.755792: |   50 4f 52 54  45 44 29 00  00 1c 00 00  40 04 
91 1c
Aug 16 18:05:16.755801: |   4b 8a 6e 11  99 bd e1 b4  7d 9b 10 77  c9 8f 
b8 5b
Aug 16 18:05:16.755806: |   1e 56 00 00  00 1c 00 00  40 05 36 f4  89 56 
72 d3
Aug 16 18:05:16.755811: |   7e 65 57 d7  ef 2e ee 35  09 d4 54 16  58 bf
Aug 16 18:05:16.755821: | processing: start from 1.144.95.124:585 (in 
process_md() at demux.c:392)
Aug 16 18:05:16.755829: | **parse ISAKMP Message:
Aug 16 18:05:16.755835: |    initiator cookie:
Aug 16 18:05:16.755840: |   fe e6 d7 65  ca 54 75 3b
Aug 16 18:05:16.755845: |    responder cookie:
Aug 16 18:05:16.755849: |   00 00 00 00  00 00 00 00
Aug 16 18:05:16.755855: |    first contained payload type: 
ISAKMP_NEXT_v2SA (0x21)
Aug 16 18:05:16.755861: |    ISAKMP version: IKEv2 version 2.0 
(rfc4306/rfc5996) (0x20)
Aug 16 18:05:16.755866: |    exchange type: ISAKMP_v2_SA_INIT (0x22)
Aug 16 18:05:16.755872: |    flags: ISAKMP_FLAG_v2_IKE_INIT (0x8)
Aug 16 18:05:16.755877: |    message ID:  00 00 00 00
Aug 16 18:05:16.755882: |    length: 366 (0x16e)
Aug 16 18:05:16.755887: |  processing version=2.0 packet with exchange 
type=ISAKMP_v2_SA_INIT (34)
Aug 16 18:05:16.755893: | I am receiving an IKEv2 Request ISAKMP_v2_SA_INIT
Aug 16 18:05:16.755898: | I am the IKE SA Original Responder
Aug 16 18:05:16.755907: | icookie table: hash icookie fe e6 d7 65  ca 54 
75 3b to 15999983715547008262 slot 0x5598d5c3e680
Aug 16 18:05:16.755912: | parent_init v2 state object not found
Aug 16 18:05:16.755918: | #null state always idle
Aug 16 18:05:16.755924: | #0 in state PARENT_R0: processing SA_INIT request
Aug 16 18:05:16.755930: | Unpacking clear payload for svm: Respond to 
IKE_SA_INIT
Aug 16 18:05:16.755949: | Now let's proceed with payload (ISAKMP_NEXT_v2SA)
Aug 16 18:05:16.755963: | ***parse IKEv2 Security Association Payload:
Aug 16 18:05:16.755969: |    next payload type: ISAKMP_NEXT_v2KE (0x22)
Aug 16 18:05:16.755974: |    flags: none (0x0)
Aug 16 18:05:16.755979: |    length: 88 (0x58)
Aug 16 18:05:16.755984: | processing payload: ISAKMP_NEXT_v2SA (len=88)
Aug 16 18:05:16.755989: | Now let's proceed with payload (ISAKMP_NEXT_v2KE)
Aug 16 18:05:16.755995: | ***parse IKEv2 Key Exchange Payload:
Aug 16 18:05:16.756000: |    next payload type: ISAKMP_NEXT_v2Ni (0x28)
Aug 16 18:05:16.756005: |    flags: none (0x0)
Aug 16 18:05:16.756010: |    length: 72 (0x48)
Aug 16 18:05:16.756015: |    DH group: OAKLEY_GROUP_ECP_256 (0x13)
Aug 16 18:05:16.756020: | processing payload: ISAKMP_NEXT_v2KE (len=72)
Aug 16 18:05:16.756025: | Now let's proceed with payload (ISAKMP_NEXT_v2Ni)
Aug 16 18:05:16.756030: | ***parse IKEv2 Nonce Payload:
Aug 16 18:05:16.756036: |    next payload type: ISAKMP_NEXT_v2V (0x2b)
Aug 16 18:05:16.756041: |    flags: none (0x0)
Aug 16 18:05:16.756045: |    length: 36 (0x24)
Aug 16 18:05:16.756051: | processing payload: ISAKMP_NEXT_v2Ni (len=36)
Aug 16 18:05:16.756056: | Now let's proceed with payload (ISAKMP_NEXT_v2V)
Aug 16 18:05:16.756061: | ***parse IKEv2 Vendor ID Payload:
Aug 16 18:05:16.756066: |    next payload type: ISAKMP_NEXT_v2V (0x2b)
Aug 16 18:05:16.756071: |    flags: none (0x0)
Aug 16 18:05:16.756075: |    length: 23 (0x17)
Aug 16 18:05:16.756081: | processing payload: ISAKMP_NEXT_v2V (len=23)
Aug 16 18:05:16.756086: | Now let's proceed with payload (ISAKMP_NEXT_v2V)
Aug 16 18:05:16.756091: | ***parse IKEv2 Vendor ID Payload:
Aug 16 18:05:16.756096: |    next payload type: ISAKMP_NEXT_v2V (0x2b)
Aug 16 18:05:16.756101: |    flags: none (0x0)
Aug 16 18:05:16.756105: |    length: 19 (0x13)
Aug 16 18:05:16.756110: | processing payload: ISAKMP_NEXT_v2V (len=19)
Aug 16 18:05:16.756115: | Now let's proceed with payload (ISAKMP_NEXT_v2V)
Aug 16 18:05:16.756120: | ***parse IKEv2 Vendor ID Payload:
Aug 16 18:05:16.756125: |    next payload type: ISAKMP_NEXT_v2V (0x2b)
Aug 16 18:05:16.756130: |    flags: none (0x0)
Aug 16 18:05:16.756135: |    length: 23 (0x17)
Aug 16 18:05:16.756140: | processing payload: ISAKMP_NEXT_v2V (len=23)
Aug 16 18:05:16.756145: | Now let's proceed with payload (ISAKMP_NEXT_v2V)
Aug 16 18:05:16.756150: | ***parse IKEv2 Vendor ID Payload:
Aug 16 18:05:16.756155: |    next payload type: ISAKMP_NEXT_v2N (0x29)
Aug 16 18:05:16.756160: |    flags: none (0x0)
Aug 16 18:05:16.756164: |    length: 21 (0x15)
Aug 16 18:05:16.756169: | processing payload: ISAKMP_NEXT_v2V (len=21)
Aug 16 18:05:16.756174: | Now let's proceed with payload (ISAKMP_NEXT_v2N)
Aug 16 18:05:16.756180: | ***parse IKEv2 Notify Payload:
Aug 16 18:05:16.756185: |    next payload type: ISAKMP_NEXT_v2N (0x29)
Aug 16 18:05:16.756190: |    flags: none (0x0)
Aug 16 18:05:16.756194: |    length: 28 (0x1c)
Aug 16 18:05:16.756199: |    Protocol ID: PROTO_v2_RESERVED (0x0)
Aug 16 18:05:16.756204: |    SPI size: 0 (0x0)
Aug 16 18:05:16.756210: |    Notify Message Type: 
v2N_NAT_DETECTION_SOURCE_IP (0x4004)
Aug 16 18:05:16.756215: | processing payload: ISAKMP_NEXT_v2N (len=28)
Aug 16 18:05:16.756220: | Now let's proceed with payload (ISAKMP_NEXT_v2N)
Aug 16 18:05:16.756225: | ***parse IKEv2 Notify Payload:
Aug 16 18:05:16.756230: |    next payload type: ISAKMP_NEXT_v2NONE (0x0)
Aug 16 18:05:16.756235: |    flags: none (0x0)
Aug 16 18:05:16.756240: |    length: 28 (0x1c)
Aug 16 18:05:16.756245: |    Protocol ID: PROTO_v2_RESERVED (0x0)
Aug 16 18:05:16.756249: |    SPI size: 0 (0x0)
Aug 16 18:05:16.756255: |    Notify Message Type: 
v2N_NAT_DETECTION_DESTINATION_IP (0x4005)
Aug 16 18:05:16.756260: | processing payload: ISAKMP_NEXT_v2N (len=28)
Aug 16 18:05:16.756265: | selected state microcode Respond to IKE_SA_INIT
Aug 16 18:05:16.756270: | Now let's proceed with state specific processing
Aug 16 18:05:16.756275: | calling processor Respond to IKE_SA_INIT
Aug 16 18:05:16.756284: | anti-DDoS cookies not required (and no cookie 
received)
Aug 16 18:05:16.756293: | find_host_connection me=110.232.112.209:500 
him=1.144.95.124:585 policy=RSASIG+IKEV2_ALLOW
Aug 16 18:05:16.756300: | find_host_pair: comparing 110.232.112.209:500 
to 0.0.0.0:500
Aug 16 18:05:16.756307: | find_host_pair: comparing 110.232.112.209:500 
to 1.144.95.124:500
Aug 16 18:05:16.756312: | find_next_host_connection 
policy=RSASIG+IKEV2_ALLOW
Aug 16 18:05:16.756319: | found policy = 
PSK+ENCRYPT+TUNNEL+PFS+IKEV2_ALLOW+IKEV2_PROPOSE+SAREF_TRACK+IKE_FRAG_ALLOW+ESN_NO 
(router-2.reub.net-ipv4)
Aug 16 18:05:16.756325: | find_next_host_connection returns empty
Aug 16 18:05:16.756331: | find_host_connection me=110.232.112.209:500 
him=%any:585 policy=RSASIG+IKEV2_ALLOW
Aug 16 18:05:16.756337: | find_host_pair: comparing 110.232.112.209:500 
to 1.144.95.124:500
Aug 16 18:05:16.756343: | find_host_pair: comparing 110.232.112.209:500 
to 0.0.0.0:500
Aug 16 18:05:16.756348: | find_next_host_connection 
policy=RSASIG+IKEV2_ALLOW
Aug 16 18:05:16.756354: | found policy = 
PSK+ENCRYPT+TUNNEL+PFS+IKEV2_ALLOW+IKEV2_PROPOSE+SAREF_TRACK+IKE_FRAG_ALLOW+ESN_NO 
(router-2.reub.net-ipv4)
Aug 16 18:05:16.756359: | find_next_host_connection returns empty
Aug 16 18:05:16.756365: | initial parent SA message received on 
110.232.112.209:500 but no connection has been authorized with policy 
RSASIG+IKEV2_ALLOW
Aug 16 18:05:16.756371: | find_host_connection me=110.232.112.209:500 
him=1.144.95.124:585 policy=PSK+IKEV2_ALLOW
Aug 16 18:05:16.756377: | find_host_pair: comparing 110.232.112.209:500 
to 0.0.0.0:500
Aug 16 18:05:16.756383: | find_host_pair: comparing 110.232.112.209:500 
to 1.144.95.124:500
Aug 16 18:05:16.756388: | find_next_host_connection policy=PSK+IKEV2_ALLOW
Aug 16 18:05:16.756394: | found policy = 
PSK+ENCRYPT+TUNNEL+PFS+IKEV2_ALLOW+IKEV2_PROPOSE+SAREF_TRACK+IKE_FRAG_ALLOW+ESN_NO 
(router-2.reub.net-ipv4)
Aug 16 18:05:16.756400: | find_next_host_connection returns 
router-2.reub.net-ipv4[1] 1.144.95.124
Aug 16 18:05:16.756407: | found connection: router-2.reub.net-ipv4[1] 
1.144.95.124 with policy PSK+IKEV2_ALLOW
Aug 16 18:05:16.756413: | find_host_pair: comparing 110.232.112.209:500 
to 1.144.95.124:500
Aug 16 18:05:16.756418: | find_host_pair: comparing 110.232.112.209:500 
to 0.0.0.0:500
Aug 16 18:05:16.756427: | ignoring Vendor ID payload [CISCO-DELETE-REASON]
Aug 16 18:05:16.756433: | ignoring Vendor ID payload [CISCOVPN-REV-02]
Aug 16 18:05:16.756439: | ignoring Vendor ID payload [CISCO-DYNAMIC-ROUTE]
Aug 16 18:05:16.756444: | ignoring Vendor ID payload [FLEXVPN-SUPPORTED]
Aug 16 18:05:16.756450: | already determined local IKE proposals for 
router-2.reub.net-ipv4 (IKE SA responder matching remote proposals)
Aug 16 18:05:16.756450: | already determined local IKE proposals for 
router-2.reub.net-ipv4 (IKE SA responder matching remote proposals)
Aug 16 18:05:16.756457: | Comparing remote proposals against IKE 
responder 1 local proposals
Aug 16 18:05:16.756464: | local proposal 1 type ENCR has 2 transforms
Aug 16 18:05:16.756469: | local proposal 1 type PRF has 1 transforms
Aug 16 18:05:16.756475: | local proposal 1 type INTEG has 1 transforms
Aug 16 18:05:16.756480: | local proposal 1 type DH has 1 transforms
Aug 16 18:05:16.756485: | local proposal 1 type ESN has 0 transforms
Aug 16 18:05:16.756491: | local proposal 1 transforms: required: 
ENCR+PRF+INTEG+DH; optional: none
Aug 16 18:05:16.756496: | ****parse IKEv2 Proposal Substructure Payload:
Aug 16 18:05:16.756502: |    last proposal: v2_PROPOSAL_LAST (0x0)
Aug 16 18:05:16.756506: |    length: 84 (0x54)
Aug 16 18:05:16.756511: |    prop #: 1 (0x1)
Aug 16 18:05:16.756516: |    proto ID: IKEv2_SEC_PROTO_IKE (0x1)
Aug 16 18:05:16.756521: |    spi size: 0 (0x0)
Aug 16 18:05:16.756526: |    # transforms: 9 (0x9)
Aug 16 18:05:16.756532: | Comparing remote proposal 1 containing 9 
transforms against local proposal [1..1] of 1 local proposals
Aug 16 18:05:16.756538: | *****parse IKEv2 Transform Substructure Payload:
Aug 16 18:05:16.756543: |    last transform: v2_TRANSFORM_NON_LAST (0x3)
Aug 16 18:05:16.756548: |    length: 12 (0xc)
Aug 16 18:05:16.756553: |    IKEv2 transform type: TRANS_TYPE_ENCR (0x1)
Aug 16 18:05:16.756558: |    IKEv2 transform ID: AES_CBC (0xc)
Aug 16 18:05:16.756567: | ******parse IKEv2 Attribute Substructure Payload:
Aug 16 18:05:16.756573: |    af+type: IKEv2_KEY_LENGTH (0x800e)
Aug 16 18:05:16.756578: |    length/value: 256 (0x100)
Aug 16 18:05:16.756586: | remote proposal 1 transform 0 
(ENCR=AES_CBC_256) matches local proposal 1 type 1 (ENCR) transform 0
Aug 16 18:05:16.756592: | *****parse IKEv2 Transform Substructure Payload:
Aug 16 18:05:16.756597: |    last transform: v2_TRANSFORM_NON_LAST (0x3)
Aug 16 18:05:16.756602: |    length: 8 (0x8)
Aug 16 18:05:16.756607: |    IKEv2 transform type: TRANS_TYPE_PRF (0x2)
Aug 16 18:05:16.756612: |    IKEv2 transform ID: PRF_HMAC_SHA2_512 (0x7)
Aug 16 18:05:16.756619: | remote proposal 1 transform 1 
(PRF=HMAC_SHA2_512) matches local proposal 1 type 2 (PRF) transform 0
Aug 16 18:05:16.756624: | *****parse IKEv2 Transform Substructure Payload:
Aug 16 18:05:16.756630: |    last transform: v2_TRANSFORM_NON_LAST (0x3)
Aug 16 18:05:16.756635: |    length: 8 (0x8)
Aug 16 18:05:16.756639: |    IKEv2 transform type: TRANS_TYPE_PRF (0x2)
Aug 16 18:05:16.756645: |    IKEv2 transform ID: PRF_HMAC_SHA2_384 (0x6)
Aug 16 18:05:16.756650: | *****parse IKEv2 Transform Substructure Payload:
Aug 16 18:05:16.756656: |    last transform: v2_TRANSFORM_NON_LAST (0x3)
Aug 16 18:05:16.756661: |    length: 8 (0x8)
Aug 16 18:05:16.756666: |    IKEv2 transform type: TRANS_TYPE_INTEG (0x3)
Aug 16 18:05:16.756671: |    IKEv2 transform ID: AUTH_HMAC_SHA2_512_256 
(0xe)
Aug 16 18:05:16.756677: | remote proposal 1 transform 3 
(INTEG=HMAC_SHA2_512_256) matches local proposal 1 type 3 (INTEG) 
transform 0
Aug 16 18:05:16.756683: | *****parse IKEv2 Transform Substructure Payload:
Aug 16 18:05:16.756688: |    last transform: v2_TRANSFORM_NON_LAST (0x3)
Aug 16 18:05:16.756693: |    length: 8 (0x8)
Aug 16 18:05:16.756698: |    IKEv2 transform type: TRANS_TYPE_INTEG (0x3)
Aug 16 18:05:16.756703: |    IKEv2 transform ID: AUTH_HMAC_SHA2_384_192 
(0xd)
Aug 16 18:05:16.756709: | *****parse IKEv2 Transform Substructure Payload:
Aug 16 18:05:16.756714: |    last transform: v2_TRANSFORM_NON_LAST (0x3)
Aug 16 18:05:16.756719: |    length: 8 (0x8)
Aug 16 18:05:16.756724: |    IKEv2 transform type: TRANS_TYPE_DH (0x4)
Aug 16 18:05:16.756729: |    IKEv2 transform ID: OAKLEY_GROUP_ECP_256 (0x13)
Aug 16 18:05:16.756735: | remote proposal 1 transform 5 (DH=ECP_256) 
matches local proposal 1 type 4 (DH) transform 0
Aug 16 18:05:16.756741: | *****parse IKEv2 Transform Substructure Payload:
Aug 16 18:05:16.756746: |    last transform: v2_TRANSFORM_NON_LAST (0x3)
Aug 16 18:05:16.756751: |    length: 8 (0x8)
Aug 16 18:05:16.756756: |    IKEv2 transform type: TRANS_TYPE_DH (0x4)
Aug 16 18:05:16.756761: |    IKEv2 transform ID: OAKLEY_GROUP_MODP2048 (0xe)
Aug 16 18:05:16.756767: | *****parse IKEv2 Transform Substructure Payload:
Aug 16 18:05:16.756772: |    last transform: v2_TRANSFORM_NON_LAST (0x3)
Aug 16 18:05:16.756777: |    length: 8 (0x8)
Aug 16 18:05:16.756782: |    IKEv2 transform type: TRANS_TYPE_DH (0x4)
Aug 16 18:05:16.756787: |    IKEv2 transform ID: OAKLEY_GROUP_ECP_521 (0x15)
Aug 16 18:05:16.756792: | *****parse IKEv2 Transform Substructure Payload:
Aug 16 18:05:16.756797: |    last transform: v2_TRANSFORM_LAST (0x0)
Aug 16 18:05:16.756802: |    length: 8 (0x8)
Aug 16 18:05:16.756807: |    IKEv2 transform type: TRANS_TYPE_DH (0x4)
Aug 16 18:05:16.756813: |    IKEv2 transform ID: OAKLEY_GROUP_MODP1536 (0x5)
Aug 16 18:05:16.756820: | remote proposal 1 proposed transforms: 
ENCR+PRF+INTEG+DH; matched: ENCR+PRF+INTEG+DH; unmatched: none
Aug 16 18:05:16.756827: | comparing remote proposal 1 containing 
ENCR+PRF+INTEG+DH transforms to local proposal 1; required: 
ENCR+PRF+INTEG+DH; optional: none; matched: ENCR+PRF+INTEG+DH
Aug 16 18:05:16.756833: | remote proposal 1 matches local proposal 1
Aug 16 18:05:16.756842: packet from 1.144.95.124:585: proposal 
1:IKE:ENCR=AES_CBC_256;PRF=HMAC_SHA2_512;INTEG=HMAC_SHA2_512_256;DH=ECP_256 
chosen from remote proposals 
1:IKE:ENCR=AES_CBC_256;PRF=HMAC_SHA2_512;PRF=HMAC_SHA2_384;INTEG=HMAC_SHA2_512_256;INTEG=HMAC_SHA2_384_192;DH=ECP_256;DH=MODP2048;DH=ECP_521;DH=MODP1536[first-match]
Aug 16 18:05:16.756855: | accepted IKE proposal ikev2_proposal: 
1:IKE:ENCR=AES_CBC_256;PRF=HMAC_SHA2_512;INTEG=HMAC_SHA2_512_256;DH=ECP_256
Aug 16 18:05:16.756860: | converting proposal to internal trans attrs
Aug 16 18:05:16.756872: | creating state object #138 at 0x5598d74f24e0
Aug 16 18:05:16.756878: | parent state #138: new => STATE_UNDEFINED(ignore)
Aug 16 18:05:16.756929: | processing: start state #138 connection 
"router-2.reub.net-ipv4"[1] 1.144.95.124 1.144.95.124 (in 
initialize_new_state() at ipsec_doi.c:485)
Aug 16 18:05:16.756938: | inserting state object #138
Aug 16 18:05:16.756945: | serialno list: inserting object 0x5598d74f24e0 
(state #138) entry 0x5598d74f2c78 into list 0x5598d5c493e0 (older 
0x5598d74f0948 newer 0x5598d74f0948)
Aug 16 18:05:16.756952: | serialno list: inserted  object 0x5598d74f24e0 
(state #138) entry 0x5598d74f2c78 (older 0x5598d74f0948 newer 
0x5598d5c493e0)
Aug 16 18:05:16.756958: | serialno list: list entry 0x5598d5c493e0 is 
HEAD (older 0x5598d74f2c78 newer 0x5598d74f0948)
Aug 16 18:05:16.756964: | serialno table: inserting object 
0x5598d74f24e0 (state #138) entry 0x5598d74f2c98 into list 
0x5598d5c3fd40 (older 0x5598d5c3fd40 newer 0x5598d5c3fd40)
Aug 16 18:05:16.756971: | serialno table: inserted  object 
0x5598d74f24e0 (state #138) entry 0x5598d74f2c98 (older 0x5598d5c3fd40 
newer 0x5598d5c3fd40)
Aug 16 18:05:16.756976: | serialno table: list entry 0x5598d5c3fd40 is 
HEAD (older 0x5598d74f2c98 newer 0x5598d74f2c98)
Aug 16 18:05:16.756985: | processing: [RE]START state #138 connection 
"router-2.reub.net-ipv4"[1] 1.144.95.124 1.144.95.124 (in 
initialize_new_state() at ipsec_doi.c:503)
Aug 16 18:05:16.756992: | parent state #138: STATE_UNDEFINED(ignore) => 
STATE_PARENT_R1(half-open-ike)
Aug 16 18:05:16.756997: | ignore states: 0
Aug 16 18:05:16.757002: | half-open-ike states: 2
Aug 16 18:05:16.757007: | open-ike states: 0
Aug 16 18:05:16.757012: | established-anonymous-ike states: 0
Aug 16 18:05:16.757017: | established-authenticated-ike states: 0
Aug 16 18:05:16.757021: | anonymous-ipsec states: 0
Aug 16 18:05:16.757026: | authenticated-ipsec states: 0
Aug 16 18:05:16.757031: | informational states: 0
Aug 16 18:05:16.757035: | unknown states: 0
Aug 16 18:05:16.757040: | category states: 2 count states: 2
Aug 16 18:05:16.757062: | natd_hash: Warning, rcookie is zero !!
Aug 16 18:05:16.757080: | natd_hash: hasher=0x5598d5c2b600(20)
Aug 16 18:05:16.757087: | natd_hash: icookie=  fe e6 d7 65  ca 54 75 3b
Aug 16 18:05:16.757092: | natd_hash: rcookie=  00 00 00 00  00 00 00 00
Aug 16 18:05:16.757097: | natd_hash: ip=  6e e8 70 d1
Aug 16 18:05:16.757102: | natd_hash: port=500
Aug 16 18:05:16.757107: | natd_hash: hash=  36 f4 89 56  72 d3 7e 65  57 
d7 ef 2e  ee 35 09 d4
Aug 16 18:05:16.757111: | natd_hash: hash=  54 16 58 bf
Aug 16 18:05:16.757116: | natd_hash: Warning, rcookie is zero !!
Aug 16 18:05:16.757127: | natd_hash: hasher=0x5598d5c2b600(20)
Aug 16 18:05:16.757133: | natd_hash: icookie=  fe e6 d7 65  ca 54 75 3b
Aug 16 18:05:16.757139: | natd_hash: rcookie=  00 00 00 00  00 00 00 00
Aug 16 18:05:16.757143: | natd_hash: ip=  01 90 5f 7c
Aug 16 18:05:16.757148: | natd_hash: port=585
Aug 16 18:05:16.757153: | natd_hash: hash=  27 7f 49 0f  61 d8 05 40  cc 
a5 6b 38  95 72 03 11
Aug 16 18:05:16.757158: | natd_hash: hash=  40 bd 77 c6
Aug 16 18:05:16.757163: | NAT_TRAVERSAL encaps using auto-detect
Aug 16 18:05:16.757168: | NAT_TRAVERSAL this end is NOT behind NAT
Aug 16 18:05:16.757173: | NAT_TRAVERSAL that end is behind NAT 1.144.95.124
Aug 16 18:05:16.757178: | NAT_TRAVERSAL nat_keepalive enabled 1.144.95.124
Aug 16 18:05:16.757185: | adding ikev2_inI1outR1 KE work-order 138 for 
state #138
Aug 16 18:05:16.757191: | state #138 requesting to delete non existing event
Aug 16 18:05:16.757197: | event_schedule: new 
EVENT_CRYPTO_TIMEOUT-pe at 0x7f4024005be0
Aug 16 18:05:16.757206: | inserting event EVENT_CRYPTO_TIMEOUT, timeout 
in 60.000 seconds for #138
Aug 16 18:05:16.757216: | backlog: inserting object 0x5598d74f3ca0 
(work-order 138 state #138) entry 0x5598d74f3ca8 into list 
0x5598d5c4a480 (older 0x5598d5c4a480 newer 0x5598d5c4a480)
Aug 16 18:05:16.757228: | backlog: inserted  object 0x5598d74f3ca0 
(work-order 138 state #138) entry 0x5598d74f3ca8 (older 0x5598d5c4a480 
newer 0x5598d5c4a480)
Aug 16 18:05:16.757235: | backlog: list entry 0x5598d5c4a480 is HEAD 
(older 0x5598d74f3ca8 newer 0x5598d74f3ca8)
Aug 16 18:05:16.757254: | suspending state #138 and saving MD
Aug 16 18:05:16.757261: | #138 is busy; has a suspended MD
Aug 16 18:05:16.757269: | processing: [RE]START state #138 connection 
"router-2.reub.net-ipv4"[1] 1.144.95.124 1.144.95.124:585 (in 
log_stf_suspend() at ikev2.c:2709)
Aug 16 18:05:16.757277: | "router-2.reub.net-ipv4"[1] 1.144.95.124 #138 
complete v2 state STATE_PARENT_R1 transition with STF_SUSPEND suspended 
from complete_v2_state_transition:2781
Aug 16 18:05:16.757284: | processing: stop from 1.144.95.124:585 
(BACKGROUND) (in process_md() at demux.c:394)
Aug 16 18:05:16.757297: | processing: stop state #138 connection 
"router-2.reub.net-ipv4"[1] 1.144.95.124 1.144.95.124:585 (in 
process_md() at demux.c:396)
Aug 16 18:05:16.757283: | crypto helper 2 resuming
Aug 16 18:05:16.757336: | backlog: removing  object 0x5598d74f3ca0 
(work-order 138 state #138) entry 0x5598d74f3ca8 (older 0x5598d5c4a480 
newer 0x5598d5c4a480)
Aug 16 18:05:16.757349: | backlog: empty
Aug 16 18:05:16.757304: | serialno table: hash serialno #0 to head 
0x5598d5c3ec00
Aug 16 18:05:16.757356: | crypto helper 2 starting work-order 138 for 
state #138
Aug 16 18:05:16.757376: | crypto helper 2 doing build KE and nonce; 
request ID 138
Aug 16 18:05:16.757366: | serialno table: hash serialno #0 to head 
0x5598d5c3ec00
Aug 16 18:05:16.757396: | processing: STOP connection NULL (in 
process_md() at demux.c:397)
Aug 16 18:05:16.758251: | crypto helper 2 finished build KE and nonce; 
request ID 138 time elapsed 873 usec
Aug 16 18:05:16.758264: | crypto helper 2 sending results from 
work-order 138 for state #138 to event queue
Aug 16 18:05:16.758270: | scheduling now-event sending helper answer for 
#138
Aug 16 18:05:16.758291: | crypto helper 2 waiting (nothing to do)
Aug 16 18:05:16.758338: | executing now-event sending helper answer for 138
Aug 16 18:05:16.758351: | serialno table: hash serialno #138 to head 
0x5598d5c3fd40
Aug 16 18:05:16.758356: | serialno table: hash serialno #138 to head 
0x5598d5c3fd40
Aug 16 18:05:16.758365: | processing: start state #138 connection 
"router-2.reub.net-ipv4"[1] 1.144.95.124 1.144.95.124:585 (in 
schedule_event_now_cb() at server.c:595)
Aug 16 18:05:16.758372: | crypto helper 2 replies to request ID 138
Aug 16 18:05:16.758377: | calling continuation function 0x5598d5b59000
Aug 16 18:05:16.758382: | ikev2_parent_inI1outR1_continue for #138: 
calculated ke+nonce, sending R1
Aug 16 18:05:16.758403: | **emit ISAKMP Message:
Aug 16 18:05:16.758409: |    initiator cookie:
Aug 16 18:05:16.758414: |   fe e6 d7 65  ca 54 75 3b
Aug 16 18:05:16.758419: |    responder cookie:
Aug 16 18:05:16.758423: |   85 50 50 ce  a9 e8 c3 59
Aug 16 18:05:16.758429: |    first contained payload type: 
ISAKMP_NEXT_v2SA (0x21)
Aug 16 18:05:16.758434: |    ISAKMP version: IKEv2 version 2.0 
(rfc4306/rfc5996) (0x20)
Aug 16 18:05:16.758439: |    exchange type: ISAKMP_v2_SA_INIT (0x22)
Aug 16 18:05:16.758454: |    flags: ISAKMP_FLAG_v2_MSG_RESPONSE (0x20)
Aug 16 18:05:16.758461: |    message ID:  00 00 00 00
Aug 16 18:05:16.758467: | next payload type: saving message location 
'ISAKMP Message'.'first contained payload type'
Aug 16 18:05:16.758473: | Emitting ikev2_proposal ...
Aug 16 18:05:16.758479: | next payload type: previous 'ISAKMP 
Message'.'first contained payload type' matches 'IKEv2 Security 
Association Payload' (33:ISAKMP_NEXT_v2SA)
Aug 16 18:05:16.758485: | ***emit IKEv2 Security Association Payload:
Aug 16 18:05:16.758490: |    next payload type: ISAKMP_NEXT_v2KE (0x22)
Aug 16 18:05:16.758495: |    flags: none (0x0)
Aug 16 18:05:16.758501: | next payload type: saving payload location 
'IKEv2 Security Association Payload'.'next payload type'
Aug 16 18:05:16.758512: | nowhere to backpatch ISAKMP_NEXT_P
Aug 16 18:05:16.758518: | ****emit IKEv2 Proposal Substructure Payload:
Aug 16 18:05:16.758523: |    last proposal: v2_PROPOSAL_LAST (0x0)
Aug 16 18:05:16.758528: |    prop #: 1 (0x1)
Aug 16 18:05:16.758533: |    proto ID: IKEv2_SEC_PROTO_IKE (0x1)
Aug 16 18:05:16.758538: |    spi size: 0 (0x0)
Aug 16 18:05:16.758543: |    # transforms: 4 (0x4)
Aug 16 18:05:16.758548: | next payload type: saving payload location 
'IKEv2 Proposal Substructure Payload'.'last proposal'
Aug 16 18:05:16.758553: | nowhere to backpatch ISAKMP_NEXT_T
Aug 16 18:05:16.758558: | *****emit IKEv2 Transform Substructure Payload:
Aug 16 18:05:16.758564: |    last transform: v2_TRANSFORM_NON_LAST (0x3)
Aug 16 18:05:16.758569: |    IKEv2 transform type: TRANS_TYPE_ENCR (0x1)
Aug 16 18:05:16.758574: |    IKEv2 transform ID: AES_CBC (0xc)
Aug 16 18:05:16.758579: | next payload type: saving payload location 
'IKEv2 Transform Substructure Payload'.'last transform'
Aug 16 18:05:16.758585: | ******emit IKEv2 Attribute Substructure Payload:
Aug 16 18:05:16.758590: |    af+type: IKEv2_KEY_LENGTH (0x800e)
Aug 16 18:05:16.758595: |    length/value: 256 (0x100)
Aug 16 18:05:16.758600: | emitting length of IKEv2 Transform 
Substructure Payload: 12
Aug 16 18:05:16.758606: | next payload type: previous 'IKEv2 Transform 
Substructure Payload'.'last transform' matches 'IKEv2 Transform 
Substructure Payload' (3:v2_TRANSFORM_NON_LAST)
Aug 16 18:05:16.758612: | *****emit IKEv2 Transform Substructure Payload:
Aug 16 18:05:16.758617: |    last transform: v2_TRANSFORM_NON_LAST (0x3)
Aug 16 18:05:16.758622: |    IKEv2 transform type: TRANS_TYPE_PRF (0x2)
Aug 16 18:05:16.758627: |    IKEv2 transform ID: PRF_HMAC_SHA2_512 (0x7)
Aug 16 18:05:16.758632: | next payload type: saving payload location 
'IKEv2 Transform Substructure Payload'.'last transform'
Aug 16 18:05:16.758638: | emitting length of IKEv2 Transform 
Substructure Payload: 8
Aug 16 18:05:16.758643: | next payload type: previous 'IKEv2 Transform 
Substructure Payload'.'last transform' matches 'IKEv2 Transform 
Substructure Payload' (3:v2_TRANSFORM_NON_LAST)
Aug 16 18:05:16.758649: | *****emit IKEv2 Transform Substructure Payload:
Aug 16 18:05:16.758654: |    last transform: v2_TRANSFORM_NON_LAST (0x3)
Aug 16 18:05:16.758659: |    IKEv2 transform type: TRANS_TYPE_INTEG (0x3)
Aug 16 18:05:16.758664: |    IKEv2 transform ID: AUTH_HMAC_SHA2_512_256 
(0xe)
Aug 16 18:05:16.758669: | next payload type: saving payload location 
'IKEv2 Transform Substructure Payload'.'last transform'
Aug 16 18:05:16.758675: | emitting length of IKEv2 Transform 
Substructure Payload: 8
Aug 16 18:05:16.758680: | next payload type: previous 'IKEv2 Transform 
Substructure Payload'.'last transform' matches 'IKEv2 Transform 
Substructure Payload' (3:v2_TRANSFORM_NON_LAST)
Aug 16 18:05:16.758686: | *****emit IKEv2 Transform Substructure Payload:
Aug 16 18:05:16.758691: |    last transform: v2_TRANSFORM_LAST (0x0)
Aug 16 18:05:16.758696: |    IKEv2 transform type: TRANS_TYPE_DH (0x4)
Aug 16 18:05:16.758701: |    IKEv2 transform ID: OAKLEY_GROUP_ECP_256 (0x13)
Aug 16 18:05:16.758706: | next payload type: saving payload location 
'IKEv2 Transform Substructure Payload'.'last transform'
Aug 16 18:05:16.758711: | emitting length of IKEv2 Transform 
Substructure Payload: 8
Aug 16 18:05:16.758716: | emitting length of IKEv2 Proposal Substructure 
Payload: 44
Aug 16 18:05:16.758722: | emitting length of IKEv2 Security Association 
Payload: 48
Aug 16 18:05:16.758728: | next payload type: previous 'IKEv2 Security 
Association Payload'.'next payload type' matches 'IKEv2 Key Exchange 
Payload' (34:ISAKMP_NEXT_v2KE)
Aug 16 18:05:16.758734: | ***emit IKEv2 Key Exchange Payload:
Aug 16 18:05:16.758739: |    next payload type: ISAKMP_NEXT_v2Ni (0x28)
Aug 16 18:05:16.758744: |    flags: none (0x0)
Aug 16 18:05:16.758749: |    DH group: OAKLEY_GROUP_ECP_256 (0x13)
Aug 16 18:05:16.758754: | next payload type: saving payload location 
'IKEv2 Key Exchange Payload'.'next payload type'
Aug 16 18:05:16.758760: | emitting 64 raw bytes of ikev2 g^x into IKEv2 
Key Exchange Payload
Aug 16 18:05:16.758769: | ikev2 g^x  34 f1 1b 2c  55 2e 08 2e  df 15 fb 
f4  c9 03 89 ec
Aug 16 18:05:16.758774: | ikev2 g^x  47 4c df 56  d4 b6 22 1f  20 21 11 
87  04 f3 77 8f
Aug 16 18:05:16.758779: | ikev2 g^x  9b b9 b1 09  06 a0 98 fc  f7 63 74 
2f  c6 62 b4 6c
Aug 16 18:05:16.758784: | ikev2 g^x  94 67 fa 02  56 a0 a6 de  9c 7d 35 
91  fd 03 ae 61
Aug 16 18:05:16.758790: | emitting length of IKEv2 Key Exchange Payload: 72
Aug 16 18:05:16.758796: | next payload type: previous 'IKEv2 Key 
Exchange Payload'.'next payload type' matches 'IKEv2 Nonce Payload' 
(40:ISAKMP_NEXT_v2Ni)
Aug 16 18:05:16.758801: | ***emit IKEv2 Nonce Payload:
Aug 16 18:05:16.758806: |    next payload type: ISAKMP_NEXT_v2N (0x29)
Aug 16 18:05:16.758811: |    flags: none (0x0)
Aug 16 18:05:16.758816: | next payload type: saving payload location 
'IKEv2 Nonce Payload'.'next payload type'
Aug 16 18:05:16.758822: | emitting 32 raw bytes of IKEv2 nonce into 
IKEv2 Nonce Payload
Aug 16 18:05:16.758827: | IKEv2 nonce  4c 39 cc 2d  a1 8a fd fc  e3 9a 
fe 0f  86 b9 88 ca
Aug 16 18:05:16.758832: | IKEv2 nonce  7d 95 01 9c  6d db a3 67  6d 53 
40 5d  bd d4 6c 11
Aug 16 18:05:16.758837: | emitting length of IKEv2 Nonce Payload: 36
Aug 16 18:05:16.758842: | Adding a v2N Payload
Aug 16 18:05:16.758848: | next payload type: previous 'IKEv2 Nonce 
Payload'.'next payload type' matches 'IKEv2 Notify Payload' 
(41:ISAKMP_NEXT_v2N)
Aug 16 18:05:16.758853: | ***emit IKEv2 Notify Payload:
Aug 16 18:05:16.758858: |    next payload type: ISAKMP_NEXT_v2N (0x29)
Aug 16 18:05:16.758863: |    flags: none (0x0)
Aug 16 18:05:16.758868: |    Protocol ID: PROTO_v2_RESERVED (0x0)
Aug 16 18:05:16.758873: |    SPI size: 0 (0x0)
Aug 16 18:05:16.758879: |    Notify Message Type: 
v2N_IKEV2_FRAGMENTATION_SUPPORTED (0x402e)
Aug 16 18:05:16.758884: | next payload type: saving payload location 
'IKEv2 Notify Payload'.'next payload type'
Aug 16 18:05:16.758890: | emitting 0 raw bytes of Notify data into IKEv2 
Notify Payload
Aug 16 18:05:16.758894: | Notify data
Aug 16 18:05:16.758900: | emitting length of IKEv2 Notify Payload: 8
Aug 16 18:05:16.758906: |  NAT-Traversal support  [enabled] add v2N 
payloads.
Aug 16 18:05:16.758922: | natd_hash: hasher=0x5598d5c2b600(20)
Aug 16 18:05:16.758929: | natd_hash: icookie=  fe e6 d7 65  ca 54 75 3b
Aug 16 18:05:16.758934: | natd_hash: rcookie=  85 50 50 ce  a9 e8 c3 59
Aug 16 18:05:16.758939: | natd_hash: ip=  6e e8 70 d1
Aug 16 18:05:16.758944: | natd_hash: port=500
Aug 16 18:05:16.758949: | natd_hash: hash=  72 3c 32 21  90 45 d7 88  fc 
54 3a da  73 30 20 93
Aug 16 18:05:16.758953: | natd_hash: hash=  1f b3 b4 5c
Aug 16 18:05:16.758958: | Adding a v2N Payload
Aug 16 18:05:16.758964: | next payload type: previous 'IKEv2 Notify 
Payload'.'next payload type' matches 'IKEv2 Notify Payload' 
(41:ISAKMP_NEXT_v2N)
Aug 16 18:05:16.758969: | ***emit IKEv2 Notify Payload:
Aug 16 18:05:16.758974: |    next payload type: ISAKMP_NEXT_v2N (0x29)
Aug 16 18:05:16.758979: |    flags: none (0x0)
Aug 16 18:05:16.758984: |    Protocol ID: PROTO_v2_RESERVED (0x0)
Aug 16 18:05:16.758989: |    SPI size: 0 (0x0)
Aug 16 18:05:16.758994: |    Notify Message Type: 
v2N_NAT_DETECTION_SOURCE_IP (0x4004)
Aug 16 18:05:16.758999: | next payload type: saving payload location 
'IKEv2 Notify Payload'.'next payload type'
Aug 16 18:05:16.759004: | emitting 20 raw bytes of Notify data into 
IKEv2 Notify Payload
Aug 16 18:05:16.759009: | Notify data  72 3c 32 21  90 45 d7 88  fc 54 
3a da  73 30 20 93
Aug 16 18:05:16.759014: | Notify data  1f b3 b4 5c
Aug 16 18:05:16.759019: | emitting length of IKEv2 Notify Payload: 28
Aug 16 18:05:16.759038: | natd_hash: hasher=0x5598d5c2b600(20)
Aug 16 18:05:16.759045: | natd_hash: icookie=  fe e6 d7 65  ca 54 75 3b
Aug 16 18:05:16.759050: | natd_hash: rcookie=  85 50 50 ce  a9 e8 c3 59
Aug 16 18:05:16.759055: | natd_hash: ip=  01 90 5f 7c
Aug 16 18:05:16.759060: | natd_hash: port=585
Aug 16 18:05:16.759065: | natd_hash: hash=  65 62 64 7e  79 3c e9 29  00 
48 1a 91  3d 0a 60 15
Aug 16 18:05:16.759070: | natd_hash: hash=  69 5a f0 73
Aug 16 18:05:16.759079: | Adding a v2N Payload
Aug 16 18:05:16.759085: | next payload type: previous 'IKEv2 Notify 
Payload'.'next payload type' matches 'IKEv2 Notify Payload' 
(41:ISAKMP_NEXT_v2N)
Aug 16 18:05:16.759090: | ***emit IKEv2 Notify Payload:
Aug 16 18:05:16.759095: |    next payload type: ISAKMP_NEXT_v2NONE (0x0)
Aug 16 18:05:16.759100: |    flags: none (0x0)
Aug 16 18:05:16.759105: |    Protocol ID: PROTO_v2_RESERVED (0x0)
Aug 16 18:05:16.759110: |    SPI size: 0 (0x0)
Aug 16 18:05:16.759115: |    Notify Message Type: 
v2N_NAT_DETECTION_DESTINATION_IP (0x4005)
Aug 16 18:05:16.759120: | next payload type: saving payload location 
'IKEv2 Notify Payload'.'next payload type'
Aug 16 18:05:16.759126: | emitting 20 raw bytes of Notify data into 
IKEv2 Notify Payload
Aug 16 18:05:16.759131: | Notify data  65 62 64 7e  79 3c e9 29  00 48 
1a 91  3d 0a 60 15
Aug 16 18:05:16.759136: | Notify data  69 5a f0 73
Aug 16 18:05:16.759141: | emitting length of IKEv2 Notify Payload: 28
Aug 16 18:05:16.759146: | emitting length of ISAKMP Message: 248
Aug 16 18:05:16.759155: | processing: [RE]START state #138 connection 
"router-2.reub.net-ipv4"[1] 1.144.95.124 1.144.95.124:585 (in 
complete_v2_state_transition() at ikev2.c:2805)
Aug 16 18:05:16.759162: | #138 complete v2 state transition from 
STATE_PARENT_R1 with STF_OK
Aug 16 18:05:16.759167: | IKEv2: transition from state STATE_IKEv2_BASE 
to state STATE_PARENT_R1
Aug 16 18:05:16.759175: | message ID #138 STATE_PARENT_R1 
router-2.reub.net-ipv4 pst #138 st_msgid_nextuse(before=0) 0 
st_msgid_lastack 4294967295 st_msgid_lastrecv 0 md is a request
Aug 16 18:05:16.759184: "router-2.reub.net-ipv4"[1] 1.144.95.124 #138: 
STATE_PARENT_R1: received v2I1, sent v2R1 {auth=IKEv2 cipher=aes_256 
integ=sha512_256 prf=sha2_512 group=DH19}
Aug 16 18:05:16.759191: | sending V2 new request packet to 
1.144.95.124:585 (from port 500)
Aug 16 18:05:16.759198: | sending 248 bytes for STATE_IKEv2_BASE through 
eth0:500 to 1.144.95.124:585 (using #138)
Aug 16 18:05:16.759203: |   fe e6 d7 65  ca 54 75 3b  85 50 50 ce  a9 e8 
c3 59
Aug 16 18:05:16.759208: |   21 20 22 20  00 00 00 00  00 00 00 f8  22 00 
00 30
Aug 16 18:05:16.759213: |   00 00 00 2c  01 01 00 04  03 00 00 0c  01 00 
00 0c
Aug 16 18:05:16.759217: |   80 0e 01 00  03 00 00 08  02 00 00 07  03 00 
00 08
Aug 16 18:05:16.759222: |   03 00 00 0e  00 00 00 08  04 00 00 13  28 00 
00 48
Aug 16 18:05:16.759227: |   00 13 00 00  34 f1 1b 2c  55 2e 08 2e  df 15 
fb f4
Aug 16 18:05:16.759231: |   c9 03 89 ec  47 4c df 56  d4 b6 22 1f  20 21 
11 87
Aug 16 18:05:16.759236: |   04 f3 77 8f  9b b9 b1 09  06 a0 98 fc  f7 63 
74 2f
Aug 16 18:05:16.759241: |   c6 62 b4 6c  94 67 fa 02  56 a0 a6 de  9c 7d 
35 91
Aug 16 18:05:16.759245: |   fd 03 ae 61  29 00 00 24  4c 39 cc 2d  a1 8a 
fd fc
Aug 16 18:05:16.759250: |   e3 9a fe 0f  86 b9 88 ca  7d 95 01 9c  6d db 
a3 67
Aug 16 18:05:16.759254: |   6d 53 40 5d  bd d4 6c 11  29 00 00 08  00 00 
40 2e
Aug 16 18:05:16.759259: |   29 00 00 1c  00 00 40 04  72 3c 32 21  90 45 
d7 88
Aug 16 18:05:16.759264: |   fc 54 3a da  73 30 20 93  1f b3 b4 5c  00 00 
00 1c
Aug 16 18:05:16.759268: |   00 00 40 05  65 62 64 7e  79 3c e9 29  00 48 
1a 91
Aug 16 18:05:16.759273: |   3d 0a 60 15  69 5a f0 73
Aug 16 18:05:16.759321: | state #138 requesting EVENT_CRYPTO_TIMEOUT to 
be deleted
Aug 16 18:05:16.759332: | free_event_entry: release 
EVENT_CRYPTO_TIMEOUT-pe at 0x7f4024005be0
Aug 16 18:05:16.759339: | event_schedule: new 
EVENT_v2_RESPONDER_TIMEOUT-pe at 0x7f4024005be0
Aug 16 18:05:16.759346: | inserting event EVENT_v2_RESPONDER_TIMEOUT, 
timeout in 200.000 seconds for #138
Aug 16 18:05:16.759357: | processing: stop state #138 connection 
"router-2.reub.net-ipv4"[1] 1.144.95.124 1.144.95.124:585 (in 
schedule_event_now_cb() at server.c:598)
Aug 16 18:05:16.759363: | serialno table: hash serialno #0 to head 
0x5598d5c3ec00
Aug 16 18:05:16.759369: | serialno table: hash serialno #0 to head 
0x5598d5c3ec00
Aug 16 18:05:17.783049: |  kernel_process_msg_cb process netlink message
Aug 16 18:05:17.783100: | netlink_get: XFRM_MSG_DELPOLICY message
Aug 16 18:05:17.783109: | xfrm netlink address change RTM_NEWADDR msg len 72
Aug 16 18:05:18.342951: |  kernel_process_msg_cb process netlink message
Aug 16 18:05:18.343003: | netlink_get: XFRM_MSG_DELPOLICY message
Aug 16 18:05:18.343011: | xfrm netlink address change RTM_NEWADDR msg len 72
Aug 16 18:05:18.485488: | *received 366 bytes from 1.144.95.124:585 on 
eth0 (port=500)
Aug 16 18:05:18.485531: |   fe e6 d7 65  ca 54 75 3b  00 00 00 00  00 00 
00 00
Aug 16 18:05:18.485537: |   21 20 22 08  00 00 00 00  00 00 01 6e  22 00 
00 58
Aug 16 18:05:18.485542: |   00 00 00 54  01 01 00 09  03 00 00 0c  01 00 
00 0c
Aug 16 18:05:18.485547: |   80 0e 01 00  03 00 00 08  02 00 00 07  03 00 
00 08
Aug 16 18:05:18.485552: |   02 00 00 06  03 00 00 08  03 00 00 0e  03 00 
00 08
Aug 16 18:05:18.485556: |   03 00 00 0d  03 00 00 08  04 00 00 13  03 00 
00 08
Aug 16 18:05:18.485561: |   04 00 00 0e  03 00 00 08  04 00 00 15  00 00 
00 08
Aug 16 18:05:18.485566: |   04 00 00 05  28 00 00 48  00 13 00 00  48 12 
de ee
Aug 16 18:05:18.485570: |   dc 50 dd cf  ad 6b 86 a6  bd fe 04 ee  ea 29 
8e 71
Aug 16 18:05:18.485575: |   a1 15 96 ec  9e c0 63 4e  aa 3c 4e 5b  83 ea 
28 19
Aug 16 18:05:18.485580: |   01 4b 35 07  2c cb 57 8e  ff a6 7b 74  64 84 
60 eb
Aug 16 18:05:18.485584: |   a0 64 89 e9  cf 99 a5 ec  80 79 6f a6  2b 00 
00 24
Aug 16 18:05:18.485589: |   b2 f5 63 a3  ba f9 8b 10  5d 6f ae 01  01 42 
f0 2f
Aug 16 18:05:18.485594: |   7f 49 bc 76  da 9e a8 b2  dd 01 30 df  ea 6e 
da 10
Aug 16 18:05:18.485598: |   2b 00 00 17  43 49 53 43  4f 2d 44 45  4c 45 
54 45
Aug 16 18:05:18.485603: |   2d 52 45 41  53 4f 4e 2b  00 00 13 43  49 53 
43 4f
Aug 16 18:05:18.485608: |   56 50 4e 2d  52 45 56 2d  30 32 2b 00  00 17 
43 49
Aug 16 18:05:18.485612: |   53 43 4f 2d  44 59 4e 41  4d 49 43 2d  52 4f 
55 54
Aug 16 18:05:18.485617: |   45 29 00 00  15 46 4c 45  58 56 50 4e  2d 53 
55 50
Aug 16 18:05:18.485622: |   50 4f 52 54  45 44 29 00  00 1c 00 00  40 04 
91 1c
Aug 16 18:05:18.485626: |   4b 8a 6e 11  99 bd e1 b4  7d 9b 10 77  c9 8f 
b8 5b
Aug 16 18:05:18.485631: |   1e 56 00 00  00 1c 00 00  40 05 36 f4  89 56 
72 d3
Aug 16 18:05:18.485636: |   7e 65 57 d7  ef 2e ee 35  09 d4 54 16  58 bf
Aug 16 18:05:18.485645: | processing: start from 1.144.95.124:585 (in 
process_md() at demux.c:392)
Aug 16 18:05:18.485654: | **parse ISAKMP Message:
Aug 16 18:05:18.485659: |    initiator cookie:
Aug 16 18:05:18.485664: |   fe e6 d7 65  ca 54 75 3b
Aug 16 18:05:18.485669: |    responder cookie:
Aug 16 18:05:18.485674: |   00 00 00 00  00 00 00 00
Aug 16 18:05:18.485680: |    first contained payload type: 
ISAKMP_NEXT_v2SA (0x21)
Aug 16 18:05:18.485686: |    ISAKMP version: IKEv2 version 2.0 
(rfc4306/rfc5996) (0x20)
Aug 16 18:05:18.485691: |    exchange type: ISAKMP_v2_SA_INIT (0x22)
Aug 16 18:05:18.485697: |    flags: ISAKMP_FLAG_v2_IKE_INIT (0x8)
Aug 16 18:05:18.485702: |    message ID:  00 00 00 00
Aug 16 18:05:18.485707: |    length: 366 (0x16e)
Aug 16 18:05:18.485713: |  processing version=2.0 packet with exchange 
type=ISAKMP_v2_SA_INIT (34)
Aug 16 18:05:18.485719: | I am receiving an IKEv2 Request ISAKMP_v2_SA_INIT
Aug 16 18:05:18.485724: | I am the IKE SA Original Responder
Aug 16 18:05:18.485733: | icookie table: hash icookie fe e6 d7 65  ca 54 
75 3b to 15999983715547008262 slot 0x5598d5c3e680
Aug 16 18:05:18.485739: | parent_init v2 peer and cookies match on #138
Aug 16 18:05:18.485744: | v2 state object #138 found, in STATE_PARENT_R1
Aug 16 18:05:18.485755: | processing: start state #138 connection 
"router-2.reub.net-ipv4"[1] 1.144.95.124 1.144.95.124:585 (in 
ikev2_process_packet() at ikev2.c:1403)
Aug 16 18:05:18.485761: | #138 is idle
Aug 16 18:05:18.485767: | #138 STATE_PARENT_R1: retransmits: duplicate 
IKE_INIT_I message received, retransmiting previous packet
Aug 16 18:05:18.485775: | sending 248 bytes for 
ikev2-responder-retransmit IKE_SA_INIT through eth0:500 to 
1.144.95.124:585 (using #138)
Aug 16 18:05:18.485780: |   fe e6 d7 65  ca 54 75 3b  85 50 50 ce  a9 e8 
c3 59
Aug 16 18:05:18.485785: |   21 20 22 20  00 00 00 00  00 00 00 f8  22 00 
00 30
Aug 16 18:05:18.485790: |   00 00 00 2c  01 01 00 04  03 00 00 0c  01 00 
00 0c
Aug 16 18:05:18.485807: |   80 0e 01 00  03 00 00 08  02 00 00 07  03 00 
00 08
Aug 16 18:05:18.485812: |   03 00 00 0e  00 00 00 08  04 00 00 13  28 00 
00 48
Aug 16 18:05:18.485817: |   00 13 00 00  34 f1 1b 2c  55 2e 08 2e  df 15 
fb f4
Aug 16 18:05:18.485822: |   c9 03 89 ec  47 4c df 56  d4 b6 22 1f  20 21 
11 87
Aug 16 18:05:18.485827: |   04 f3 77 8f  9b b9 b1 09  06 a0 98 fc  f7 63 
74 2f
Aug 16 18:05:18.485832: |   c6 62 b4 6c  94 67 fa 02  56 a0 a6 de  9c 7d 
35 91
Aug 16 18:05:18.485836: |   fd 03 ae 61  29 00 00 24  4c 39 cc 2d  a1 8a 
fd fc
Aug 16 18:05:18.485841: |   e3 9a fe 0f  86 b9 88 ca  7d 95 01 9c  6d db 
a3 67
Aug 16 18:05:18.485846: |   6d 53 40 5d  bd d4 6c 11  29 00 00 08  00 00 
40 2e
Aug 16 18:05:18.485850: |   29 00 00 1c  00 00 40 04  72 3c 32 21  90 45 
d7 88
Aug 16 18:05:18.485855: |   fc 54 3a da  73 30 20 93  1f b3 b4 5c  00 00 
00 1c
Aug 16 18:05:18.485860: |   00 00 40 05  65 62 64 7e  79 3c e9 29  00 48 
1a 91
Aug 16 18:05:18.485864: |   3d 0a 60 15  69 5a f0 73
Aug 16 18:05:18.485912: | processing: stop state #138 connection 
"router-2.reub.net-ipv4"[1] 1.144.95.124 1.144.95.124:585 (in 
ikev2_process_packet() at ikev2.c:1414)
Aug 16 18:05:18.485922: | serialno table: hash serialno #0 to head 
0x5598d5c3ec00
Aug 16 18:05:18.485927: | serialno table: hash serialno #0 to head 
0x5598d5c3ec00
Aug 16 18:05:18.485934: | processing: stop from 1.144.95.124:585 (in 
process_md() at demux.c:394)
Aug 16 18:05:18.485942: | processing: STOP state #0 (in process_md() at 
demux.c:396)
Aug 16 18:05:18.485947: | serialno table: hash serialno #0 to head 
0x5598d5c3ec00
Aug 16 18:05:18.485952: | serialno table: hash serialno #0 to head 
0x5598d5c3ec00
Aug 16 18:05:18.485958: | processing: STOP connection NULL (in 
process_md() at demux.c:397)
Aug 16 18:05:19.276847: | timer_event_cb: processing event at 0x7f40240050a0
Aug 16 18:05:19.276962: | handling event EVENT_SHUNT_SCAN
Aug 16 18:05:19.277179: | expiring aged bare shunts from shunt table
Aug 16 18:05:19.277197: | event_schedule: new 
EVENT_SHUNT_SCAN-pe at 0x7f40340046d0
Aug 16 18:05:19.277213: | inserting event EVENT_SHUNT_SCAN, timeout in 
20.000 seconds
Aug 16 18:05:19.277231: | free_event_entry: release 
EVENT_SHUNT_SCAN-pe at 0x7f40240050a0
Aug 16 18:05:21.566546: |  kernel_process_msg_cb process netlink message
Aug 16 18:05:21.566599: | netlink_get: XFRM_MSG_DELPOLICY message
Aug 16 18:05:21.566607: | xfrm netlink address change RTM_NEWADDR msg len 72
Aug 16 18:05:22.066594: | *received 366 bytes from 1.144.95.124:585 on 
eth0 (port=500)
Aug 16 18:05:22.066638: |   fe e6 d7 65  ca 54 75 3b  00 00 00 00  00 00 
00 00
Aug 16 18:05:22.066644: |   21 20 22 08  00 00 00 00  00 00 01 6e  22 00 
00 58
Aug 16 18:05:22.066649: |   00 00 00 54  01 01 00 09  03 00 00 0c  01 00 
00 0c
Aug 16 18:05:22.066654: |   80 0e 01 00  03 00 00 08  02 00 00 07  03 00 
00 08
Aug 16 18:05:22.066659: |   02 00 00 06  03 00 00 08  03 00 00 0e  03 00 
00 08
Aug 16 18:05:22.066664: |   03 00 00 0d  03 00 00 08  04 00 00 13  03 00 
00 08
Aug 16 18:05:22.066669: |   04 00 00 0e  03 00 00 08  04 00 00 15  00 00 
00 08
Aug 16 18:05:22.066674: |   04 00 00 05  28 00 00 48  00 13 00 00  48 12 
de ee
Aug 16 18:05:22.066679: |   dc 50 dd cf  ad 6b 86 a6  bd fe 04 ee  ea 29 
8e 71
Aug 16 18:05:22.066683: |   a1 15 96 ec  9e c0 63 4e  aa 3c 4e 5b  83 ea 
28 19
Aug 16 18:05:22.066688: |   01 4b 35 07  2c cb 57 8e  ff a6 7b 74  64 84 
60 eb
Aug 16 18:05:22.066693: |   a0 64 89 e9  cf 99 a5 ec  80 79 6f a6  2b 00 
00 24
Aug 16 18:05:22.066698: |   b2 f5 63 a3  ba f9 8b 10  5d 6f ae 01  01 42 
f0 2f
Aug 16 18:05:22.066703: |   7f 49 bc 76  da 9e a8 b2  dd 01 30 df  ea 6e 
da 10
Aug 16 18:05:22.066707: |   2b 00 00 17  43 49 53 43  4f 2d 44 45  4c 45 
54 45
Aug 16 18:05:22.066712: |   2d 52 45 41  53 4f 4e 2b  00 00 13 43  49 53 
43 4f
Aug 16 18:05:22.066717: |   56 50 4e 2d  52 45 56 2d  30 32 2b 00  00 17 
43 49
Aug 16 18:05:22.066722: |   53 43 4f 2d  44 59 4e 41  4d 49 43 2d  52 4f 
55 54
Aug 16 18:05:22.066726: |   45 29 00 00  15 46 4c 45  58 56 50 4e  2d 53 
55 50
Aug 16 18:05:22.066731: |   50 4f 52 54  45 44 29 00  00 1c 00 00  40 04 
91 1c
Aug 16 18:05:22.066752: |   4b 8a 6e 11  99 bd e1 b4  7d 9b 10 77  c9 8f 
b8 5b
Aug 16 18:05:22.066758: |   1e 56 00 00  00 1c 00 00  40 05 36 f4  89 56 
72 d3
Aug 16 18:05:22.066763: |   7e 65 57 d7  ef 2e ee 35  09 d4 54 16  58 bf
Aug 16 18:05:22.066773: | processing: start from 1.144.95.124:585 (in 
process_md() at demux.c:392)
Aug 16 18:05:22.066782: | **parse ISAKMP Message:
Aug 16 18:05:22.066788: |    initiator cookie:
Aug 16 18:05:22.066793: |   fe e6 d7 65  ca 54 75 3b
Aug 16 18:05:22.066798: |    responder cookie:
Aug 16 18:05:22.066803: |   00 00 00 00  00 00 00 00
Aug 16 18:05:22.066809: |    first contained payload type: 
ISAKMP_NEXT_v2SA (0x21)
Aug 16 18:05:22.066814: |    ISAKMP version: IKEv2 version 2.0 
(rfc4306/rfc5996) (0x20)
Aug 16 18:05:22.066820: |    exchange type: ISAKMP_v2_SA_INIT (0x22)
Aug 16 18:05:22.066826: |    flags: ISAKMP_FLAG_v2_IKE_INIT (0x8)
Aug 16 18:05:22.066831: |    message ID:  00 00 00 00
Aug 16 18:05:22.066836: |    length: 366 (0x16e)
Aug 16 18:05:22.066842: |  processing version=2.0 packet with exchange 
type=ISAKMP_v2_SA_INIT (34)
Aug 16 18:05:22.066848: | I am receiving an IKEv2 Request ISAKMP_v2_SA_INIT
Aug 16 18:05:22.066853: | I am the IKE SA Original Responder
Aug 16 18:05:22.066862: | icookie table: hash icookie fe e6 d7 65  ca 54 
75 3b to 15999983715547008262 slot 0x5598d5c3e680
Aug 16 18:05:22.066868: | parent_init v2 peer and cookies match on #138
Aug 16 18:05:22.066874: | v2 state object #138 found, in STATE_PARENT_R1
Aug 16 18:05:22.066896: | processing: start state #138 connection 
"router-2.reub.net-ipv4"[1] 1.144.95.124 1.144.95.124:585 (in 
ikev2_process_packet() at ikev2.c:1403)
Aug 16 18:05:22.066903: | #138 is idle
Aug 16 18:05:22.066909: | #138 STATE_PARENT_R1: retransmits: duplicate 
IKE_INIT_I message received, retransmiting previous packet
Aug 16 18:05:22.066917: | sending 248 bytes for 
ikev2-responder-retransmit IKE_SA_INIT through eth0:500 to 
1.144.95.124:585 (using #138)
Aug 16 18:05:22.066922: |   fe e6 d7 65  ca 54 75 3b  85 50 50 ce  a9 e8 
c3 59
Aug 16 18:05:22.066926: |   21 20 22 20  00 00 00 00  00 00 00 f8  22 00 
00 30
Aug 16 18:05:22.066931: |   00 00 00 2c  01 01 00 04  03 00 00 0c  01 00 
00 0c
Aug 16 18:05:22.066936: |   80 0e 01 00  03 00 00 08  02 00 00 07  03 00 
00 08
Aug 16 18:05:22.066940: |   03 00 00 0e  00 00 00 08  04 00 00 13  28 00 
00 48
Aug 16 18:05:22.066945: |   00 13 00 00  34 f1 1b 2c  55 2e 08 2e  df 15 
fb f4
Aug 16 18:05:22.066949: |   c9 03 89 ec  47 4c df 56  d4 b6 22 1f  20 21 
11 87
Aug 16 18:05:22.066954: |   04 f3 77 8f  9b b9 b1 09  06 a0 98 fc  f7 63 
74 2f
Aug 16 18:05:22.066958: |   c6 62 b4 6c  94 67 fa 02  56 a0 a6 de  9c 7d 
35 91
Aug 16 18:05:22.066963: |   fd 03 ae 61  29 00 00 24  4c 39 cc 2d  a1 8a 
fd fc
Aug 16 18:05:22.066967: |   e3 9a fe 0f  86 b9 88 ca  7d 95 01 9c  6d db 
a3 67
Aug 16 18:05:22.066972: |   6d 53 40 5d  bd d4 6c 11  29 00 00 08  00 00 
40 2e
Aug 16 18:05:22.066977: |   29 00 00 1c  00 00 40 04  72 3c 32 21  90 45 
d7 88
Aug 16 18:05:22.066981: |   fc 54 3a da  73 30 20 93  1f b3 b4 5c  00 00 
00 1c
Aug 16 18:05:22.066986: |   00 00 40 05  65 62 64 7e  79 3c e9 29  00 48 
1a 91
Aug 16 18:05:22.066990: |   3d 0a 60 15  69 5a f0 73
Aug 16 18:05:22.067050: | processing: stop state #138 connection 
"router-2.reub.net-ipv4"[1] 1.144.95.124 1.144.95.124:585 (in 
ikev2_process_packet() at ikev2.c:1414)
Aug 16 18:05:22.067060: | serialno table: hash serialno #0 to head 
0x5598d5c3ec00
Aug 16 18:05:22.067066: | serialno table: hash serialno #0 to head 
0x5598d5c3ec00
Aug 16 18:05:22.067073: | processing: stop from 1.144.95.124:585 (in 
process_md() at demux.c:394)
Aug 16 18:05:22.067081: | processing: STOP state #0 (in process_md() at 
demux.c:396)
Aug 16 18:05:22.067086: | serialno table: hash serialno #0 to head 
0x5598d5c3ec00
Aug 16 18:05:22.067091: | serialno table: hash serialno #0 to head 
0x5598d5c3ec00
Aug 16 18:05:22.067097: | processing: STOP connection NULL (in 
process_md() at demux.c:397)
Aug 16 18:05:22.291117: |  kernel_process_msg_cb process netlink message
Aug 16 18:05:22.291200: | netlink_get: XFRM_MSG_DELPOLICY message
Aug 16 18:05:22.291215: | xfrm netlink address change RTM_NEWADDR msg len 72
Aug 16 18:05:24.810258: |  kernel_process_msg_cb process netlink message
Aug 16 18:05:24.810375: | netlink_get: XFRM_MSG_DELPOLICY message
Aug 16 18:05:24.810602: | xfrm netlink address change RTM_NEWADDR msg len 72
Aug 16 18:05:25.782974: |  kernel_process_msg_cb process netlink message
Aug 16 18:05:25.783024: | netlink_get: XFRM_MSG_DELPOLICY message
Aug 16 18:05:25.783033: | xfrm netlink address change RTM_NEWADDR msg len 72
Aug 16 18:05:28.547030: |  kernel_process_msg_cb process netlink message
Aug 16 18:05:28.547083: | netlink_get: XFRM_MSG_DELPOLICY message
Aug 16 18:05:28.547091: | xfrm netlink address change RTM_NEWADDR msg len 72
Aug 16 18:05:28.867894: |  kernel_process_msg_cb process netlink message
Aug 16 18:05:28.867955: | netlink_get: XFRM_MSG_DELPOLICY message
Aug 16 18:05:28.867969: | xfrm netlink address change RTM_NEWADDR msg len 72
Aug 16 18:05:30.074811: | *received 366 bytes from 1.144.95.124:585 on 
eth0 (port=500)
Aug 16 18:05:30.074934: |   fe e6 d7 65  ca 54 75 3b  00 00 00 00  00 00 
00 00
Aug 16 18:05:30.075164: |   21 20 22 08  00 00 00 00  00 00 01 6e  22 00 
00 58
Aug 16 18:05:30.075173: |   00 00 00 54  01 01 00 09  03 00 00 0c  01 00 
00 0c
Aug 16 18:05:30.075178: |   80 0e 01 00  03 00 00 08  02 00 00 07  03 00 
00 08
Aug 16 18:05:30.075183: |   02 00 00 06  03 00 00 08  03 00 00 0e  03 00 
00 08
Aug 16 18:05:30.075202: |   03 00 00 0d  03 00 00 08  04 00 00 13  03 00 
00 08
Aug 16 18:05:30.075209: |   04 00 00 0e  03 00 00 08  04 00 00 15  00 00 
00 08
Aug 16 18:05:30.075214: |   04 00 00 05  28 00 00 48  00 13 00 00  48 12 
de ee
Aug 16 18:05:30.075220: |   dc 50 dd cf  ad 6b 86 a6  bd fe 04 ee  ea 29 
8e 71
Aug 16 18:05:30.075225: |   a1 15 96 ec  9e c0 63 4e  aa 3c 4e 5b  83 ea 
28 19
Aug 16 18:05:30.075230: |   01 4b 35 07  2c cb 57 8e  ff a6 7b 74  64 84 
60 eb
Aug 16 18:05:30.075235: |   a0 64 89 e9  cf 99 a5 ec  80 79 6f a6  2b 00 
00 24
Aug 16 18:05:30.075239: |   b2 f5 63 a3  ba f9 8b 10  5d 6f ae 01  01 42 
f0 2f
Aug 16 18:05:30.075244: |   7f 49 bc 76  da 9e a8 b2  dd 01 30 df  ea 6e 
da 10
Aug 16 18:05:30.075249: |   2b 00 00 17  43 49 53 43  4f 2d 44 45  4c 45 
54 45
Aug 16 18:05:30.075255: |   2d 52 45 41  53 4f 4e 2b  00 00 13 43  49 53 
43 4f
Aug 16 18:05:30.075259: |   56 50 4e 2d  52 45 56 2d  30 32 2b 00  00 17 
43 49
Aug 16 18:05:30.075277: |   53 43 4f 2d  44 59 4e 41  4d 49 43 2d  52 4f 
55 54
Aug 16 18:05:30.075285: |   45 29 00 00  15 46 4c 45  58 56 50 4e  2d 53 
55 50
Aug 16 18:05:30.075290: |   50 4f 52 54  45 44 29 00  00 1c 00 00  40 04 
91 1c
Aug 16 18:05:30.075295: |   4b 8a 6e 11  99 bd e1 b4  7d 9b 10 77  c9 8f 
b8 5b
Aug 16 18:05:30.075311: |   1e 56 00 00  00 1c 00 00  40 05 36 f4  89 56 
72 d3
Aug 16 18:05:30.075317: |   7e 65 57 d7  ef 2e ee 35  09 d4 54 16  58 bf
Aug 16 18:05:30.075328: | processing: start from 1.144.95.124:585 (in 
process_md() at demux.c:392)
Aug 16 18:05:30.075337: | **parse ISAKMP Message:
Aug 16 18:05:30.075343: |    initiator cookie:
Aug 16 18:05:30.075348: |   fe e6 d7 65  ca 54 75 3b
Aug 16 18:05:30.075353: |    responder cookie:
Aug 16 18:05:30.075358: |   00 00 00 00  00 00 00 00
Aug 16 18:05:30.075364: |    first contained payload type: 
ISAKMP_NEXT_v2SA (0x21)
Aug 16 18:05:30.075370: |    ISAKMP version: IKEv2 version 2.0 
(rfc4306/rfc5996) (0x20)
Aug 16 18:05:30.075375: |    exchange type: ISAKMP_v2_SA_INIT (0x22)
Aug 16 18:05:30.075382: |    flags: ISAKMP_FLAG_v2_IKE_INIT (0x8)
Aug 16 18:05:30.075387: |    message ID:  00 00 00 00
Aug 16 18:05:30.075392: |    length: 366 (0x16e)
Aug 16 18:05:30.075398: |  processing version=2.0 packet with exchange 
type=ISAKMP_v2_SA_INIT (34)
Aug 16 18:05:30.075404: | I am receiving an IKEv2 Request ISAKMP_v2_SA_INIT
Aug 16 18:05:30.075409: | I am the IKE SA Original Responder
Aug 16 18:05:30.075418: | icookie table: hash icookie fe e6 d7 65  ca 54 
75 3b to 15999983715547008262 slot 0x5598d5c3e680
Aug 16 18:05:30.075425: | parent_init v2 peer and cookies match on #138
Aug 16 18:05:30.075438: | v2 state object #138 found, in STATE_PARENT_R1
Aug 16 18:05:30.075450: | processing: start state #138 connection 
"router-2.reub.net-ipv4"[1] 1.144.95.124 1.144.95.124:585 (in 
ikev2_process_packet() at ikev2.c:1403)
Aug 16 18:05:30.075456: | #138 is idle
Aug 16 18:05:30.075462: | #138 STATE_PARENT_R1: retransmits: duplicate 
IKE_INIT_I message received, retransmiting previous packet
Aug 16 18:05:30.075470: | sending 248 bytes for 
ikev2-responder-retransmit IKE_SA_INIT through eth0:500 to 
1.144.95.124:585 (using #138)
Aug 16 18:05:30.075475: |   fe e6 d7 65  ca 54 75 3b  85 50 50 ce  a9 e8 
c3 59
Aug 16 18:05:30.075480: |   21 20 22 20  00 00 00 00  00 00 00 f8  22 00 
00 30
Aug 16 18:05:30.075485: |   00 00 00 2c  01 01 00 04  03 00 00 0c  01 00 
00 0c
Aug 16 18:05:30.075490: |   80 0e 01 00  03 00 00 08  02 00 00 07  03 00 
00 08
Aug 16 18:05:30.075495: |   03 00 00 0e  00 00 00 08  04 00 00 13  28 00 
00 48
Aug 16 18:05:30.075500: |   00 13 00 00  34 f1 1b 2c  55 2e 08 2e  df 15 
fb f4
Aug 16 18:05:30.075504: |   c9 03 89 ec  47 4c df 56  d4 b6 22 1f  20 21 
11 87
Aug 16 18:05:30.075509: |   04 f3 77 8f  9b b9 b1 09  06 a0 98 fc  f7 63 
74 2f
Aug 16 18:05:30.075514: |   c6 62 b4 6c  94 67 fa 02  56 a0 a6 de  9c 7d 
35 91
Aug 16 18:05:30.075519: |   fd 03 ae 61  29 00 00 24  4c 39 cc 2d  a1 8a 
fd fc
Aug 16 18:05:30.075524: |   e3 9a fe 0f  86 b9 88 ca  7d 95 01 9c  6d db 
a3 67
Aug 16 18:05:30.075528: |   6d 53 40 5d  bd d4 6c 11  29 00 00 08  00 00 
40 2e
Aug 16 18:05:30.075533: |   29 00 00 1c  00 00 40 04  72 3c 32 21  90 45 
d7 88
Aug 16 18:05:30.075538: |   fc 54 3a da  73 30 20 93  1f b3 b4 5c  00 00 
00 1c
Aug 16 18:05:30.075543: |   00 00 40 05  65 62 64 7e  79 3c e9 29  00 48 
1a 91
Aug 16 18:05:30.075547: |   3d 0a 60 15  69 5a f0 73
Aug 16 18:05:30.075597: | processing: stop state #138 connection 
"router-2.reub.net-ipv4"[1] 1.144.95.124 1.144.95.124:585 (in 
ikev2_process_packet() at ikev2.c:1414)
Aug 16 18:05:30.075606: | serialno table: hash serialno #0 to head 
0x5598d5c3ec00
Aug 16 18:05:30.075612: | serialno table: hash serialno #0 to head 
0x5598d5c3ec00
Aug 16 18:05:30.075619: | processing: stop from 1.144.95.124:585 (in 
process_md() at demux.c:394)
Aug 16 18:05:30.075626: | processing: STOP state #0 (in process_md() at 
demux.c:396)
Aug 16 18:05:30.075632: | serialno table: hash serialno #0 to head 
0x5598d5c3ec00
Aug 16 18:05:30.075637: | serialno table: hash serialno #0 to head 
0x5598d5c3ec00
Aug 16 18:05:30.075643: | processing: STOP connection NULL (in 
process_md() at demux.c:397)
Aug 16 18:05:31.955126: |  kernel_process_msg_cb process netlink message
Aug 16 18:05:31.955178: | netlink_get: XFRM_MSG_DELPOLICY message
Aug 16 18:05:31.955186: | xfrm netlink address change RTM_NEWADDR msg len 72
Aug 16 18:05:32.238964: |  kernel_process_msg_cb process netlink message
Aug 16 18:05:32.239015: | netlink_get: XFRM_MSG_DELPOLICY message
Aug 16 18:05:32.239023: | xfrm netlink address change RTM_NEWADDR msg len 72
Aug 16 18:05:35.066288: |  kernel_process_msg_cb process netlink message
Aug 16 18:05:35.066342: | netlink_get: XFRM_MSG_DELPOLICY message
Aug 16 18:05:35.066351: | xfrm netlink address change RTM_NEWADDR msg len 72
Aug 16 18:05:35.405121: |  kernel_process_msg_cb process netlink message
Aug 16 18:05:35.405278: | netlink_get: XFRM_MSG_DELPOLICY message
Aug 16 18:05:35.405580: | xfrm netlink address change RTM_NEWADDR msg len 72
Aug 16 18:05:35.475764: | timer_event_cb: processing event at 0x7f402c005be0
Aug 16 18:05:35.475820: | handling event EVENT_v2_RESPONDER_TIMEOUT for 
parent state #137
Aug 16 18:05:35.475836: | processing: start state #137 connection 
"router-2.reub.net-ipv4"[1] 1.144.95.124 1.144.95.124:585 (in 
timer_event_cb() at timer.c:318)
Aug 16 18:05:35.475843: | EVENT_SA_EXPIRE picked newest_isakmp_sa
Aug 16 18:05:35.475849: | un-established partial ISAKMP SA timeout 
(Responder timeout)
Aug 16 18:05:35.475861: | cookies table: hash icookie 1c 85 00 c6  57 4b 
9c 92 rcookie fc 8f 44 c7  99 5f 20 03 to 2230292375010317950 slot 
0x5598d5c396e0
Aug 16 18:05:35.475870: | processing: [RE]START state #137 connection 
"router-2.reub.net-ipv4"[1] 1.144.95.124 1.144.95.124:585 (in 
delete_state() at state.c:973)
Aug 16 18:05:35.475895: | serialno table: hash serialno #137 to head 
0x5598d5c3fd20
Aug 16 18:05:35.475901: | serialno table: hash serialno #137 to head 
0x5598d5c3fd20
Aug 16 18:05:35.475909: "router-2.reub.net-ipv4"[1] 1.144.95.124 #137: 
deleting state (STATE_PARENT_R1) and NOT sending notification
Aug 16 18:05:35.475916: | parent state #137: 
STATE_PARENT_R1(half-open-ike) => delete
Aug 16 18:05:35.475922: | state #137 requesting N/A-pe@(nil) be deleted
Aug 16 18:05:35.475927: | delete_pluto_event cannot delete NULL event
Aug 16 18:05:35.475933: | state #137 requesting N/A-pe@(nil) be deleted
Aug 16 18:05:35.475937: | delete_pluto_event cannot delete NULL event
Aug 16 18:05:35.475942: | state #137 requesting N/A-pe@(nil) be deleted
Aug 16 18:05:35.475947: | delete_pluto_event cannot delete NULL event
Aug 16 18:05:35.475952: | state #137 requesting N/A-pe@(nil) be deleted
Aug 16 18:05:35.475957: | delete_pluto_event cannot delete NULL event
Aug 16 18:05:35.475962: | state #137 requesting to delete non existing event
Aug 16 18:05:35.475969: | serialno list: removing  object 0x5598d74f01b0 
(state #137) entry 0x5598d74f0948 (older 0x5598d5c493e0 newer 
0x5598d74f2c78)
Aug 16 18:05:35.475976: | serialno list: updated older entry 
0x5598d5c493e0 is HEAD (older 0x5598d74f2c78 newer 0x5598d74f2c78)
Aug 16 18:05:35.475982: | serialno list: updated newer   object 
0x5598d74f24e0 (state #138) entry 0x5598d74f2c78 (older 0x5598d5c493e0 
newer 0x5598d5c493e0)
Aug 16 18:05:35.475988: | serialno table: removing  object 
0x5598d74f01b0 (state #137) entry 0x5598d74f0968 (older 0x5598d5c3fd20 
newer 0x5598d5c3fd20)
Aug 16 18:05:35.475993: | serialno table: empty
Aug 16 18:05:35.475999: | in connection_discard for connection 
router-2.reub.net-ipv4
Aug 16 18:05:35.476004: | connection is instance
Aug 16 18:05:35.476009: | not in pending use
Aug 16 18:05:35.476015: | parent state #137: 
STATE_PARENT_R1(half-open-ike) => STATE_UNDEFINED(ignore)
Aug 16 18:05:35.476021: | ignore states: 0
Aug 16 18:05:35.476025: | half-open-ike states: 1
Aug 16 18:05:35.476030: | open-ike states: 0
Aug 16 18:05:35.476035: | established-anonymous-ike states: 0
Aug 16 18:05:35.476040: | established-authenticated-ike states: 0
Aug 16 18:05:35.476045: | anonymous-ipsec states: 0
Aug 16 18:05:35.476050: | authenticated-ipsec states: 0
Aug 16 18:05:35.476055: | informational states: 0
Aug 16 18:05:35.476059: | unknown states: 0
Aug 16 18:05:35.476064: | category states: 1 count states: 1
Aug 16 18:05:35.476102: | processing: stop state #137 1.144.95.124:585 
(in delete_state() at state.c:1191)
Aug 16 18:05:35.476110: | serialno table: hash serialno #137 to head 
0x5598d5c3fd20
Aug 16 18:05:35.476115: | serialno table: hash serialno #137 to head 
0x5598d5c3fd20
Aug 16 18:05:35.476126: | free_event_entry: release 
EVENT_v2_RESPONDER_TIMEOUT-pe at 0x7f402c005be0
Aug 16 18:05:35.476132: | processing: STOP state #0 (in timer_event_cb() 
at timer.c:659)
Aug 16 18:05:35.476138: | serialno table: hash serialno #0 to head 
0x5598d5c3ec00
Aug 16 18:05:35.476143: | serialno table: hash serialno #0 to head 
0x5598d5c3ec00
Aug 16 18:05:38.178956: | timer_event_cb: processing event at 0x7f402c0050a0
Aug 16 18:05:38.179005: | handling event EVENT_PENDING_PHASE2
Aug 16 18:05:38.179015: | event_schedule: new 
EVENT_PENDING_PHASE2-pe at 0x7f402c005be0
Aug 16 18:05:38.179024: | inserting event EVENT_PENDING_PHASE2, timeout 
in 120.000 seconds
Aug 16 18:05:38.179039: | pending review: connection 
"router-2.reub.net-ipv4"[1] 1.144.95.124 was not up, skipped
Aug 16 18:05:38.179045: | pending review: connection 
"router-2.reub.net-ipv4" was not up, skipped
Aug 16 18:05:38.179054: | free_event_entry: release 
EVENT_PENDING_PHASE2-pe at 0x7f402c0050a0
Aug 16 18:05:38.219202: | timer_event_cb: processing event at 0x7f4034005aa0
Aug 16 18:05:38.219251: | handling event EVENT_PENDING_DDNS
Aug 16 18:05:38.219261: | event_schedule: new 
EVENT_PENDING_DDNS-pe at 0x7f402c0050a0
Aug 16 18:05:38.219270: | inserting event EVENT_PENDING_DDNS, timeout in 
60.000 seconds
Aug 16 18:05:38.219298: | elapsed time in connection_check_ddns for 
hostname lookup 0.000000
Aug 16 18:05:38.219307: | free_event_entry: release 
EVENT_PENDING_DDNS-pe at 0x7f4034005aa0
Aug 16 18:05:38.793615: |  kernel_process_msg_cb process netlink message
Aug 16 18:05:38.793664: | netlink_get: XFRM_MSG_DELPOLICY message
Aug 16 18:05:38.793673: | xfrm netlink address change RTM_NEWADDR msg len 72
Aug 16 18:05:38.920201: |  kernel_process_msg_cb process netlink message
Aug 16 18:05:38.920251: | netlink_get: XFRM_MSG_DELPOLICY message
Aug 16 18:05:38.920260: | xfrm netlink address change RTM_NEWADDR msg len 72
Aug 16 18:05:39.280749: | timer_event_cb: processing event at 0x7f40340046d0
Aug 16 18:05:39.280797: | handling event EVENT_SHUNT_SCAN
Aug 16 18:05:39.280805: | expiring aged bare shunts from shunt table
Aug 16 18:05:39.280813: | event_schedule: new 
EVENT_SHUNT_SCAN-pe at 0x7f4034005aa0
Aug 16 18:05:39.280823: | inserting event EVENT_SHUNT_SCAN, timeout in 
20.000 seconds
Aug 16 18:05:39.280834: | free_event_entry: release 
EVENT_SHUNT_SCAN-pe at 0x7f40340046d0
Aug 16 18:05:42.034443: |  kernel_process_msg_cb process netlink message
Aug 16 18:05:42.034499: | netlink_get: XFRM_MSG_DELPOLICY message
Aug 16 18:05:42.034507: | xfrm netlink address change RTM_NEWADDR msg len 72
Aug 16 18:05:42.681384: |  kernel_process_msg_cb process netlink message
Aug 16 18:05:42.681434: | netlink_get: XFRM_MSG_DELPOLICY message
Aug 16 18:05:42.681443: | xfrm netlink address change RTM_NEWADDR msg len 72
Aug 16 18:05:44.623573: |  kernel_process_msg_cb process netlink message
Aug 16 18:05:44.623626: | netlink_get: XFRM_MSG_DELPOLICY message
Aug 16 18:05:44.623639: | xfrm netlink address change RTM_NEWADDR msg len 72
Aug 16 18:05:44.623653: | netlink_get: XFRM_MSG_DELPOLICY message
Aug 16 18:05:44.623663: | xfrm netlink address change RTM_NEWADDR msg len 72
Aug 16 18:05:44.633371: |  kernel_process_msg_cb process netlink message
Aug 16 18:05:44.633427: | netlink_get: XFRM_MSG_DELPOLICY message
Aug 16 18:05:44.633441: | xfrm netlink address change RTM_NEWADDR msg len 72
Aug 16 18:05:44.633456: | netlink_get: XFRM_MSG_DELPOLICY message
Aug 16 18:05:44.633466: | xfrm netlink address change RTM_NEWADDR msg len 72
Aug 16 18:05:44.683063: |  kernel_process_msg_cb process netlink message
Aug 16 18:05:44.683119: | netlink_get: XFRM_MSG_DELPOLICY message
Aug 16 18:05:44.683134: | xfrm netlink address change RTM_NEWADDR msg len 72
Aug 16 18:05:44.684253: |  kernel_process_msg_cb process netlink message
Aug 16 18:05:44.684283: | netlink_get: XFRM_MSG_DELPOLICY message
Aug 16 18:05:44.684296: | xfrm netlink address change RTM_NEWADDR msg len 72
Aug 16 18:05:44.685917: |  kernel_process_msg_cb process netlink message


Cisco debugs:

Aug 16 18:05:03 lo0.router-2.reub.net router-2: Aug 16 18:05:02: 
IKEv2:(SESSION ID = 1,SA ID = 1):Sending Packet [To 
110.232.112.209:500/From 10.102.66.94:500/VRF i0:f0]
Aug 16 18:05:03 lo0.router-2.reub.net router-2: Initiator SPI : 
FEE6D765CA54753B - Responder SPI : 0000000000000000 Message id: 0
Aug 16 18:05:03 lo0.router-2.reub.net router-2: IKEv2 IKE_SA_INIT 
Exchange REQUEST
Aug 16 18:05:03 lo0.router-2.reub.net router-2: Payload contents:
Aug 16 18:05:03 lo0.router-2.reub.net router-2:  SA KE N VID VID VID VID 
NOTIFY(NAT_DETECTION_SOURCE_IP) NOTIFY(NAT_DETECTION_DESTINATION_IP)
Aug 16 18:05:03 lo0.router-2.reub.net router-2: Aug 16 18:05:03: 
IPSEC:(SESSION ID = 1) (key_engine) request timer fired: count = 1,
Aug 16 18:05:03 lo0.router-2.reub.net router-2:   (identity) local= 
10.102.66.94:0, remote= 110.232.112.209:0,
Aug 16 18:05:03 lo0.router-2.reub.net router-2:     local_proxy= 
0.0.0.0/0.0.0.0/256/0,
Aug 16 18:05:03 lo0.router-2.reub.net router-2:     remote_proxy= 
0.0.0.0/0.0.0.0/256/0
Aug 16 18:05:03 lo0.router-2.reub.net router-2: Aug 16 18:05:03: 
IPSEC(sa_request): ,
Aug 16 18:05:03 lo0.router-2.reub.net router-2:   (key eng. msg.) 
OUTBOUND local= 10.102.66.94:500, remote= 110.232.112.209:500,
Aug 16 18:05:03 lo0.router-2.reub.net router-2:     local_proxy= 
0.0.0.0/0.0.0.0/256/0,
Aug 16 18:05:03 lo0.router-2.reub.net router-2:     remote_proxy= 
0.0.0.0/0.0.0.0/256/0,
Aug 16 18:05:03 lo0.router-2.reub.net router-2:     protocol= ESP, 
transform= esp-aes esp-sha-hmac  (Tunnel),
Aug 16 18:05:03 lo0.router-2.reub.net router-2:     lifedur= 3600s and 
4608000kb,
Aug 16 18:05:03 lo0.router-2.reub.net router-2:     spi= 0x0(0), 
conn_id= 0, keysize= 128, flags= 0x0
Aug 16 18:05:03 lo0.router-2.reub.net router-2: Aug 16 18:05:03: IKEv2:% 
Getting preshared key from profile keyring reub-keyring
Aug 16 18:05:03 lo0.router-2.reub.net router-2: Aug 16 18:05:03: IKEv2:% 
Matched peer block 'lightning.reub.net-ipv4'
Aug 16 18:05:03 lo0.router-2.reub.net router-2: Aug 16 18:05:03: 
IKEv2:Searching Policy with fvrf 0, local address 10.102.66.94
Aug 16 18:05:03 lo0.router-2.reub.net router-2: Aug 16 18:05:03: 
IKEv2:Using the Default Policy for Proposal
Aug 16 18:05:03 lo0.router-2.reub.net router-2: Aug 16 18:05:03: IKEv2:
Aug 16 18:05:04 lo0.router-2.reub.net router-2: Found Policy 'default'
Aug 16 18:05:04 lo0.router-2.reub.net router-2: Aug 16 18:05:03: 
IKEv2:SA is already in negotiation, hence not negotiating again
Aug 16 18:05:32 lo0.router-2.reub.net router-2: Aug 16 18:05:31: 
IKEv2:(SESSION ID = 1,SA ID = 1):Retransmitting packet
Aug 16 18:05:32 lo0.router-2.reub.net router-2: Aug 16 18:05:31: 
IKEv2:(SESSION ID = 1,SA ID = 1):Sending Packet [To 
110.232.112.209:500/From 10.102.66.94:500/VRF i0:f0]
Aug 16 18:05:32 lo0.router-2.reub.net router-2: Initiator SPI : 
FEE6D765CA54753B - Responder SPI : 0000000000000000 Message id: 0
Aug 16 18:05:32 lo0.router-2.reub.net router-2: IKEv2 IKE_SA_INIT 
Exchange REQUEST
Aug 16 18:05:32 lo0.router-2.reub.net router-2: Payload contents:
Aug 16 18:05:32 lo0.router-2.reub.net router-2:  SA KE N VID VID VID VID 
NOTIFY(NAT_DETECTION_SOURCE_IP) NOTIFY(NAT_DETECTION_DESTINATION_IP)
Aug 16 18:05:33 lo0.router-2.reub.net router-2: Aug 16 18:05:33: 
IPSEC:(SESSION ID = 1) (key_engine) request timer fired: count = 2,
Aug 16 18:05:33 lo0.router-2.reub.net router-2:   (identity) local= 
10.102.66.94:0, remote= 110.232.112.209:0,
Aug 16 18:05:33 lo0.router-2.reub.net router-2:     local_proxy= 
0.0.0.0/0.0.0.0/256/0,
Aug 16 18:05:33 lo0.router-2.reub.net router-2:     remote_proxy= 
0.0.0.0/0.0.0.0/256/0
Aug 16 18:05:33 lo0.router-2.reub.net router-2: Aug 16 18:05:33: 
IPSEC(sa_request): ,
Aug 16 18:05:33 lo0.router-2.reub.net router-2:   (key eng. msg.) 
OUTBOUND local= 10.102.66.94:500, remote= 110.232.112.209:500,
Aug 16 18:05:33 lo0.router-2.reub.net router-2:     local_proxy= 
0.0.0.0/0.0.0.0/256/0,
Aug 16 18:05:33 lo0.router-2.reub.net router-2:     remote_proxy= 
0.0.0.0/0.0.0.0/256/0,
Aug 16 18:05:33 lo0.router-2.reub.net router-2:     protocol= ESP, 
transform= esp-aes esp-sha-hmac  (Tunnel),
Aug 16 18:05:33 lo0.router-2.reub.net router-2:     lifedur= 3600s and 
4608000kb,
Aug 16 18:05:33 lo0.router-2.reub.net router-2:     spi= 0x0(0), 
conn_id= 0, keysize= 128, flags= 0x0
Aug 16 18:05:33 lo0.router-2.reub.net router-2: Aug 16 18:05:33: IKEv2:% 
Getting preshared key from profile keyring reub-keyring
Aug 16 18:05:34 lo0.router-2.reub.net router-2: Aug 16 18:05:33: IKEv2:% 
Matched peer block 'lightning.reub.net-ipv4'
Aug 16 18:05:34 lo0.router-2.reub.net router-2: Aug 16 18:05:33: 
IKEv2:Searching Policy with fvrf 0, local address 10.102.66.94
Aug 16 18:05:34 lo0.router-2.reub.net router-2: Aug 16 18:05:33: 
IKEv2:Using the Default Policy for Proposal
Aug 16 18:05:34 lo0.router-2.reub.net router-2: Aug 16 18:05:33: 
IKEv2:Found Policy 'default'
Aug 16 18:05:34 lo0.router-2.reub.net router-2: Aug 16 18:05:33: 
IKEv2:SA is already in negotiation, hence not negotiating again
Aug 16 18:06:03 lo0.router-2.reub.net router-2: Aug 16 18:06:03: 
IPSEC:(SESSION ID = 1) (key_engine) request timer fired: count = 3,
Aug 16 18:06:03 lo0.router-2.reub.net router-2:   (identity) local= 
10.102.66.94:0, remote= 110.232.112.209:0,
Aug 16 18:06:03 lo0.router-2.reub.net router-2:     local_proxy= 
0.0.0.0/0.0.0.0/256/0,
Aug 16 18:06:03 lo0.router-2.reub.net router-2:     remote_proxy= 
0.0.0.0/0.0.0.0/256/0
Aug 16 18:06:03 lo0.router-2.reub.net router-2: Aug 16 18:06:03: 
IPSEC(sa_request): ,
Aug 16 18:06:03 lo0.router-2.reub.net router-2:   (key eng. msg.) 
OUTBOUND local= 10.102.66.94:500, remote= 110.232.112.209:500,
Aug 16 18:06:03 lo0.router-2.reub.net router-2:     local_proxy= 
0.0.0.0/0.0.0.0/256/0,
Aug 16 18:06:03 lo0.router-2.reub.net router-2:     remote_proxy= 
0.0.0.0/0.0.0.0/256/0,
Aug 16 18:06:03 lo0.router-2.reub.net router-2:     protocol= ESP, 
transform= esp-aes esp-sha-hmac  (Tunnel),
Aug 16 18:06:03 lo0.router-2.reub.net router-2:     lifedur= 3600s and 
4608000kb,
Aug 16 18:06:03 lo0.router-2.reub.net router-2:     spi= 0x0(0), 
conn_id= 0, keysize= 128, flags= 0x0
Aug 16 18:06:03 lo0.router-2.reub.net router-2: Aug 16 18:06:03: IKEv2:% 
Getting preshared key from profile keyring reub-keyring
Aug 16 18:06:04 lo0.router-2.reub.net router-2: Aug 16 18:06:03: IKEv2:% 
Matched peer block 'lightning.reub.net-ipv4'
Aug 16 18:06:04 lo0.router-2.reub.net router-2: Aug 16 18:06:03: 
IKEv2:Searching Policy with fvrf 0, local address 10.102.66.94
Aug 16 18:06:04 lo0.router-2.reub.net router-2: Aug 16 18:06:03: 
IKEv2:Using the Default Policy for Proposal
Aug 16 18:06:04 lo0.router-2.reub.net router-2: Aug 16 18:06:03: 
IKEv2:Found Policy 'default'
Aug 16 18:06:04 lo0.router-2.reub.net router-2: Aug 16 18:06:03: 
IKEv2:SA is already in negotiation, hence not negotiating again
Aug 16 18:06:33 lo0.router-2.reub.net router-2: Aug 16 18:06:32: 
IKEv2:(SESSION ID = 1,SA ID = 1):Retransmitting packet
Aug 16 18:06:33 lo0.router-2.reub.net router-2: Aug 16 18:06:32: 
IKEv2:(SESSION ID = 1,SA ID = 1):Sending Packet [To 
110.232.112.209:500/From 10.102.66.94:500/VRF i0:f0]
Aug 16 18:06:33 lo0.router-2.reub.net router-2: Initiator SPI : 
FEE6D765CA54753B - Responder SPI : 0000000000000000 Message id: 0
Aug 16 18:06:33 lo0.router-2.reub.net router-2: IKEv2 IKE_SA_INIT 
Exchange REQUEST
Aug 16 18:06:33 lo0.router-2.reub.net router-2: Payload contents:
Aug 16 18:06:33 lo0.router-2.reub.net router-2:  SA KE N VID VID VID VID 
NOTIFY(NAT_DETECTION_SOURCE_IP) NOTIFY(NAT_DETECTION_DESTINATION_IP)
Aug 16 18:06:33 lo0.router-2.reub.net router-2: Aug 16 18:06:33: 
IPSEC:(SESSION ID = 1) (key_engine) request timer fired: count = 4,
Aug 16 18:06:33 lo0.router-2.reub.net router-2:   (identity) local= 
10.102.66.94:0, remote= 110.232.112.209:0,
Aug 16 18:06:33 lo0.router-2.reub.net router-2:     local_proxy= 
0.0.0.0/0.0.0.0/256/0,
Aug 16 18:06:33 lo0.router-2.reub.net router-2:     remote_proxy= 
0.0.0.0/0.0.0.0/256/0
Aug 16 18:06:33 lo0.router-2.reub.net router-2: Aug 16 18:06:33: 
IPSEC(sa_request): ,
Aug 16 18:06:33 lo0.router-2.reub.net router-2:   (key eng. msg.) 
OUTBOUND local= 10.102.66.94:500, remote= 110.232.112.209:500,
Aug 16 18:06:33 lo0.router-2.reub.net router-2:     local_proxy= 
0.0.0.0/0.0.0.0/256/0,
Aug 16 18:06:33 lo0.router-2.reub.net router-2:     remote_proxy= 
0.0.0.0/0.0.0.0/256/0,
Aug 16 18:06:33 lo0.router-2.reub.net router-2:     protocol= ESP, 
transform= esp-aes esp-sha-hmac  (Tunnel),
Aug 16 18:06:33 lo0.router-2.reub.net router-2:     lifedur= 3600s and 
4608000kb,
Aug 16 18:06:33 lo0.router-2.reub.net router-2:     spi= 0x0(0), 
conn_id= 0, keysize= 128, flags= 0x0
Aug 16 18:06:33 lo0.router-2.reub.net router-2: Aug 16 18:06:33: IKEv2:% 
Getting preshared key from profile keyring reub-keyring
Aug 16 18:06:33 lo0.router-2.reub.net router-2: Aug 16 18:06:33: IKEv2:% 
Matched peer block 'lightning.reub.net-ipv4'
Aug 16 18:06:33 lo0.router-2.reub.net router-2: Aug 16 18:06:33: 
IKEv2:Searching Policy with fvrf 0, local address 10.102.66.94
Aug 16 18:06:33 lo0.router-2.reub.net router-2: Aug 16 18:06:33: 
IKEv2:Using the Default Policy for Proposal
Aug 16 18:06:33 lo0.router-2.reub.net router-2: Aug 16 18:06:33: IKEv2:
Aug 16 18:06:34 lo0.router-2.reub.net router-2: Found Policy 'default'
Aug 16 18:06:34 lo0.router-2.reub.net router-2: Aug 16 18:06:33: 
IKEv2:SA is already in negotiation, hence not negotiating again
Aug 16 18:06:38 lo0.router-2.reub.net router-2: Aug 16 18:06:37: 
IKEv2-ERROR:(SESSION ID = 1,SA ID = 1):: Maximum number of 
retransmissions reached
Aug 16 18:06:38 lo0.router-2.reub.net router-2: Aug 16 18:06:37: 
IKEv2:(SESSION ID = 1,SA ID = 1):Failed SA init exchange
Aug 16 18:06:38 lo0.router-2.reub.net router-2: Aug 16 18:06:37: 
IKEv2-ERROR:(SESSION ID = 1,SA ID = 1):Initial exchange failed: Initial 
exchange failed
Aug 16 18:06:38 lo0.router-2.reub.net router-2: Aug 16 18:06:37: 
IKEv2:(SESSION ID = 1,SA ID = 1):Abort exchange
Aug 16 18:06:38 lo0.router-2.reub.net router-2: Aug 16 18:06:37: 
IKEv2:(SESSION ID = 1,SA ID = 1):Deleting SA
Aug 16 18:07:04 lo0.router-2.reub.net router-2: Aug 16 18:07:03: 
IPSEC:(SESSION ID = 1) (key_engine) request timer fired: count = 5,
Aug 16 18:07:04 lo0.router-2.reub.net router-2:   (identity) local= 
10.102.66.94:0, remote= 110.232.112.209:0,
Aug 16 18:07:04 lo0.router-2.reub.net router-2:     local_proxy= 
0.0.0.0/0.0.0.0/256/0,
Aug 16 18:07:04 lo0.router-2.reub.net router-2:     remote_proxy= 
0.0.0.0/0.0.0.0/256/0
Aug 16 18:07:34 lo0.router-2.reub.net router-2: Aug 16 18:07:34: 
IPSEC(sa_request): ,
Aug 16 18:07:34 lo0.router-2.reub.net router-2:   (key eng. msg.) 
OUTBOUND local= 10.102.66.94:500, remote= 110.232.112.209:500,
Aug 16 18:07:34 lo0.router-2.reub.net router-2:     local_proxy= 
0.0.0.0/0.0.0.0/256/0,
Aug 16 18:07:34 lo0.router-2.reub.net router-2:     remote_proxy= 
0.0.0.0/0.0.0.0/256/0,
Aug 16 18:07:34 lo0.router-2.reub.net router-2:     protocol= ESP, 
transform= esp-aes esp-sha-hmac  (Tunnel),
Aug 16 18:07:34 lo0.router-2.reub.net router-2:     lifedur= 3600s and 
4608000kb,
Aug 16 18:07:34 lo0.router-2.reub.net router-2:     spi= 0x0(0), 
conn_id= 0, keysize= 128, flags= 0x0
Aug 16 18:07:34 lo0.router-2.reub.net router-2: Aug 16 18:07:34: IKEv2:% 
Getting preshared key from profile keyring reub-keyring
Aug 16 18:07:34 lo0.router-2.reub.net router-2: Aug 16 18:07:34: IKEv2:% 
Matched peer block 'lightning.reub.net-ipv4'
Aug 16 18:07:34 lo0.router-2.reub.net router-2: Aug 16 18:07:34: 
IKEv2:Searching Policy with fvrf 0, local address 10.102.66.94
Aug 16 18:07:34 lo0.router-2.reub.net router-2: Aug 16 18:07:34: 
IKEv2:Using the Default Policy for Proposal
Aug 16 18:07:34 lo0.router-2.reub.net router-2: Aug 16 18:07:34: IKEv2:
Aug 16 18:07:34 lo0.router-2.reub.net router-2: Found Policy 'default'
Aug 16 18:07:34 lo0.router-2.reub.net router-2: Aug 16 18:07:34: 
IKEv2:(SESSION ID = 1,SA ID = 1):[IKEv2 -> Crypto Engine] Computing DH 
public key, DH Group 19
Aug 16 18:07:34 lo0.router-2.reub.net router-2: Aug 16 18:07:34: 
IKEv2:(SA ID = 1):[Crypto Engine -> IKEv2] DH key Computation PASSED
Aug 16 18:07:34 lo0.router-2.reub.net router-2: Aug 16 18:07:34: 
IKEv2:(SESSION ID = 1,SA ID = 1):Request queued for computation of DH key
Aug 16 18:07:34 lo0.router-2.reub.net router-2: Aug 16 18:07:34: 
IKEv2:IKEv2 initiator - no config data to send in IKE_SA_INIT exch
Aug 16 18:07:34 lo0.router-2.reub.net router-2: Aug 16 18:07:34: 
IKEv2:(SESSION ID = 1,SA ID = 1):Generating IKE_SA_INIT message
Aug 16 18:07:34 lo0.router-2.reub.net router-2: Aug 16 18:07:34: 
IKEv2:(SESSION ID = 1,SA ID = 1):IKE Proposal: 1, SPI size: 0 (initial 
negotiation),
Aug 16 18:07:34 lo0.router-2.reub.net router-2: Num. transforms: 9
Aug 16 18:07:34 lo0.router-2.reub.net router-2:    AES-CBC   SHA512 
SHA384   SHA512   SHA384   DH_GROUP_256_ECP/Group 19
Aug 16 18:07:35 lo0.router-2.reub.net router-2: 
DH_GROUP_2048_MODP/Group 14   DH_GROUP_521_ECP/Group 21 
DH_GROUP_1536_MODP/Group 5
Aug 16 18:07:35 lo0.router-2.reub.net router-2: Aug 16 18:07:34: 
IKEv2:(SESSION ID = 1,SA ID = 1):Sending Packet [To 
110.232.112.209:500/From 10.102.66.94:500/VRF i0:f0]
Aug 16 18:07:35 lo0.router-2.reub.net router-2: Initiator SPI : 
B8335E814D8F6500 - Responder SPI : 0000000000000000 Message id: 0
Aug 16 18:07:35 lo0.router-2.reub.net router-2: IKEv2 IKE_SA_INIT 
Exchange REQUEST
Aug 16 18:07:35 lo0.router-2.reub.net router-2: Payload contents:
Aug 16 18:07:35 lo0.router-2.reub.net router-2:  SA KE N VID VID VID VID 
NOTIFY(NAT_DETECTION_SOURCE_IP) NOTIFY(NAT_DETECTION_DESTINATION_IP)
Aug 16 18:07:35 lo0.router-2.reub.net router-2: Aug 16 18:07:34: 
IKEv2:(SESSION ID = 1,SA ID = 1):Insert SA
Aug 16 18:07:37 lo0.router-2.reub.net router-2: Aug 16 18:07:36: 
IKEv2:(SESSION ID = 1,SA ID = 1):Retransmitting packet
Aug 16 18:07:37 lo0.router-2.reub.net router-2: Aug 16 18:07:36: 
IKEv2:(SESSION ID = 1,SA ID = 1):Sending Packet [To 
110.232.112.209:500/From 10.102.66.94:500/VRF i0:f0]
Aug 16 18:07:37 lo0.router-2.reub.net router-2: Initiator SPI : 
B8335E814D8F6500 - Responder SPI : 0000000000000000 Message id: 0
Aug 16 18:07:37 lo0.router-2.reub.net router-2: IKEv2 IKE_SA_INIT 
Exchange REQUEST
Aug 16 18:07:37 lo0.router-2.reub.net router-2: Payload contents:
Aug 16 18:07:37 lo0.router-2.reub.net router-2:  SA KE N VID VID VID VID 
NOTIFY(NAT_DETECTION_SOURCE_IP) NOTIFY(NAT_DETECTION_DESTINATION_IP)
Aug 16 18:07:41 lo0.router-2.reub.net router-2: Aug 16 18:07:40: 
IKEv2:(SESSION ID = 1,SA ID = 1):Retransmitting packet
Aug 16 18:07:41 lo0.router-2.reub.net router-2: Aug 16 18:07:40: 
IKEv2:(SESSION ID = 1,SA ID = 1):Sending Packet [To 
110.232.112.209:500/From 10.102.66.94:500/VRF i0:f0]
Aug 16 18:07:41 lo0.router-2.reub.net router-2: Initiator SPI : 
B8335E814D8F6500 - Responder SPI : 0000000000000000 Message id: 0
Aug 16 18:07:41 lo0.router-2.reub.net router-2: IKEv2 IKE_SA_INIT 
Exchange REQUEST
Aug 16 18:07:41 lo0.router-2.reub.net router-2: Payload contents:
Aug 16 18:07:41 lo0.router-2.reub.net router-2:  SA KE N VID VID VID VID 
NOTIFY(NAT_DETECTION_SOURCE_IP) NOTIFY(NAT_DETECTION_DESTINATION_IP)
Aug 16 18:07:48 lo0.router-2.reub.net router-2: Aug 16 18:07:47: 
IKEv2:(SESSION ID = 1,SA ID = 1):Retransmitting packet
Aug 16 18:07:48 lo0.router-2.reub.net router-2: Aug 16 18:07:47: 
IKEv2:(SESSION ID = 1,SA ID = 1):Sending Packet [To 
110.232.112.209:500/From 10.102.66.94:500/VRF i0:f0]
Aug 16 18:07:48 lo0.router-2.reub.net router-2: Initiator SPI : 
B8335E814D8F6500 - Responder SPI : 0000000000000000 Message id: 0
Aug 16 18:07:48 lo0.router-2.reub.net router-2: IKEv2 IKE_SA_INIT 
Exchange REQUEST
Aug 16 18:07:48 lo0.router-2.reub.net router-2: Payload contents:
Aug 16 18:07:48 lo0.router-2.reub.net router-2:  SA KE N VID VID VID VID 
NOTIFY(NAT_DETECTION_SOURCE_IP) NOTIFY(NAT_DETECTION_DESTINATION_IP)
Aug 16 18:08:04 lo0.router-2.reub.net router-2: Aug 16 18:08:02: 
IKEv2:(SESSION ID = 1,SA ID = 1):Retransmitting packet
Aug 16 18:08:04 lo0.router-2.reub.net router-2: Aug 16 18:08:02: 
IKEv2:(SESSION ID = 1,SA ID = 1):Sending Packet [To 
110.232.112.209:500/From 10.102.66.94:500/VRF i0:f0]
Aug 16 18:08:04 lo0.router-2.reub.net router-2: Initiator SPI : 
B8335E814D8F6500 - Responder SPI : 0000000000000000 Message id: 0
Aug 16 18:08:04 lo0.router-2.reub.net router-2: IKEv2 IKE_SA_INIT 
Exchange REQUEST
Aug 16 18:08:04 lo0.router-2.reub.net router-2: Payload contents:
Aug 16 18:08:04 lo0.router-2.reub.net router-2:  SA KE N VID VID VID VID 
NOTIFY(NAT_DETECTION_SOURCE_IP) NOTIFY(NAT_DETECTION_DESTINATION_IP)
Aug 16 18:08:04 lo0.router-2.reub.net router-2: Aug 16 18:08:04: 
IPSEC:(SESSION ID = 1) (key_engine) request timer fired: count = 1,
Aug 16 18:08:04 lo0.router-2.reub.net router-2:   (identity) local= 
10.102.66.94:0, remote= 110.232.112.209:0,
Aug 16 18:08:04 lo0.router-2.reub.net router-2:     local_proxy= 
0.0.0.0/0.0.0.0/256/0,
Aug 16 18:08:04 lo0.router-2.reub.net router-2:     remote_proxy= 
0.0.0.0/0.0.0.0/256/0
Aug 16 18:08:04 lo0.router-2.reub.net router-2: Aug 16 18:08:04: 
IPSEC(sa_request): ,
Aug 16 18:08:04 lo0.router-2.reub.net router-2:   (key eng. msg.) 
OUTBOUND local= 10.102.66.94:500, remote= 110.232.112.209:500,
Aug 16 18:08:04 lo0.router-2.reub.net router-2:     local_proxy= 
0.0.0.0/0.0.0.0/256/0,
Aug 16 18:08:04 lo0.router-2.reub.net router-2:     remote_proxy= 
0.0.0.0/0.0.0.0/256/0,
Aug 16 18:08:04 lo0.router-2.reub.net router-2:     protocol= ESP, 
transform= esp-aes esp-sha-hmac  (Tunnel),
Aug 16 18:08:04 lo0.router-2.reub.net router-2:     lifedur= 3600s and 
4608000kb,
Aug 16 18:08:04 lo0.router-2.reub.net router-2:     spi= 0x0(0), 
conn_id= 0, keysize= 128, flags= 0x0
Aug 16 18:08:04 lo0.router-2.reub.net router-2: Aug 16 18:08:04: IKEv2:% 
Getting preshared key from profile keyring reub-keyring
Aug 16 18:08:05 lo0.router-2.reub.net router-2: Aug 16 18:08:04: IKEv2:% 
Matched peer block 'lightning.reub.net-ipv4'
Aug 16 18:08:05 lo0.router-2.reub.net router-2: Aug 16 18:08:04: 
IKEv2:Searching Policy with fvrf 0, local address 10.102.66.94
Aug 16 18:08:05 lo0.router-2.reub.net router-2: Aug 16 18:08:04: 
IKEv2:Using the Default Policy for Proposal
Aug 16 18:08:05 lo0.router-2.reub.net router-2: Aug 16 18:08:04: 
IKEv2:Found Policy 'default'
Aug 16 18:08:05 lo0.router-2.reub.net router-2: Aug 16 18:08:04: 
IKEv2:SA is already in negotiation, hence not negotiating again
Aug 16 18:08:34 lo0.router-2.reub.net router-2: Aug 16 18:08:33: 
IKEv2:(SESSION ID = 1,SA ID = 1):Retransmitting packet
Aug 16 18:08:34 lo0.router-2.reub.net router-2: Aug 16 18:08:33: 
IKEv2:(SESSION ID = 1,SA ID = 1):Sending Packet [To 
110.232.112.209:500/From 10.102.66.94:500/VRF i0:f0]
Aug 16 18:08:34 lo0.router-2.reub.net router-2: Initiator SPI : 
B8335E814D8F6500 - Responder SPI : 0000000000000000 Message id: 0
Aug 16 18:08:34 lo0.router-2.reub.net router-2: IKEv2 IKE_SA_INIT 
Exchange REQUEST
Aug 16 18:08:34 lo0.router-2.reub.net router-2: Payload contents:
Aug 16 18:08:34 lo0.router-2.reub.net router-2:  SA KE N VID VID VID VID 
NOTIFY(NAT_DETECTION_SOURCE_IP) NOTIFY(NAT_DETECTION_DESTINATION_IP)
Aug 16 18:08:34 lo0.router-2.reub.net router-2: Aug 16 18:08:34: 
IPSEC:(SESSION ID = 1) (key_engine) request timer fired: count = 2,
Aug 16 18:08:34 lo0.router-2.reub.net router-2:   (identity) local= 
10.102.66.94:0, remote= 110.232.112.209:0,
Aug 16 18:08:34 lo0.router-2.reub.net router-2:     local_proxy= 
0.0.0.0/0.0.0.0/256/0,
Aug 16 18:08:34 lo0.router-2.reub.net router-2:     remote_proxy= 
0.0.0.0/0.0.0.0/256/0
Aug 16 18:08:34 lo0.router-2.reub.net router-2: Aug 16 18:08:34: 
IPSEC(sa_request): ,
Aug 16 18:08:34 lo0.router-2.reub.net router-2:   (key eng. msg.) 
OUTBOUND local= 10.102.66.94:500, remote= 110.232.112.209:500,
Aug 16 18:08:34 lo0.router-2.reub.net router-2:     local_proxy= 
0.0.0.0/0.0.0.0/256/0,
Aug 16 18:08:34 lo0.router-2.reub.net router-2:     remote_proxy= 
0.0.0.0/0.0.0.0/256/0,
Aug 16 18:08:34 lo0.router-2.reub.net router-2:     protocol= ESP, 
transform= esp-aes esp-sha-hmac  (Tunnel),
Aug 16 18:08:34 lo0.router-2.reub.net router-2:     lifedur= 3600s and 
4608000kb,
Aug 16 18:08:34 lo0.router-2.reub.net router-2:     spi= 0x0(0), 
conn_id= 0, keysize= 128, flags= 0x0
Aug 16 18:08:34 lo0.router-2.reub.net router-2: Aug 16 18:08:34: IKEv2:% 
Getting preshared key from profile keyring reub-keyring
Aug 16 18:08:34 lo0.router-2.reub.net router-2: Aug 16 18:08:34: IKEv2:% 
Matched peer block 'lightning.reub.net-ipv4'
Aug 16 18:08:34 lo0.router-2.reub.net router-2: Aug 16 18:08:34: 
IKEv2:Searching Policy with fvrf 0, local address 10.102.66.94
Aug 16 18:08:34 lo0.router-2.reub.net router-2: Aug 16 18:08:34: 
IKEv2:Using the Default Policy for Proposal
Aug 16 18:08:34 lo0.router-2.reub.net router-2: Aug 16 18:08:34: IKEv2:
Aug 16 18:08:35 lo0.router-2.reub.net router-2: Found Policy 'default'
Aug 16 18:08:35 lo0.router-2.reub.net router-2: Aug 16 18:08:34: 
IKEv2:SA is already in negotiation, hence not negotiating again
Aug 16 18:09:04 lo0.router-2.reub.net router-2: Aug 16 18:09:04: 
IPSEC:(SESSION ID = 1) (key_engine) request timer fired: count = 3,
Aug 16 18:09:04 lo0.router-2.reub.net router-2:   (identity) local= 
10.102.66.94:0, remote= 110.232.112.209:0,
Aug 16 18:09:04 lo0.router-2.reub.net router-2:     local_proxy= 
0.0.0.0/0.0.0.0/256/0,
Aug 16 18:09:04 lo0.router-2.reub.net router-2:     remote_proxy= 
0.0.0.0/0.0.0.0/256/0
Aug 16 18:09:04 lo0.router-2.reub.net router-2: Aug 16 18:09:04: 
IPSEC(sa_request): ,
Aug 16 18:09:04 lo0.router-2.reub.net router-2:   (key eng. msg.) 
OUTBOUND local= 10.102.66.94:500, remote= 110.232.112.209:500,
Aug 16 18:09:04 lo0.router-2.reub.net router-2:     local_proxy= 
0.0.0.0/0.0.0.0/256/0,
Aug 16 18:09:04 lo0.router-2.reub.net router-2:     remote_proxy= 
0.0.0.0/0.0.0.0/256/0,
Aug 16 18:09:04 lo0.router-2.reub.net router-2:     protocol= ESP, 
transform= esp-aes esp-sha-hmac  (Tunnel),
Aug 16 18:09:04 lo0.router-2.reub.net router-2:     lifedur= 3600s and 
4608000kb,
Aug 16 18:09:04 lo0.router-2.reub.net router-2:     spi= 0x0(0), 
conn_id= 0, keysize= 128, flags= 0x0
Aug 16 18:09:04 lo0.router-2.reub.net router-2: Aug 16 18:09:04: IKEv2:% 
Getting preshared key from profile keyring reub-keyring
Aug 16 18:09:05 lo0.router-2.reub.net router-2: Aug 16 18:09:04: IKEv2:% 
Matched peer block 'lightning.reub.net-ipv4'
Aug 16 18:09:05 lo0.router-2.reub.net router-2: Aug 16 18:09:04: 
IKEv2:Searching Policy with fvrf 0, local address 10.102.66.94
Aug 16 18:09:05 lo0.router-2.reub.net router-2: Aug 16 18:09:04: 
IKEv2:Using the Default Policy for Proposal
Aug 16 18:09:05 lo0.router-2.reub.net router-2: Aug 16 18:09:04: 
IKEv2:Found Policy 'default'
Aug 16 18:09:05 lo0.router-2.reub.net router-2: Aug 16 18:09:04: 
IKEv2:SA is already in negotiation, hence not negotiating again
Aug 16 18:09:34 lo0.router-2.reub.net router-2: Aug 16 18:09:34: 
IPSEC:(SESSION ID = 1) (key_engine) request timer fired: count = 4,
Aug 16 18:09:34 lo0.router-2.reub.net router-2:   (identity) local= 
10.102.66.94:0, remote= 110.232.112.209:0,
Aug 16 18:09:34 lo0.router-2.reub.net router-2:     local_proxy= 
0.0.0.0/0.0.0.0/256/0,
Aug 16 18:09:34 lo0.router-2.reub.net router-2:     remote_proxy= 
0.0.0.0/0.0.0.0/256/0
Aug 16 18:09:34 lo0.router-2.reub.net router-2: Aug 16 18:09:34: 
IPSEC(sa_request): ,
Aug 16 18:09:34 lo0.router-2.reub.net router-2:   (key eng. msg.) 
OUTBOUND local= 10.102.66.94:500, remote= 110.232.112.209:500,
Aug 16 18:09:34 lo0.router-2.reub.net router-2:     local_proxy= 
0.0.0.0/0.0.0.0/256/0,
Aug 16 18:09:34 lo0.router-2.reub.net router-2:     remote_proxy= 
0.0.0.0/0.0.0.0/256/0,
Aug 16 18:09:34 lo0.router-2.reub.net router-2:     protocol= ESP, 
transform= esp-aes esp-sha-hmac  (Tunnel),
Aug 16 18:09:34 lo0.router-2.reub.net router-2:     lifedur= 3600s and 
4608000kb,
Aug 16 18:09:34 lo0.router-2.reub.net router-2:     spi= 0x0(0), 
conn_id= 0, keysize= 128, flags= 0x0
Aug 16 18:09:34 lo0.router-2.reub.net router-2: Aug 16 18:09:34: IKEv2:% 
Getting preshared key from profile keyring reub-keyring
Aug 16 18:09:35 lo0.router-2.reub.net router-2: Aug 16 18:09:34: IKEv2:% 
Matched peer block 'lightning.reub.net-ipv4'
Aug 16 18:09:35 lo0.router-2.reub.net router-2: Aug 16 18:09:34: 
IKEv2:Searching Policy with fvrf 0, local address 10.102.66.94
Aug 16 18:09:35 lo0.router-2.reub.net router-2: Aug 16 18:09:34: 
IKEv2:Using the Default Policy for Proposal
Aug 16 18:09:35 lo0.router-2.reub.net router-2: Aug 16 18:09:34: 
IKEv2:Found Policy 'default'
Aug 16 18:09:35 lo0.router-2.reub.net router-2: Aug 16 18:09:34: 
IKEv2:SA is already in negotiation, hence not negotiating again
Aug 16 18:09:37 lo0.router-2.reub.net router-2: Aug 16 18:09:36: 
IKEv2:(SESSION ID = 1,SA ID = 1):Retransmitting packet
Aug 16 18:09:37 lo0.router-2.reub.net router-2: Aug 16 18:09:36: 
IKEv2:(SESSION ID = 1,SA ID = 1):Sending Packet [To 
110.232.112.209:500/From 10.102.66.94:500/VRF i0:f0]
Aug 16 18:09:37 lo0.router-2.reub.net router-2: Initiator SPI : 
B8335E814D8F6500 - Responder SPI : 0000000000000000 Message id: 0
Aug 16 18:09:37 lo0.router-2.reub.net router-2: IKEv2 IKE_SA_INIT 
Exchange REQUEST
Aug 16 18:09:37 lo0.router-2.reub.net router-2: Payload contents:
Aug 16 18:09:37 lo0.router-2.reub.net router-2:  SA KE N VID VID VID VID 
NOTIFY(NAT_DETECTION_SOURCE_IP) NOTIFY(NAT_DETECTION_DESTINATION_IP)

Any further help gladly received.

Thanks,
Reuben




More information about the Swan mailing list