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@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@0x7f4024005be0
Aug 16 18:05:16.759339: | event_schedule: new
EVENT_v2_RESPONDER_TIMEOUT-pe@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@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@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@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@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@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@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@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@0x7f402c0050a0
Aug 16 18:05:38.219202: | timer_event_cb: processing event@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@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@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@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@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@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
_______________________________________________
Swan mailing list
Swan@lists.libreswan.org
https://lists.libreswan.org/mailman/listinfo/swan
