[Swan] Android 14 - IKEv2/IPSEC PSK
antonio
asilva at wirelessmundi.com
Thu Mar 28 19:40:39 EET 2024
Hi, Paul,
thanks for the reply.
The tunnel is to connect an android phone to my network, like a roadwarrior, the client doesn’t have a static ip address, where the device can navigate using my connection or access local resources.
The configuration I post here is a local setup using a virtual machine for testing. Using only local LANs to be easier to debug.
In the real world the connection would be:
MOBILE/Client (any IP) —— [home: isp router — [ipsec server] — local LAN]
In the past I used Android l2tp/ipsec and later I switch to Ipsec xauth psk, but now none of them are available for android 14.
I’ve a Samsung device where I can setup vpn profile: IKEv2/ipsec MSCHAPv2, IKEv2/ipsec PSK, IKEv2/ipsec RSA.
Both IKEv2/ipsec PSK, IKEv2/ipsec RSA don’t requiere username/password it looks like a normal tunnel between sides validating on PSK or RSA.
But I think there is some issue with android native implementation, it doesn’t respond… Here is the full log:
Mar 28 17:25:03.271188: | spent 0.00655 (0.0065) milliseconds in udp_read_packet() calling check_incoming_msg_errqueue()
Mar 28 17:25:03.271245: | struct msg_digest: newref @0x563a7894a418(0->1) (udp_read_packet() +249 programs/pluto/iface_udp.c)
Mar 28 17:25:03.271260: | struct iface_endpoint: addref @0x563a789493d8(1->2) (udp_read_packet() +249 programs/pluto/iface_udp.c)
Mar 28 17:25:03.271272: | alloc logger: newref @0x563a78946448(0->1) (udp_read_packet() +249 programs/pluto/iface_udp.c)
Mar 28 17:25:03.271290: | *received 652 bytes from 192.168.1.126:59964 on enp0s3 192.168.1.10:500 using UDP
Mar 28 17:25:03.271301: | 3b 78 77 0a dd f4 4e 5e 00 00 00 00 00 00 00 00 ;xw...N^........
Mar 28 17:25:03.271310: | 21 20 22 08 00 00 00 00 00 00 02 8c 22 00 00 f4 ! "........."...
Mar 28 17:25:03.271320: | 02 00 00 88 01 01 00 0f 03 00 00 0c 01 00 00 0c ................
Mar 28 17:25:03.271330: | 80 0e 01 00 03 00 00 0c 01 00 00 0c 80 0e 00 80 ................
Mar 28 17:25:03.271340: | 03 00 00 08 03 00 00 0e 03 00 00 08 03 00 00 0d ................
Mar 28 17:25:03.271350: | 03 00 00 08 03 00 00 0c 03 00 00 08 03 00 00 02 ................
Mar 28 17:25:03.271359: | 03 00 00 08 02 00 00 07 03 00 00 08 02 00 00 06 ................
Mar 28 17:25:03.271369: | 03 00 00 08 02 00 00 05 03 00 00 08 02 00 00 02 ................
Mar 28 17:25:03.271379: | 03 00 00 08 04 00 00 18 03 00 00 08 04 00 00 14 ................
Mar 28 17:25:03.271389: | 03 00 00 08 04 00 00 13 03 00 00 08 04 00 00 0e ................
Mar 28 17:25:03.271398: | 00 00 00 08 04 00 00 05 00 00 00 68 02 01 00 0b ...........h....
Mar 28 17:25:03.271408: | 03 00 00 0c 01 00 00 14 80 0e 01 00 03 00 00 0c ................
Mar 28 17:25:03.271418: | 01 00 00 14 80 0e 00 80 03 00 00 08 02 00 00 07 ................
Mar 28 17:25:03.271428: | 03 00 00 08 02 00 00 06 03 00 00 08 02 00 00 05 ................
Mar 28 17:25:03.271437: | 03 00 00 08 02 00 00 02 03 00 00 08 04 00 00 18 ................
Mar 28 17:25:03.271447: | 03 00 00 08 04 00 00 14 03 00 00 08 04 00 00 13 ................
Mar 28 17:25:03.271457: | 03 00 00 08 04 00 00 0e 00 00 00 08 04 00 00 05 ................
Mar 28 17:25:03.271467: | 28 00 01 08 00 18 00 00 58 b0 f4 00 26 ce f6 27 (.......X...&..'
Mar 28 17:25:03.271477: | 3e eb fd fa e7 67 e9 66 ef 26 ac 40 c2 ff 27 45 >....g.f.&. at ..'E
Mar 28 17:25:03.271486: | 7b 7e 9e 49 f8 0e 1f c2 37 9b 03 b1 2d ae 46 bf {~.I....7...-.F.
Mar 28 17:25:03.271496: | 7d 1b 66 f6 91 d2 70 08 de ef cf 1e 28 1a 25 7a }.f...p.....(.%z
Mar 28 17:25:03.271506: | bf 16 22 31 3e c4 be f6 d6 e4 6c f7 b4 e4 2f c5 .."1>.....l.../.
Mar 28 17:25:03.271516: | 59 67 32 91 62 74 6a 83 ce 17 85 8b 56 79 90 15 Yg2.btj.....Vy..
Mar 28 17:25:03.271525: | cb 71 f3 3f 31 40 5f bf 6c f0 9b d7 08 02 8c 30 .q.?1 at _.l......0
Mar 28 17:25:03.271535: | 1c f2 d8 02 f5 e8 70 08 17 87 0e db 26 53 41 cb ......p.....&SA.
Mar 28 17:25:03.271545: | e9 d1 08 73 46 e6 a5 2d 73 58 fb 0d ae 37 d4 28 ...sF..-sX...7.(
Mar 28 17:25:03.271555: | 9a 4c cb a1 32 96 5c b5 8b 2f 3e 82 71 40 0a 9b .L..2.\../>.q at ..
Mar 28 17:25:03.271565: | fd c0 9c 53 38 4e 87 fe 59 4c 72 fc 99 59 4d 29 ...S8N..YLr..YM)
Mar 28 17:25:03.271574: | bb 26 73 c9 21 52 89 a4 e8 39 99 f9 93 67 02 19 .&s.!R...9...g..
Mar 28 17:25:03.271584: | f1 44 47 6d 03 06 52 dc 1c 58 40 b6 09 69 1a 5c .DGm..R..X at ..i.\
Mar 28 17:25:03.271594: | 1f dd 27 3f c7 82 3f 91 23 08 bb b1 37 c3 9d df ..'?..?.#...7...
Mar 28 17:25:03.271604: | bd 6f 45 57 9a bf 60 80 89 7e 97 27 51 63 95 9a .oEW..`..~.'Qc..
Mar 28 17:25:03.271614: | 3c 22 a3 f5 e0 fc bf 1f 1c 89 dd b2 0a 2d 8f 92 <"...........-..
Mar 28 17:25:03.271642: | 9b df ee 1f 00 23 cb 49 29 00 00 24 f5 61 ff a5 .....#.I)..$.a..
Mar 28 17:25:03.271652: | 30 b8 30 dc 6b 4d 12 05 f8 53 25 2b cf 9a f8 65 0.0.kM...S%+...e
Mar 28 17:25:03.271690: | 24 75 a1 5e af 95 2b 6c 25 30 74 df 29 00 00 1c $u.^..+l%0t.)...
Mar 28 17:25:03.271703: | 00 00 40 04 6b b9 09 53 28 24 96 2e 7c f2 a5 cb .. at .k..S($..|...
Mar 28 17:25:03.271713: | 11 5b 36 fc 38 5d a9 e1 29 00 00 1c 00 00 40 05 .[6.8]..)..... at .
Mar 28 17:25:03.271723: | 4c d8 c7 a9 e4 03 0f 9b 19 88 df b0 ce bb 42 14 L.............B.
Mar 28 17:25:03.271732: | f2 89 1a 33 29 00 00 10 00 00 40 2f 00 02 00 03 ...3).....@/....
Mar 28 17:25:03.271742: | 00 04 00 05 00 00 00 08 00 00 40 16 .......... at .
Mar 28 17:25:03.271761: | **parse ISAKMP Message:
Mar 28 17:25:03.271776: | initiator SPI: 3b 78 77 0a dd f4 4e 5e
Mar 28 17:25:03.271791: | responder SPI: 00 00 00 00 00 00 00 00
Mar 28 17:25:03.271801: | next payload type: ISAKMP_NEXT_v2SA (0x21)
Mar 28 17:25:03.271811: | ISAKMP version: IKEv2 version 2.0 (rfc4306/rfc5996) (0x20)
Mar 28 17:25:03.271820: | exchange type: ISAKMP_v2_IKE_SA_INIT (0x22)
Mar 28 17:25:03.271830: | flags: ISAKMP_FLAG_v2_IKE_INIT (0x8)
Mar 28 17:25:03.271843: | Message ID: 0 (00 00 00 00)
Mar 28 17:25:03.271856: | length: 652 (00 00 02 8c)
Mar 28 17:25:03.271866: | processing version=2.0 packet with exchange type=ISAKMP_v2_IKE_SA_INIT (34)
Mar 28 17:25:03.271877: | I am the IKE SA Original Responder receiving an IKEv2 IKE_SA_INIT request
Mar 28 17:25:03.271888: | State DB: IKEv2 state not found (find_v2_ike_sa_by_initiator_spi)
Mar 28 17:25:03.271898: | Now let's proceed with payload (ISAKMP_NEXT_v2SA)
Mar 28 17:25:03.271908: | ***parse IKEv2 Security Association Payload:
Mar 28 17:25:03.271918: | next payload type: ISAKMP_NEXT_v2KE (0x22)
Mar 28 17:25:03.271928: | flags: none (0x0)
Mar 28 17:25:03.271939: | length: 244 (00 f4)
Mar 28 17:25:03.271948: | processing payload: ISAKMP_NEXT_v2SA (len=240)
Mar 28 17:25:03.271958: | Now let's proceed with payload (ISAKMP_NEXT_v2KE)
Mar 28 17:25:03.271968: | ***parse IKEv2 Key Exchange Payload:
Mar 28 17:25:03.271977: | next payload type: ISAKMP_NEXT_v2Ni (0x28)
Mar 28 17:25:03.271987: | flags: none (0x0)
Mar 28 17:25:03.271998: | length: 264 (01 08)
Mar 28 17:25:03.272008: | DH group: OAKLEY_GROUP_DH24 (0x18)
Mar 28 17:25:03.272017: | processing payload: ISAKMP_NEXT_v2KE (len=256)
Mar 28 17:25:03.272027: | Now let's proceed with payload (ISAKMP_NEXT_v2Ni)
Mar 28 17:25:03.272036: | ***parse IKEv2 Nonce Payload:
Mar 28 17:25:03.272046: | next payload type: ISAKMP_NEXT_v2N (0x29)
Mar 28 17:25:03.272056: | flags: none (0x0)
Mar 28 17:25:03.272067: | length: 36 (00 24)
Mar 28 17:25:03.272110: | processing payload: ISAKMP_NEXT_v2Ni (len=32)
Mar 28 17:25:03.272123: | Now let's proceed with payload (ISAKMP_NEXT_v2N)
Mar 28 17:25:03.272134: | ***parse IKEv2 Notify Payload:
Mar 28 17:25:03.272143: | next payload type: ISAKMP_NEXT_v2N (0x29)
Mar 28 17:25:03.272153: | flags: none (0x0)
Mar 28 17:25:03.272164: | length: 28 (00 1c)
Mar 28 17:25:03.272174: | Protocol ID: IKEv2_SEC_PROTO_NONE (0x0)
Mar 28 17:25:03.272185: | SPI size: 0 (00)
Mar 28 17:25:03.272194: | Notify Message Type: v2N_NAT_DETECTION_SOURCE_IP (0x4004)
Mar 28 17:25:03.272204: | processing payload: ISAKMP_NEXT_v2N (len=20)
Mar 28 17:25:03.272214: | Now let's proceed with payload (ISAKMP_NEXT_v2N)
Mar 28 17:25:03.272224: | ***parse IKEv2 Notify Payload:
Mar 28 17:25:03.272233: | next payload type: ISAKMP_NEXT_v2N (0x29)
Mar 28 17:25:03.272243: | flags: none (0x0)
Mar 28 17:25:03.272254: | length: 28 (00 1c)
Mar 28 17:25:03.272264: | Protocol ID: IKEv2_SEC_PROTO_NONE (0x0)
Mar 28 17:25:03.272274: | SPI size: 0 (00)
Mar 28 17:25:03.272284: | Notify Message Type: v2N_NAT_DETECTION_DESTINATION_IP (0x4005)
Mar 28 17:25:03.272294: | processing payload: ISAKMP_NEXT_v2N (len=20)
Mar 28 17:25:03.272314: | Now let's proceed with payload (ISAKMP_NEXT_v2N)
Mar 28 17:25:03.272324: | ***parse IKEv2 Notify Payload:
Mar 28 17:25:03.272333: | next payload type: ISAKMP_NEXT_v2N (0x29)
Mar 28 17:25:03.272343: | flags: none (0x0)
Mar 28 17:25:03.272354: | length: 16 (00 10)
Mar 28 17:25:03.272364: | Protocol ID: IKEv2_SEC_PROTO_NONE (0x0)
Mar 28 17:25:03.272374: | SPI size: 0 (00)
Mar 28 17:25:03.272384: | Notify Message Type: v2N_SIGNATURE_HASH_ALGORITHMS (0x402f)
Mar 28 17:25:03.272394: | processing payload: ISAKMP_NEXT_v2N (len=8)
Mar 28 17:25:03.272403: | Now let's proceed with payload (ISAKMP_NEXT_v2N)
Mar 28 17:25:03.272413: | ***parse IKEv2 Notify Payload:
Mar 28 17:25:03.272423: | next payload type: ISAKMP_NEXT_v2NONE (0x0)
Mar 28 17:25:03.272432: | flags: none (0x0)
Mar 28 17:25:03.272444: | length: 8 (00 08)
Mar 28 17:25:03.272453: | Protocol ID: IKEv2_SEC_PROTO_NONE (0x0)
Mar 28 17:25:03.272464: | SPI size: 0 (00)
Mar 28 17:25:03.272473: | Notify Message Type: v2N_REDIRECT_SUPPORTED (0x4016)
Mar 28 17:25:03.272483: | processing payload: ISAKMP_NEXT_v2N (len=0)
Mar 28 17:25:03.272493: | DDOS disabled and no cookie sent, continuing
Mar 28 17:25:03.272508: | looking for transition from PARENT_R0 matching IKE_SA_INIT request: SA,KE,Ni,N(NAT_DETECTION_SOURCE_IP),N(NAT_DETECTION_DESTINATION_IP),N(SIGNATURE_HASH_ALGORITHMS),N(REDIRECT_SUPPORTED)
Mar 28 17:25:03.272519: | trying: Respond to IKE_SA_INIT
Mar 28 17:25:03.272528: | unsecured message matched
Mar 28 17:25:03.272544: | ikev2_find_host_connection() 192.168.1.126->192.168.1.10 remote_authby=ECDSA
Mar 28 17:25:03.272559: | FOR_EACH_CONNECTION[local=192.168.1.10,remote=192.168.1.126].... in (ikev2_find_host_connection() +139 programs/pluto/ikev2_host_pair.c)
Mar 28 17:25:03.272570: | matches: 0
Mar 28 17:25:03.272583: | FOR_EACH_CONNECTION[local=192.168.1.10,remote=<unset-address>].... in (ikev2_find_host_connection() +214 programs/pluto/ikev2_host_pair.c)
Mar 28 17:25:03.272593: | found "tunnel1"
Mar 28 17:25:03.272604: | skipping "tunnel1", PSK missing required authby ECDSA
Mar 28 17:25:03.272614: | matches: 1
Mar 28 17:25:03.272627: | ISAKMP_v2_IKE_SA_INIT message received on 192.168.1.10:500 but no connection has been authorized with policy ECDSA, sending reject response
Mar 28 17:25:03.272642: | ikev2_find_host_connection() 192.168.1.126->192.168.1.10 remote_authby=RSASIG
Mar 28 17:25:03.272657: | FOR_EACH_CONNECTION[local=192.168.1.10,remote=192.168.1.126].... in (ikev2_find_host_connection() +139 programs/pluto/ikev2_host_pair.c)
Mar 28 17:25:03.272667: | matches: 0
Mar 28 17:25:03.272679: | FOR_EACH_CONNECTION[local=192.168.1.10,remote=<unset-address>].... in (ikev2_find_host_connection() +214 programs/pluto/ikev2_host_pair.c)
Mar 28 17:25:03.272689: | found "tunnel1"
Mar 28 17:25:03.272699: | skipping "tunnel1", PSK missing required authby RSASIG
Mar 28 17:25:03.272709: | matches: 1
Mar 28 17:25:03.272721: | ISAKMP_v2_IKE_SA_INIT message received on 192.168.1.10:500 but no connection has been authorized with policy RSASIG, sending reject response
Mar 28 17:25:03.272737: | ikev2_find_host_connection() 192.168.1.126->192.168.1.10 remote_authby=RSASIG_v1_5
Mar 28 17:25:03.272752: | FOR_EACH_CONNECTION[local=192.168.1.10,remote=192.168.1.126].... in (ikev2_find_host_connection() +139 programs/pluto/ikev2_host_pair.c)
Mar 28 17:25:03.272761: | matches: 0
Mar 28 17:25:03.272774: | FOR_EACH_CONNECTION[local=192.168.1.10,remote=<unset-address>].... in (ikev2_find_host_connection() +214 programs/pluto/ikev2_host_pair.c)
Mar 28 17:25:03.272783: | found "tunnel1"
Mar 28 17:25:03.272794: | skipping "tunnel1", PSK missing required authby RSASIG_v1_5
Mar 28 17:25:03.272803: | matches: 1
Mar 28 17:25:03.272816: | ISAKMP_v2_IKE_SA_INIT message received on 192.168.1.10:500 but no connection has been authorized with policy RSASIG_v1_5, sending reject response
Mar 28 17:25:03.272831: | ikev2_find_host_connection() 192.168.1.126->192.168.1.10 remote_authby=PSK
Mar 28 17:25:03.272846: | FOR_EACH_CONNECTION[local=192.168.1.10,remote=192.168.1.126].... in (ikev2_find_host_connection() +139 programs/pluto/ikev2_host_pair.c)
Mar 28 17:25:03.272865: | matches: 0
Mar 28 17:25:03.272878: | FOR_EACH_CONNECTION[local=192.168.1.10,remote=<unset-address>].... in (ikev2_find_host_connection() +214 programs/pluto/ikev2_host_pair.c)
Mar 28 17:25:03.272888: | found "tunnel1"
Mar 28 17:25:03.272898: | instant winner with non-opportunistic template "tunnel1"
Mar 28 17:25:03.272908: | instantiate roadwarrior winner "tunnel1"
Mar 28 17:25:03.272923: | "tunnel1": rw_responder_instantiate: remote=192.168.1.126 id=<null-id> kind=TEMPLATE sec_label= (ikev2_find_host_connection() +319 programs/pluto/ikev2_host_pair.c)
Mar 28 17:25:03.272933: | connection $1: "tunnel1"
Mar 28 17:25:03.272943: | routing+kind: UNROUTED TEMPLATE
Mar 28 17:25:03.272957: | host: 192.168.1.10->0.0.0.0
Mar 28 17:25:03.272970: | selectors: 192.168.10.0/24 -> <unset-selector>
Mar 28 17:25:03.272979: | spds: <unset-selectors>
Mar 28 17:25:03.272991: | policy: IKEv2+PSK+ENCRYPT+TUNNEL+PFS+IKE_FRAG_ALLOW+ESN_NO+ESN_YES
Mar 28 17:25:03.273004: | struct connection: newref @0x563a7894bee8(0->1) (ikev2_find_host_connection() +319 programs/pluto/ikev2_host_pair.c)
Mar 28 17:25:03.273018: | alloc logger: newref @0x563a78944b48(0->1) (ikev2_find_host_connection() +319 programs/pluto/ikev2_host_pair.c)
Mar 28 17:25:03.273027: | "tunnel1"[1]: no whack to attach
Mar 28 17:25:03.273037: | "tunnel1": template .instance_serial_next updated to 2; instance 1
Mar 28 17:25:03.273479: | "tunnel1": addref @0x563a78943438(1->2) "tunnel1"[1] <unset-address>: (alloc_connection() +2100 programs/pluto/connections.c)
Mar 28 17:25:03.273498: | struct iface: addref @0x563a78948838(4->5) (duplicate_connection() +78 programs/pluto/instantiate.c)
Mar 28 17:25:03.273510: | left.child.has_client: no -> yes (duplicate_connection() +87 programs/pluto/instantiate.c)
Mar 28 17:25:03.273520: | right.child.has_client: no -> no (duplicate_connection() +87 programs/pluto/instantiate.c)
Mar 28 17:25:03.273533: | updating host ends from right.host.addr 192.168.1.126
Mar 28 17:25:03.273543: | updated right.host_port from 0 to 500
Mar 28 17:25:03.273656: | updated left.host_nexthop from 0.0.0.0 to 192.168.1.126
Mar 28 17:25:03.273671: | "tunnel1"[1] 192.168.1.126: tunnel1 .child.reqid=16392 because t.config.sa_requid=0 (generate)
Mar 28 17:25:03.273695: | "tunnel1"[1] 192.168.1.126: 192.168.1.10->192.168.1.126 oriented=yes
Mar 28 17:25:03.273707: | update_selectors() left selectors from 1 child.selectors
Mar 28 17:25:03.273717: | update_selectors() right.child selector formed from host address+protoport
Mar 28 17:25:03.273732: | append_end_selector() right.child.selectors.proposed[0] 192.168.1.126/32 (update_selectors() +397 programs/pluto/instantiate.c)
Mar 28 17:25:03.273742: | adding connection spds using proposed
Mar 28 17:25:03.273751: | left=1 right=1
Mar 28 17:25:03.273761: | left[IPv4]=1 right[IPv4]=1
Mar 28 17:25:03.273771: | left[IPv6]=0 right[IPv6]=0
Mar 28 17:25:03.273781: | allocating 1 SPDs
Mar 28 17:25:03.273800: | 192.168.10.0/24===192.168.1.126/32
Mar 28 17:25:03.273814: | left child spd from selector 192.168.10.0/24 left.spd.has_client=yes virt=no
Mar 28 17:25:03.273870: | right child spd from selector 192.168.1.126/32 right.spd.has_client=no virt=no
Mar 28 17:25:03.273894: | "tunnel1"[1] 192.168.1.126: rw_responder_instantiate: from "tunnel1" (ikev2_find_host_connection() +319 programs/pluto/ikev2_host_pair.c)
Mar 28 17:25:03.273907: | connection $2 clonedfrom $1: "tunnel1"[1] 192.168.1.126
Mar 28 17:25:03.273917: | routing+kind: UNROUTED INSTANCE
Mar 28 17:25:03.273931: | host: 192.168.1.10->192.168.1.126
Mar 28 17:25:03.273946: | selectors: 192.168.10.0/24 -> 192.168.1.126/32
Mar 28 17:25:03.273961: | spds: 192.168.10.0/24===192.168.1.126/32
Mar 28 17:25:03.273972: | policy: IKEv2+PSK+ENCRYPT+TUNNEL+PFS+IKE_FRAG_ALLOW+ESN_NO+ESN_YES
Mar 28 17:25:03.273985: | found connection: "tunnel1"[1] 192.168.1.126 with remote authby PSK
Mar 28 17:25:03.274008: | struct iface_endpoint: addref @0x563a789493d8(2->3) (get_responder_endpoints() +610 programs/pluto/state.c)
Mar 28 17:25:03.274084: | alloc logger: newref @0x563a78944668(0->1) (new_v2_ike_sa() +666 programs/pluto/state.c)
Mar 28 17:25:03.274308: | #0: no whack to attach
Mar 28 17:25:03.274394: | "tunnel1"[1] 192.168.1.126: addref @0x563a7894bee8(1->2) #1: (new_state() +491 programs/pluto/state.c)
Mar 28 17:25:03.274439: | creating state object #1 at 0x563a7894c498
Mar 28 17:25:03.274487: | pstats #1 ikev2.ike started
Mar 28 17:25:03.274558: | parent state #1: UNDEFINED(ignore) => PARENT_R0(half-open IKE SA)
Mar 28 17:25:03.274674: | #1.st_v2_transition NULL -> PARENT_R0->PARENT_R1 (new_v2_ike_sa() +669 programs/pluto/state.c)
Mar 28 17:25:03.274736: | Message ID: IKE #1 initializing (initiator: .sent=0->-1 .recv=0->-1 .wip=0->-1 .last_sent=0->989.568922 .last_recv=0->989.568922 responder: .sent=0->-1 .recv=0->-1 .wip=0->-1 .last_sent=0->989.568922 .last_recv=0->989.568922)
Mar 28 17:25:03.274810: | event_schedule_where: newref EVENT_v2_DISCARD-pe at 0x563a78948248 timeout in 200 seconds for #1
Mar 28 17:25:03.274940: | tt: newref @0x563a789482c8(0->1) (schedule_timeout() +557 programs/pluto/server.c)
Mar 28 17:25:03.274993: | #1 spent 2.91 (3.83) milliseconds
Mar 28 17:25:03.275088: | #1.st_v2_transition PARENT_R0->PARENT_R1 -> PARENT_R0->PARENT_R1 (v2_dispatch() +2308 programs/pluto/ikev2.c)
Mar 28 17:25:03.275237: | Message ID: IKE #1 responder starting message request 0 (initiator: .sent=-1 .recv=-1 .recv_frags=0 .wip=-1 .last_sent=989.568922 .last_recv=989.568922 responder: .sent=-1 .recv=-1 .recv_frags=0 .wip=0 .last_sent=989.568922 .last_recv=989.568922)
Mar 28 17:25:03.275285: | calling processor Respond to IKE_SA_INIT
Mar 28 17:25:03.275324: | #1 spent 3.04 (4.16) milliseconds
Mar 28 17:25:03.275579: | #1 updating local interface from 192.168.1.10:500 to 192.168.1.10:500 using md->iface (update_ike_endpoints() +1714 programs/pluto/state.c)
Mar 28 17:25:03.275623: | delref @0x563a789493d8(3->2) (update_ike_endpoints() +1719 programs/pluto/state.c)
Mar 28 17:25:03.275660: | struct iface_endpoint: addref @0x563a789493d8(2->3) (update_ike_endpoints() +1720 programs/pluto/state.c)
Mar 28 17:25:03.275894: | comparing remote proposals against IKE responder 5 local proposals
Mar 28 17:25:03.276181: | local proposal 1 type ENCR has 1 transforms
Mar 28 17:25:03.276196: | local proposal 1 type PRF has 2 transforms
Mar 28 17:25:03.276207: | local proposal 1 type INTEG has 1 transforms
Mar 28 17:25:03.276216: | local proposal 1 type DH has 8 transforms
Mar 28 17:25:03.276226: | local proposal 1 type ESN has 0 transforms
Mar 28 17:25:03.276237: | local proposal 1 transforms: required: ENCR+PRF+DH; optional: INTEG
Mar 28 17:25:03.276248: | local proposal 2 type ENCR has 1 transforms
Mar 28 17:25:03.276260: | local proposal 2 type PRF has 2 transforms
Mar 28 17:25:03.276270: | local proposal 2 type INTEG has 1 transforms
Mar 28 17:25:03.276279: | local proposal 2 type DH has 8 transforms
Mar 28 17:25:03.276289: | local proposal 2 type ESN has 0 transforms
Mar 28 17:25:03.276304: | local proposal 2 transforms: required: ENCR+PRF+DH; optional: INTEG
Mar 28 17:25:03.276413: | local proposal 3 type ENCR has 1 transforms
Mar 28 17:25:03.276428: | local proposal 3 type PRF has 2 transforms
Mar 28 17:25:03.276438: | local proposal 3 type INTEG has 1 transforms
Mar 28 17:25:03.276448: | local proposal 3 type DH has 8 transforms
Mar 28 17:25:03.276457: | local proposal 3 type ESN has 0 transforms
Mar 28 17:25:03.276468: | local proposal 3 transforms: required: ENCR+PRF+DH; optional: INTEG
Mar 28 17:25:03.276478: | local proposal 4 type ENCR has 1 transforms
Mar 28 17:25:03.276491: | local proposal 4 type PRF has 2 transforms
Mar 28 17:25:03.276505: | local proposal 4 type INTEG has 2 transforms
Mar 28 17:25:03.276515: | local proposal 4 type DH has 8 transforms
Mar 28 17:25:03.276607: | local proposal 4 type ESN has 0 transforms
Mar 28 17:25:03.276621: | local proposal 4 transforms: required: ENCR+PRF+INTEG+DH; optional: none
Mar 28 17:25:03.276643: | local proposal 5 type ENCR has 1 transforms
Mar 28 17:25:03.276653: | local proposal 5 type PRF has 2 transforms
Mar 28 17:25:03.276663: | local proposal 5 type INTEG has 2 transforms
Mar 28 17:25:03.276673: | local proposal 5 type DH has 8 transforms
Mar 28 17:25:03.276685: | local proposal 5 type ESN has 0 transforms
Mar 28 17:25:03.276700: | local proposal 5 transforms: required: ENCR+PRF+INTEG+DH; optional: none
Mar 28 17:25:03.276712: | ****parse IKEv2 Proposal Substructure Payload:
Mar 28 17:25:03.276805: | last proposal: v2_PROPOSAL_NON_LAST (0x2)
Mar 28 17:25:03.276817: | length: 136 (00 88)
Mar 28 17:25:03.276860: | prop #: 1 (01)
Mar 28 17:25:03.276871: | proto ID: IKEv2_SEC_PROTO_IKE (0x1)
Mar 28 17:25:03.276884: | spi size: 0 (00)
Mar 28 17:25:03.276895: | # transforms: 15 (0f)
Mar 28 17:25:03.276906: | Comparing remote proposal 1 containing 15 transforms against local proposal [1..5] of 5 local proposals
Mar 28 17:25:03.276917: | *****parse IKEv2 Transform Substructure Payload:
Mar 28 17:25:03.276926: | last transform: v2_TRANSFORM_NON_LAST (0x3)
Mar 28 17:25:03.276938: | length: 12 (00 0c)
Mar 28 17:25:03.276947: | IKEv2 transform type: IKEv2_TRANS_TYPE_ENCR (0x1)
Mar 28 17:25:03.276974: | IKEv2 transform ID: AES_CBC (0xc)
Mar 28 17:25:03.276986: | ******parse IKEv2 Attribute Substructure Payload:
Mar 28 17:25:03.276996: | af+type: AF+IKEv2_KEY_LENGTH (0x800e)
Mar 28 17:25:03.277008: | length/value: 256 (01 00)
Mar 28 17:25:03.277021: | remote proposal 1 transform 0 (ENCR=AES_CBC_256) matches local proposal 4 type 1 (ENCR) transform 0
Mar 28 17:25:03.277031: | *****parse IKEv2 Transform Substructure Payload:
Mar 28 17:25:03.277041: | last transform: v2_TRANSFORM_NON_LAST (0x3)
Mar 28 17:25:03.277052: | length: 12 (00 0c)
Mar 28 17:25:03.277062: | IKEv2 transform type: IKEv2_TRANS_TYPE_ENCR (0x1)
Mar 28 17:25:03.277071: | IKEv2 transform ID: AES_CBC (0xc)
Mar 28 17:25:03.277081: | ******parse IKEv2 Attribute Substructure Payload:
Mar 28 17:25:03.277091: | af+type: AF+IKEv2_KEY_LENGTH (0x800e)
Mar 28 17:25:03.277102: | length/value: 128 (00 80)
Mar 28 17:25:03.277114: | remote proposal 1 transform 1 (ENCR=AES_CBC_128) matches local proposal 5 type 1 (ENCR) transform 0
Mar 28 17:25:03.277124: | *****parse IKEv2 Transform Substructure Payload:
Mar 28 17:25:03.277134: | last transform: v2_TRANSFORM_NON_LAST (0x3)
Mar 28 17:25:03.277145: | length: 8 (00 08)
Mar 28 17:25:03.277155: | IKEv2 transform type: IKEv2_TRANS_TYPE_INTEG (0x3)
Mar 28 17:25:03.277164: | IKEv2 transform ID: AUTH_HMAC_SHA2_512_256 (0xe)
Mar 28 17:25:03.277176: | remote proposal 1 transform 2 (INTEG=HMAC_SHA2_512_256) matches local proposal 4 type 3 (INTEG) transform 0
Mar 28 17:25:03.277188: | remote proposal 1 transform 2 (INTEG=HMAC_SHA2_512_256) matches local proposal 5 type 3 (INTEG) transform 0
Mar 28 17:25:03.277198: | *****parse IKEv2 Transform Substructure Payload:
Mar 28 17:25:03.277207: | last transform: v2_TRANSFORM_NON_LAST (0x3)
Mar 28 17:25:03.277218: | length: 8 (00 08)
Mar 28 17:25:03.277228: | IKEv2 transform type: IKEv2_TRANS_TYPE_INTEG (0x3)
Mar 28 17:25:03.277238: | IKEv2 transform ID: AUTH_HMAC_SHA2_384_192 (0xd)
Mar 28 17:25:03.277248: | *****parse IKEv2 Transform Substructure Payload:
Mar 28 17:25:03.277258: | last transform: v2_TRANSFORM_NON_LAST (0x3)
Mar 28 17:25:03.277269: | length: 8 (00 08)
Mar 28 17:25:03.277278: | IKEv2 transform type: IKEv2_TRANS_TYPE_INTEG (0x3)
Mar 28 17:25:03.277288: | IKEv2 transform ID: AUTH_HMAC_SHA2_256_128 (0xc)
Mar 28 17:25:03.277298: | *****parse IKEv2 Transform Substructure Payload:
Mar 28 17:25:03.277308: | last transform: v2_TRANSFORM_NON_LAST (0x3)
Mar 28 17:25:03.277319: | length: 8 (00 08)
Mar 28 17:25:03.277328: | IKEv2 transform type: IKEv2_TRANS_TYPE_INTEG (0x3)
Mar 28 17:25:03.277338: | IKEv2 transform ID: AUTH_HMAC_SHA1_96 (0x2)
Mar 28 17:25:03.277348: | *****parse IKEv2 Transform Substructure Payload:
Mar 28 17:25:03.277369: | last transform: v2_TRANSFORM_NON_LAST (0x3)
Mar 28 17:25:03.277380: | length: 8 (00 08)
Mar 28 17:25:03.277390: | IKEv2 transform type: IKEv2_TRANS_TYPE_PRF (0x2)
Mar 28 17:25:03.277400: | IKEv2 transform ID: PRF_HMAC_SHA2_512 (0x7)
Mar 28 17:25:03.277411: | remote proposal 1 transform 6 (PRF=HMAC_SHA2_512) matches local proposal 1 type 2 (PRF) transform 0
Mar 28 17:25:03.277423: | remote proposal 1 transform 6 (PRF=HMAC_SHA2_512) matches local proposal 2 type 2 (PRF) transform 0
Mar 28 17:25:03.277434: | remote proposal 1 transform 6 (PRF=HMAC_SHA2_512) matches local proposal 3 type 2 (PRF) transform 0
Mar 28 17:25:03.277445: | remote proposal 1 transform 6 (PRF=HMAC_SHA2_512) matches local proposal 4 type 2 (PRF) transform 0
Mar 28 17:25:03.277457: | remote proposal 1 transform 6 (PRF=HMAC_SHA2_512) matches local proposal 5 type 2 (PRF) transform 0
Mar 28 17:25:03.277469: | *****parse IKEv2 Transform Substructure Payload:
Mar 28 17:25:03.277479: | last transform: v2_TRANSFORM_NON_LAST (0x3)
Mar 28 17:25:03.277491: | length: 8 (00 08)
Mar 28 17:25:03.277503: | IKEv2 transform type: IKEv2_TRANS_TYPE_PRF (0x2)
Mar 28 17:25:03.277513: | IKEv2 transform ID: PRF_HMAC_SHA2_384 (0x6)
Mar 28 17:25:03.277523: | *****parse IKEv2 Transform Substructure Payload:
Mar 28 17:25:03.277533: | last transform: v2_TRANSFORM_NON_LAST (0x3)
Mar 28 17:25:03.277544: | length: 8 (00 08)
Mar 28 17:25:03.277554: | IKEv2 transform type: IKEv2_TRANS_TYPE_PRF (0x2)
Mar 28 17:25:03.277564: | IKEv2 transform ID: PRF_HMAC_SHA2_256 (0x5)
Mar 28 17:25:03.277574: | *****parse IKEv2 Transform Substructure Payload:
Mar 28 17:25:03.277583: | last transform: v2_TRANSFORM_NON_LAST (0x3)
Mar 28 17:25:03.277595: | length: 8 (00 08)
Mar 28 17:25:03.277604: | IKEv2 transform type: IKEv2_TRANS_TYPE_PRF (0x2)
Mar 28 17:25:03.277614: | IKEv2 transform ID: PRF_HMAC_SHA1 (0x2)
Mar 28 17:25:03.277624: | *****parse IKEv2 Transform Substructure Payload:
Mar 28 17:25:03.277634: | last transform: v2_TRANSFORM_NON_LAST (0x3)
Mar 28 17:25:03.277645: | length: 8 (00 08)
Mar 28 17:25:03.277654: | IKEv2 transform type: IKEv2_TRANS_TYPE_DH (0x4)
Mar 28 17:25:03.277664: | IKEv2 transform ID: OAKLEY_GROUP_DH24 (0x18)
Mar 28 17:25:03.277675: | *****parse IKEv2 Transform Substructure Payload:
Mar 28 17:25:03.277685: | last transform: v2_TRANSFORM_NON_LAST (0x3)
Mar 28 17:25:03.277696: | length: 8 (00 08)
Mar 28 17:25:03.277705: | IKEv2 transform type: IKEv2_TRANS_TYPE_DH (0x4)
Mar 28 17:25:03.277715: | IKEv2 transform ID: OAKLEY_GROUP_ECP_384 (0x14)
Mar 28 17:25:03.277727: | remote proposal 1 transform 11 (DH=ECP_384) matches local proposal 1 type 4 (DH) transform 1
Mar 28 17:25:03.277738: | remote proposal 1 transform 11 (DH=ECP_384) matches local proposal 2 type 4 (DH) transform 1
Mar 28 17:25:03.277750: | remote proposal 1 transform 11 (DH=ECP_384) matches local proposal 3 type 4 (DH) transform 1
Mar 28 17:25:03.277761: | remote proposal 1 transform 11 (DH=ECP_384) matches local proposal 4 type 4 (DH) transform 1
Mar 28 17:25:03.277772: | remote proposal 1 transform 11 (DH=ECP_384) matches local proposal 5 type 4 (DH) transform 1
Mar 28 17:25:03.277782: | *****parse IKEv2 Transform Substructure Payload:
Mar 28 17:25:03.277792: | last transform: v2_TRANSFORM_NON_LAST (0x3)
Mar 28 17:25:03.277805: | length: 8 (00 08)
Mar 28 17:25:03.278151: | IKEv2 transform type: IKEv2_TRANS_TYPE_DH (0x4)
Mar 28 17:25:03.278216: | IKEv2 transform ID: OAKLEY_GROUP_ECP_256 (0x13)
Mar 28 17:25:03.278255: | remote proposal 1 transform 12 (DH=ECP_256) matches local proposal 1 type 4 (DH) transform 0
Mar 28 17:25:03.278292: | remote proposal 1 transform 12 (DH=ECP_256) matches local proposal 2 type 4 (DH) transform 0
Mar 28 17:25:03.278329: | remote proposal 1 transform 12 (DH=ECP_256) matches local proposal 3 type 4 (DH) transform 0
Mar 28 17:25:03.278365: | remote proposal 1 transform 12 (DH=ECP_256) matches local proposal 4 type 4 (DH) transform 0
Mar 28 17:25:03.278402: | remote proposal 1 transform 12 (DH=ECP_256) matches local proposal 5 type 4 (DH) transform 0
Mar 28 17:25:03.278481: | *****parse IKEv2 Transform Substructure Payload:
Mar 28 17:25:03.278592: | last transform: v2_TRANSFORM_NON_LAST (0x3)
Mar 28 17:25:03.278629: | length: 8 (00 08)
Mar 28 17:25:03.278731: | IKEv2 transform type: IKEv2_TRANS_TYPE_DH (0x4)
Mar 28 17:25:03.278769: | IKEv2 transform ID: OAKLEY_GROUP_MODP2048 (0xe)
Mar 28 17:25:03.278805: | *****parse IKEv2 Transform Substructure Payload:
Mar 28 17:25:03.278859: | last transform: v2_TRANSFORM_LAST (0x0)
Mar 28 17:25:03.278923: | length: 8 (00 08)
Mar 28 17:25:03.278971: | IKEv2 transform type: IKEv2_TRANS_TYPE_DH (0x4)
Mar 28 17:25:03.279097: | IKEv2 transform ID: OAKLEY_GROUP_MODP1536 (0x5)
Mar 28 17:25:03.279146: | remote proposal 1 proposed transforms: ENCR+PRF+INTEG+DH; matched: ENCR+PRF+INTEG+DH; unmatched: none
Mar 28 17:25:03.279200: | comparing remote proposal 1 containing ENCR+PRF+INTEG+DH transforms to local proposal 1; required: ENCR+PRF+DH; optional: INTEG; matched: PRF+DH
Mar 28 17:25:03.279248: | remote proposal 1 does not match local proposal 1; unmatched transforms: ENCR+INTEG; missing transforms: ENCR
Mar 28 17:25:03.279293: | comparing remote proposal 1 containing ENCR+PRF+INTEG+DH transforms to local proposal 2; required: ENCR+PRF+DH; optional: INTEG; matched: PRF+DH
Mar 28 17:25:03.279337: | remote proposal 1 does not match local proposal 2; unmatched transforms: ENCR+INTEG; missing transforms: ENCR
Mar 28 17:25:03.279574: | comparing remote proposal 1 containing ENCR+PRF+INTEG+DH transforms to local proposal 3; required: ENCR+PRF+DH; optional: INTEG; matched: PRF+DH
Mar 28 17:25:03.279695: | remote proposal 1 does not match local proposal 3; unmatched transforms: ENCR+INTEG; missing transforms: ENCR
Mar 28 17:25:03.279745: | comparing remote proposal 1 containing ENCR+PRF+INTEG+DH transforms to local proposal 4; required: ENCR+PRF+INTEG+DH; optional: none; matched: ENCR+PRF+INTEG+DH
Mar 28 17:25:03.279794: | remote proposal 1 matches local proposal 4
Mar 28 17:25:03.280079: | ****parse IKEv2 Proposal Substructure Payload:
Mar 28 17:25:03.280123: | last proposal: v2_PROPOSAL_LAST (0x0)
Mar 28 17:25:03.280169: | length: 104 (00 68)
Mar 28 17:25:03.280375: | prop #: 2 (02)
Mar 28 17:25:03.280501: | proto ID: IKEv2_SEC_PROTO_IKE (0x1)
Mar 28 17:25:03.280547: | spi size: 0 (00)
Mar 28 17:25:03.283853: | # transforms: 11 (0b)
Mar 28 17:25:03.283938: | Comparing remote proposal 2 containing 11 transforms against local proposal [1..3] of 5 local proposals
Mar 28 17:25:03.283984: | *****parse IKEv2 Transform Substructure Payload:
Mar 28 17:25:03.284480: | last transform: v2_TRANSFORM_NON_LAST (0x3)
Mar 28 17:25:03.284542: | length: 12 (00 0c)
Mar 28 17:25:03.284585: | IKEv2 transform type: IKEv2_TRANS_TYPE_ENCR (0x1)
Mar 28 17:25:03.284626: | IKEv2 transform ID: AES_GCM_C (0x14)
Mar 28 17:25:03.284849: | ******parse IKEv2 Attribute Substructure Payload:
Mar 28 17:25:03.285053: | af+type: AF+IKEv2_KEY_LENGTH (0x800e)
Mar 28 17:25:03.285117: | length/value: 256 (01 00)
Mar 28 17:25:03.285162: | remote proposal 2 transform 0 (ENCR=AES_GCM_C_256) matches local proposal 1 type 1 (ENCR) transform 0
Mar 28 17:25:03.285205: | *****parse IKEv2 Transform Substructure Payload:
Mar 28 17:25:03.285399: | last transform: v2_TRANSFORM_NON_LAST (0x3)
Mar 28 17:25:03.285445: | length: 12 (00 0c)
Mar 28 17:25:03.285584: | IKEv2 transform type: IKEv2_TRANS_TYPE_ENCR (0x1)
Mar 28 17:25:03.285629: | IKEv2 transform ID: AES_GCM_C (0x14)
Mar 28 17:25:03.285758: | ******parse IKEv2 Attribute Substructure Payload:
Mar 28 17:25:03.289703: | af+type: AF+IKEv2_KEY_LENGTH (0x800e)
Mar 28 17:25:03.289823: | length/value: 128 (00 80)
Mar 28 17:25:03.289874: | remote proposal 2 transform 1 (ENCR=AES_GCM_C_128) matches local proposal 2 type 1 (ENCR) transform 0
Mar 28 17:25:03.289918: | *****parse IKEv2 Transform Substructure Payload:
Mar 28 17:25:03.290140: | last transform: v2_TRANSFORM_NON_LAST (0x3)
Mar 28 17:25:03.290269: | length: 8 (00 08)
Mar 28 17:25:03.292847: | IKEv2 transform type: IKEv2_TRANS_TYPE_PRF (0x2)
Mar 28 17:25:03.292916: | IKEv2 transform ID: PRF_HMAC_SHA2_512 (0x7)
Mar 28 17:25:03.292963: | remote proposal 2 transform 2 (PRF=HMAC_SHA2_512) matches local proposal 1 type 2 (PRF) transform 0
Mar 28 17:25:03.294580: | remote proposal 2 transform 2 (PRF=HMAC_SHA2_512) matches local proposal 2 type 2 (PRF) transform 0
Mar 28 17:25:03.294649: | remote proposal 2 transform 2 (PRF=HMAC_SHA2_512) matches local proposal 3 type 2 (PRF) transform 0
Mar 28 17:25:03.296831: | *****parse IKEv2 Transform Substructure Payload:
Mar 28 17:25:03.298853: | last transform: v2_TRANSFORM_NON_LAST (0x3)
Mar 28 17:25:03.298932: | length: 8 (00 08)
Mar 28 17:25:03.298975: | IKEv2 transform type: IKEv2_TRANS_TYPE_PRF (0x2)
Mar 28 17:25:03.299016: | IKEv2 transform ID: PRF_HMAC_SHA2_384 (0x6)
Mar 28 17:25:03.299139: | *****parse IKEv2 Transform Substructure Payload:
Mar 28 17:25:03.299255: | last transform: v2_TRANSFORM_NON_LAST (0x3)
Mar 28 17:25:03.299305: | length: 8 (00 08)
Mar 28 17:25:03.299346: | IKEv2 transform type: IKEv2_TRANS_TYPE_PRF (0x2)
Mar 28 17:25:03.299525: | IKEv2 transform ID: PRF_HMAC_SHA2_256 (0x5)
Mar 28 17:25:03.299570: | *****parse IKEv2 Transform Substructure Payload:
Mar 28 17:25:03.299642: | last transform: v2_TRANSFORM_NON_LAST (0x3)
Mar 28 17:25:03.299873: | length: 8 (00 08)
Mar 28 17:25:03.300018: | IKEv2 transform type: IKEv2_TRANS_TYPE_PRF (0x2)
Mar 28 17:25:03.300062: | IKEv2 transform ID: PRF_HMAC_SHA1 (0x2)
Mar 28 17:25:03.300110: | *****parse IKEv2 Transform Substructure Payload:
Mar 28 17:25:03.300449: | last transform: v2_TRANSFORM_NON_LAST (0x3)
Mar 28 17:25:03.300584: | length: 8 (00 08)
Mar 28 17:25:03.302845: | IKEv2 transform type: IKEv2_TRANS_TYPE_DH (0x4)
Mar 28 17:25:03.302914: | IKEv2 transform ID: OAKLEY_GROUP_DH24 (0x18)
Mar 28 17:25:03.302959: | *****parse IKEv2 Transform Substructure Payload:
Mar 28 17:25:03.303001: | last transform: v2_TRANSFORM_NON_LAST (0x3)
Mar 28 17:25:03.303190: | length: 8 (00 08)
Mar 28 17:25:03.303205: | IKEv2 transform type: IKEv2_TRANS_TYPE_DH (0x4)
Mar 28 17:25:03.303216: | IKEv2 transform ID: OAKLEY_GROUP_ECP_384 (0x14)
Mar 28 17:25:03.303232: | remote proposal 2 transform 7 (DH=ECP_384) matches local proposal 1 type 4 (DH) transform 1
Mar 28 17:25:03.303244: | remote proposal 2 transform 7 (DH=ECP_384) matches local proposal 2 type 4 (DH) transform 1
Mar 28 17:25:03.303256: | remote proposal 2 transform 7 (DH=ECP_384) matches local proposal 3 type 4 (DH) transform 1
Mar 28 17:25:03.303266: | *****parse IKEv2 Transform Substructure Payload:
Mar 28 17:25:03.303276: | last transform: v2_TRANSFORM_NON_LAST (0x3)
Mar 28 17:25:03.303287: | length: 8 (00 08)
Mar 28 17:25:03.303296: | IKEv2 transform type: IKEv2_TRANS_TYPE_DH (0x4)
Mar 28 17:25:03.303306: | IKEv2 transform ID: OAKLEY_GROUP_ECP_256 (0x13)
Mar 28 17:25:03.303333: | remote proposal 2 transform 8 (DH=ECP_256) matches local proposal 1 type 4 (DH) transform 0
Mar 28 17:25:03.303349: | remote proposal 2 transform 8 (DH=ECP_256) matches local proposal 2 type 4 (DH) transform 0
Mar 28 17:25:03.303361: | remote proposal 2 transform 8 (DH=ECP_256) matches local proposal 3 type 4 (DH) transform 0
Mar 28 17:25:03.303371: | *****parse IKEv2 Transform Substructure Payload:
Mar 28 17:25:03.303381: | last transform: v2_TRANSFORM_NON_LAST (0x3)
Mar 28 17:25:03.303392: | length: 8 (00 08)
Mar 28 17:25:03.303402: | IKEv2 transform type: IKEv2_TRANS_TYPE_DH (0x4)
Mar 28 17:25:03.303415: | IKEv2 transform ID: OAKLEY_GROUP_MODP2048 (0xe)
Mar 28 17:25:03.303426: | *****parse IKEv2 Transform Substructure Payload:
Mar 28 17:25:03.303436: | last transform: v2_TRANSFORM_LAST (0x0)
Mar 28 17:25:03.303447: | length: 8 (00 08)
Mar 28 17:25:03.303456: | IKEv2 transform type: IKEv2_TRANS_TYPE_DH (0x4)
Mar 28 17:25:03.303466: | IKEv2 transform ID: OAKLEY_GROUP_MODP1536 (0x5)
Mar 28 17:25:03.303479: | remote proposal 2 proposed transforms: ENCR+PRF+DH; matched: ENCR+PRF+DH; unmatched: none
Mar 28 17:25:03.303510: | comparing remote proposal 2 containing ENCR+PRF+DH transforms to local proposal 1; required: ENCR+PRF+DH; optional: INTEG; matched: ENCR+PRF+DH
Mar 28 17:25:03.303520: | remote proposal 2 matches local proposal 1
Mar 28 17:25:03.303540: "tunnel1"[1] 192.168.1.126 #1: proposal 2:IKE=AES_GCM_C_256-HMAC_SHA2_512-ECP_256 chosen from remote proposals 1:IKE:ENCR=AES_CBC_256;ENCR=AES_CBC_128;INTEG=HMAC_SHA2_512_256;INTEG=HMAC_SHA2_384_192;INTEG=HMAC_SHA2_256_128;INTEG=HMAC_SHA1_96;PRF=HMAC_SHA2_512;PRF=HMAC_SHA2_384;PRF=HMAC_SHA2_256;PRF=HMAC_SHA1;DH=DH24;DH=ECP_384;DH=ECP_256;DH=MODP2048;DH=MODP1536[first-match] 2:IKE:ENCR=AES_GCM_C_256;ENCR=AES_GCM_C_128;PRF=HMAC_SHA2_512;PRF=HMAC_SHA2_384;PRF=HMAC_SHA2_256;PRF=HMAC_SHA1;DH=DH24;DH=ECP_384;DH=ECP_256;DH=MODP2048;DH=MODP1536[better-match]
Mar 28 17:25:03.303560: | accepted IKE proposal ikev2_proposal: 2:IKE=AES_GCM_C_256-HMAC_SHA2_512-ECP_256
Mar 28 17:25:03.303569: | converting proposal to internal trans attrs
Mar 28 17:25:03.303585: "tunnel1"[1] 192.168.1.126 #1: initiator guessed wrong keying material group (DH24); responding with INVALID_KE_PAYLOAD requesting DH19
Mar 28 17:25:03.303596: | opening output PBS v2N response
Mar 28 17:25:03.303606: | **emit ISAKMP Message:
Mar 28 17:25:03.303620: | initiator SPI: 3b 78 77 0a dd f4 4e 5e
Mar 28 17:25:03.303634: | responder SPI: f9 e1 df 07 11 9f 5f 0d
Mar 28 17:25:03.303649: | next payload type: ISAKMP_NEXT_NONE (0x0)
Mar 28 17:25:03.303661: | ISAKMP version: IKEv2 version 2.0 (rfc4306/rfc5996) (0x20)
Mar 28 17:25:03.303753: | exchange type: ISAKMP_v2_IKE_SA_INIT (0x22)
Mar 28 17:25:03.303767: | flags: ISAKMP_FLAG_v2_MSG_RESPONSE (0x20)
Mar 28 17:25:03.303780: | Message ID: 0 (00 00 00 00)
Mar 28 17:25:03.303790: | next payload chain: saving message location 'ISAKMP Message'.'next payload type'
Mar 28 17:25:03.303845: "tunnel1"[1] 192.168.1.126 #1: responding to IKE_SA_INIT message (ID 0) from 192.168.1.126:59964 with unencrypted notification INVALID_KE_PAYLOAD
Mar 28 17:25:03.303861: | adding a v2N Payload
Mar 28 17:25:03.303871: | ***emit IKEv2 Notify Payload:
Mar 28 17:25:03.303881: | next payload type: ISAKMP_NEXT_v2NONE (0x0)
Mar 28 17:25:03.303891: | flags: none (0x0)
Mar 28 17:25:03.303900: | Protocol ID: IKEv2_SEC_PROTO_NONE (0x0)
Mar 28 17:25:03.303911: | SPI size: 0 (00)
Mar 28 17:25:03.303921: | Notify Message Type: v2N_INVALID_KE_PAYLOAD (0x11)
Mar 28 17:25:03.303931: | next payload chain: setting previous 'ISAKMP Message'.'next payload type' to current IKEv2 Notify Payload (41:ISAKMP_NEXT_v2N)
Mar 28 17:25:03.304013: | next payload chain: saving location 'IKEv2 Notify Payload'.'next payload type' in 'v2N response'
Mar 28 17:25:03.304027: | emitting 2 raw bytes of Notify data into IKEv2 Notify Payload
Mar 28 17:25:03.304037: | Notify data: 00 13
Mar 28 17:25:03.304047: | emitting length of IKEv2 Notify Payload: 10
Mar 28 17:25:03.304057: | emitting length of ISAKMP Message: 38
Mar 28 17:25:03.304071: | #1 complete_v2_state_transition() PARENT_R0->PARENT_R1 with status STF_FATAL
Mar 28 17:25:03.304084: "tunnel1"[1] 192.168.1.126 #1: encountered fatal error in state STATE_V2_PARENT_R0
Mar 28 17:25:03.304107: | Message ID: IKE #1 responding with recorded fatal message (initiator: .sent=-1 .recv=-1 .recv_frags=0 .wip=-1 .last_sent=989.568922 .last_recv=989.568922 responder: .sent=-1 .recv=-1 .recv_frags=0 .wip=0 .last_sent=989.568922 .last_recv=989.568922)
Mar 28 17:25:03.304125: | Message ID: IKE #1 updating responder received message request 0 (initiator: responder: .recv=-1->0 .wip=0->-1 .last_recv=989.568922->989.598325)
Mar 28 17:25:03.304140: | Message ID: IKE #1 updating responder sent message response 0 (initiator: responder: .sent=-1->0 .last_sent=989.568922->989.598342)
Mar 28 17:25:03.304162: | sending 38 bytes for STF_FATAL through enp0s3 from 192.168.1.10:500 to 192.168.1.126:59964 using UDP (for #1)
Mar 28 17:25:03.304172: | 3b 78 77 0a dd f4 4e 5e f9 e1 df 07 11 9f 5f 0d ;xw...N^......_.
Mar 28 17:25:03.304195: | 29 20 22 20 00 00 00 00 00 00 00 26 00 00 00 0a ) " .......&....
Mar 28 17:25:03.304205: | 00 00 00 11 00 13 ......
Mar 28 17:25:03.304266: | sent 1 messages
Mar 28 17:25:03.304282: | "tunnel1"[1] 192.168.1.126 #1: .st_on_delete.skip_send_delete no->true (complete_v2_state_transition() +2822 programs/pluto/ikev2.c)
Mar 28 17:25:03.304314: | "tunnel1"[1] 192.168.1.126 #1: routing: connection_zap_ike_family()
Mar 28 17:25:03.304332: | IKE SA is no longer viable
Mar 28 17:25:03.304349: | "tunnel1"[1] 192.168.1.126 #1: routing: IKE SA's connection has no Child SA #0
Mar 28 17:25:03.304360: | FOR_EACH_STATE[clonedfrom=#1]... in (connection_zap_ike_family() +568 programs/pluto/terminate.c)
Mar 28 17:25:03.304370: | matches: 0
Mar 28 17:25:03.304386: | clone logger: newref @0x563a78943db8(0->1) (teardown_ike() +1278 programs/pluto/routing.c)
Mar 28 17:25:03.304402: | "tunnel1"[1] 192.168.1.126: addref @0x563a7894bee8(2->3) "tunnel1"[1] 192.168.1.126 #1: (dispatch() +2436 programs/pluto/routing.c)
Mar 28 17:25:03.304418: | "tunnel1"[1] 192.168.1.126 #1: routing: start TEARDOWN_IKE, UNROUTED, INSTANCE; IKE #1 (PARENT_R0) by=UNKNOWN; $2 at 0x563a7894bee8 (complete_v2_state_transition() +2823 programs/pluto/ikev2.c)
Mar 28 17:25:03.304428: | "tunnel1"[1] 192.168.1.126 #1: routing: IKE SA does not match .routing_sa #0
Mar 28 17:25:03.304442: | "tunnel1"[1] 192.168.1.126 #1: .st_on_delete.skip_send_delete yes->true (delete_ike_sa() +771 programs/pluto/state.c)
Mar 28 17:25:03.304455: | "tunnel1"[1] 192.168.1.126 #1: delete_state() skipping log_message:no
Mar 28 17:25:03.304465: | FOR_EACH_STATE[clonedfrom=#1]... in (delete_state() +866 programs/pluto/state.c)
Mar 28 17:25:03.304475: | matches: 0
Mar 28 17:25:03.304487: "tunnel1"[1] 192.168.1.126 #1: deleting IKE SA (processing IKE_SA_INIT request)
Mar 28 17:25:03.304500: | "tunnel1"[1] 192.168.1.126 #1: .st_on_delete.skip_log_message no->true (delete_state() +885 programs/pluto/state.c)
Mar 28 17:25:03.304516: | pstats #1 ikev2.ike deleted other
Mar 28 17:25:03.304535: | #1 main thread spent 0 (0) milliseconds helper thread spent 0 (0) milliseconds in total
Mar 28 17:25:03.315250: | suspend: no MD saved in state #1 (delete_state() +972 programs/pluto/state.c)
Mar 28 17:25:03.316881: | #1 deleting EVENT_v2_DISCARD
Mar 28 17:25:03.316952: | tt: delref @0x563a789482c8(1->0) (destroy_timeout() +575 programs/pluto/server.c)
Mar 28 17:25:03.318869: | state-event: delref @0x563a78948248(1->0) (delete_state() +979 programs/pluto/state.c)
Mar 28 17:25:03.320857: | #1 STATE_V2_PARENT_R0: retransmits: cleared
Mar 28 17:25:03.320934: | pending: flush_pending_by_state() ike 0x563a7894c498 pending (nil)
Mar 28 17:25:03.320980: | FOR_EACH_STATE[clonedfrom=#1]... in (flush_incomplete_children() +729 programs/pluto/state.c)
Mar 28 17:25:03.321098: | matches: 0
Mar 28 17:25:03.321222: | delref @0x563a789493d8(3->2) (delete_state() +1032 programs/pluto/state.c)
Mar 28 17:25:03.322885: | "tunnel1"[1] 192.168.1.126: delref @0x563a7894bee8(3->2) #1: (delete_state() +1072 programs/pluto/state.c)
Mar 28 17:25:03.322956: | parent state #1: PARENT_R0(half-open IKE SA) => UNDEFINED(ignore)
Mar 28 17:25:03.323002: | #1: releasing whack (but there are none) (delete_state() +1078 programs/pluto/state.c)
Mar 28 17:25:03.323057: | delete_state: delref st->st_dh_shared_secret-key at NULL
Mar 28 17:25:03.323099: | delete_state: delref st->st_skeyid_nss-key at NULL
Mar 28 17:25:03.323139: | delete_state: delref st->st_skey_d_nss-key at NULL
Mar 28 17:25:03.323178: | delete_state: delref st->st_skey_ai_nss-key at NULL
Mar 28 17:25:03.324851: | delete_state: delref st->st_skey_ar_nss-key at NULL
Mar 28 17:25:03.324910: | delete_state: delref st->st_skey_ei_nss-key at NULL
Mar 28 17:25:03.327285: | delete_state: delref st->st_skey_er_nss-key at NULL
Mar 28 17:25:03.327353: | delete_state: delref st->st_skey_pi_nss-key at NULL
Mar 28 17:25:03.327396: | delete_state: delref st->st_skey_pr_nss-key at NULL
Mar 28 17:25:03.327436: | delete_state: delref st->st_enc_key_nss-key at NULL
Mar 28 17:25:03.327664: | delete_state: delref st->st_sk_d_no_ppk-key at NULL
Mar 28 17:25:03.327714: | delete_state: delref st->st_sk_pi_no_ppk-key at NULL
Mar 28 17:25:03.328215: | delete_state: delref st->st_sk_pr_no_ppk-key at NULL
Mar 28 17:25:03.328410: | #1: releasing whack (but there are none) (delete_state() +1171 programs/pluto/state.c)
Mar 28 17:25:03.328537: | logger: delref @0x563a78944668(1->0) (delete_state() +1171 programs/pluto/state.c)
Mar 28 17:25:03.328662: | "tunnel1"[1] 192.168.1.126 #1: routing: stop TEARDOWN_IKE, UNROUTED, INSTANCE; ok=yes (complete_v2_state_transition() +2823 programs/pluto/ikev2.c)
Mar 28 17:25:03.328848: | "tunnel1"[1] 192.168.1.126: delref @0x563a7894bee8(2->1) "tunnel1"[1] 192.168.1.126 #1: (dispatch() +2450 programs/pluto/routing.c)
Mar 28 17:25:03.329012: | "tunnel1"[1] 192.168.1.126 #1: releasing whack (but there are none) (teardown_ike() +1290 programs/pluto/routing.c)
Mar 28 17:25:03.329799: | logger: delref @0x563a78943db8(1->0) (teardown_ike() +1290 programs/pluto/routing.c)
Mar 28 17:25:03.329888: | in statetime_stop() and could not find #1
Mar 28 17:25:03.329940: | in statetime_stop() and could not find #1
Mar 28 17:25:03.330090: | "tunnel1"[1] 192.168.1.126: delref @0x563a7894bee8(1->0) packet from 192.168.1.126:59964: (process_v2_IKE_SA_INIT() +449 programs/pluto/ikev2_ike_sa_init.c)
Mar 28 17:25:03.330219: "tunnel1"[1] 192.168.1.126: deleting connection instance with peer 192.168.1.126
Mar 28 17:25:03.331847: | clone logger: newref @0x563a78943db8(0->1) (process_v2_IKE_SA_INIT() +449 programs/pluto/ikev2_ike_sa_init.c)
Mar 28 17:25:03.331907: | discard_connection() tunnel1 $2 [0x563a7894bee8] cloned from $1
Mar 28 17:25:03.332049: | "tunnel1"[1] 192.168.1.126: peekref @0x563a7894bee8(0->0) (connection_ok_to_delete() +311 programs/pluto/connections.c)
Mar 28 17:25:03.332174: | FOR_EACH_CONNECTION[clonedfrom=$2].... in (connection_ok_to_delete() +345 programs/pluto/connections.c)
Mar 28 17:25:03.333848: | matches: 0
Mar 28 17:25:03.333915: | FOR_EACH_STATE[connection_serialno=$2]... in (connection_ok_to_delete() +364 programs/pluto/connections.c)
Mar 28 17:25:03.333961: | matches: 0
Mar 28 17:25:03.334004: | delref @0x563a78948838(5->4) (disorient() +49 programs/pluto/orient.c)
Mar 28 17:25:03.334912: | "tunnel1"[1] 192.168.1.126: 192.168.1.10->192.168.1.126 oriented=no
Mar 28 17:25:03.334974: | "tunnel1"[1] 192.168.1.126: releasing whack (but there are none) (process_v2_IKE_SA_INIT() +449 programs/pluto/ikev2_ike_sa_init.c)
Mar 28 17:25:03.335021: | logger: delref @0x563a78944b48(1->0) (process_v2_IKE_SA_INIT() +449 programs/pluto/ikev2_ike_sa_init.c)
Mar 28 17:25:03.335066: | "tunnel1": delref @0x563a78943438(2->1) "tunnel1"[1] 192.168.1.126: (discard_connection() +454 programs/pluto/connections.c)
Mar 28 17:25:03.335110: | "tunnel1"[1] 192.168.1.126: releasing whack (but there are none) (process_v2_IKE_SA_INIT() +449 programs/pluto/ikev2_ike_sa_init.c)
Mar 28 17:25:03.335600: | logger: delref @0x563a78943db8(1->0) (process_v2_IKE_SA_INIT() +449 programs/pluto/ikev2_ike_sa_init.c)
Mar 28 17:25:03.335657: | packet from 192.168.1.126:59964: delref @0x563a7894a418(1->0) (process_iface_packet() +296 programs/pluto/demux.c)
Mar 28 17:25:03.335704: | packet from 192.168.1.126:59964: releasing whack (but there are none) (process_iface_packet() +296 programs/pluto/demux.c)
Mar 28 17:25:03.335776: | logger: delref @0x563a78946448(1->0) (process_iface_packet() +296 programs/pluto/demux.c)
Mar 28 17:25:03.336037: | delref @0x563a789493d8(2->1) (process_iface_packet() +296 programs/pluto/demux.c)
Mar 28 17:25:03.336092: | spent 11 (64.9) milliseconds in process_iface_packet() reading and processing packet
Mar 28 17:25:03.336153: | spent 0.00343 (0.00342) milliseconds in udp_read_packet() calling check_incoming_msg_errqueue()
Mar 28 17:25:03.336214: | struct msg_digest: newref @0x563a7894a418(0->1) (udp_read_packet() +249 programs/pluto/iface_udp.c)
Mar 28 17:25:03.339489: | struct iface_endpoint: addref @0x563a789493d8(1->2) (udp_read_packet() +249 programs/pluto/iface_udp.c)
Mar 28 17:25:03.345389: | alloc logger: newref @0x563a78943db8(0->1) (udp_read_packet() +249 programs/pluto/iface_udp.c)
Mar 28 17:25:03.347857: | *received 460 bytes from 192.168.1.126:59964 on enp0s3 192.168.1.10:500 using UDP
Mar 28 17:25:03.347927: | 3b 78 77 0a dd f4 4e 5e 00 00 00 00 00 00 00 00 ;xw...N^........
Mar 28 17:25:03.347971: | 21 20 22 08 00 00 00 00 00 00 01 cc 22 00 00 f4 ! "........."...
Mar 28 17:25:03.348012: | 02 00 00 88 01 01 00 0f 03 00 00 0c 01 00 00 0c ................
Mar 28 17:25:03.348053: | 80 0e 01 00 03 00 00 0c 01 00 00 0c 80 0e 00 80 ................
Mar 28 17:25:03.348094: | 03 00 00 08 03 00 00 0e 03 00 00 08 03 00 00 0d ................
Mar 28 17:25:03.348167: | 03 00 00 08 03 00 00 0c 03 00 00 08 03 00 00 02 ................
Mar 28 17:25:03.348211: | 03 00 00 08 02 00 00 07 03 00 00 08 02 00 00 06 ................
Mar 28 17:25:03.348300: | 03 00 00 08 02 00 00 05 03 00 00 08 02 00 00 02 ................
Mar 28 17:25:03.348344: | 03 00 00 08 04 00 00 13 03 00 00 08 04 00 00 18 ................
Mar 28 17:25:03.348495: | 03 00 00 08 04 00 00 14 03 00 00 08 04 00 00 0e ................
Mar 28 17:25:03.348690: | 00 00 00 08 04 00 00 05 00 00 00 68 02 01 00 0b ...........h....
Mar 28 17:25:03.348742: | 03 00 00 0c 01 00 00 14 80 0e 01 00 03 00 00 0c ................
Mar 28 17:25:03.348925: | 01 00 00 14 80 0e 00 80 03 00 00 08 02 00 00 07 ................
Mar 28 17:25:03.349046: | 03 00 00 08 02 00 00 06 03 00 00 08 02 00 00 05 ................
Mar 28 17:25:03.349089: | 03 00 00 08 02 00 00 02 03 00 00 08 04 00 00 13 ................
Mar 28 17:25:03.349130: | 03 00 00 08 04 00 00 18 03 00 00 08 04 00 00 14 ................
Mar 28 17:25:03.349176: | 03 00 00 08 04 00 00 0e 00 00 00 08 04 00 00 05 ................
Mar 28 17:25:03.349315: | 28 00 00 48 00 13 00 00 83 8a 2b f2 65 88 f4 f0 (..H......+.e...
Mar 28 17:25:03.349882: | 6b b0 26 5b d0 53 f4 7a 35 e2 2a 64 0f f0 06 dc k.&[.S.z5.*d....
Mar 28 17:25:03.349937: | 49 19 4e 0a c9 7d 93 be 31 94 90 de e8 6e c1 46 I.N..}..1....n.F
Mar 28 17:25:03.349979: | b1 b8 39 57 67 61 51 7b cd 97 49 2f 95 0f ae 21 ..9WgaQ{..I/...!
Mar 28 17:25:03.351725: | 80 3a be f5 5e ba b1 d8 29 00 00 24 f5 61 ff a5 .:..^...)..$.a..
Mar 28 17:25:03.351792: | 30 b8 30 dc 6b 4d 12 05 f8 53 25 2b cf 9a f8 65 0.0.kM...S%+...e
Mar 28 17:25:03.351880: | 24 75 a1 5e af 95 2b 6c 25 30 74 df 29 00 00 1c $u.^..+l%0t.)...
Mar 28 17:25:03.351926: | 00 00 40 04 6b b9 09 53 28 24 96 2e 7c f2 a5 cb .. at .k..S($..|...
Mar 28 17:25:03.352076: | 11 5b 36 fc 38 5d a9 e1 29 00 00 1c 00 00 40 05 .[6.8]..)..... at .
Mar 28 17:25:03.352193: | 4c d8 c7 a9 e4 03 0f 9b 19 88 df b0 ce bb 42 14 L.............B.
Mar 28 17:25:03.352236: | f2 89 1a 33 29 00 00 10 00 00 40 2f 00 02 00 03 ...3).....@/....
Mar 28 17:25:03.352277: | 00 04 00 05 00 00 00 08 00 00 40 16 .......... at .
Mar 28 17:25:03.352320: | **parse ISAKMP Message:
Mar 28 17:25:03.352368: | initiator SPI: 3b 78 77 0a dd f4 4e 5e
Mar 28 17:25:03.352414: | responder SPI: 00 00 00 00 00 00 00 00
Mar 28 17:25:03.355509: | next payload type: ISAKMP_NEXT_v2SA (0x21)
Mar 28 17:25:03.356105: | ISAKMP version: IKEv2 version 2.0 (rfc4306/rfc5996) (0x20)
Mar 28 17:25:03.356153: | exchange type: ISAKMP_v2_IKE_SA_INIT (0x22)
Mar 28 17:25:03.356195: | flags: ISAKMP_FLAG_v2_IKE_INIT (0x8)
Mar 28 17:25:03.356240: | Message ID: 0 (00 00 00 00)
Mar 28 17:25:03.356283: | length: 460 (00 00 01 cc)
Mar 28 17:25:03.356325: | processing version=2.0 packet with exchange type=ISAKMP_v2_IKE_SA_INIT (34)
Mar 28 17:25:03.358876: | I am the IKE SA Original Responder receiving an IKEv2 IKE_SA_INIT request
Mar 28 17:25:03.358948: | State DB: IKEv2 state not found (find_v2_ike_sa_by_initiator_spi)
Mar 28 17:25:03.359012: | Now let's proceed with payload (ISAKMP_NEXT_v2SA)
Mar 28 17:25:03.359058: | ***parse IKEv2 Security Association Payload:
Mar 28 17:25:03.359223: | next payload type: ISAKMP_NEXT_v2KE (0x22)
Mar 28 17:25:03.360875: | flags: none (0x0)
Mar 28 17:25:03.360953: | length: 244 (00 f4)
Mar 28 17:25:03.362889: | processing payload: ISAKMP_NEXT_v2SA (len=240)
Mar 28 17:25:03.362962: | Now let's proceed with payload (ISAKMP_NEXT_v2KE)
Mar 28 17:25:03.363083: | ***parse IKEv2 Key Exchange Payload:
Mar 28 17:25:03.363201: | next payload type: ISAKMP_NEXT_v2Ni (0x28)
Mar 28 17:25:03.363250: | flags: none (0x0)
Mar 28 17:25:03.363293: | length: 72 (00 48)
Mar 28 17:25:03.363333: | DH group: OAKLEY_GROUP_ECP_256 (0x13)
Mar 28 17:25:03.363374: | processing payload: ISAKMP_NEXT_v2KE (len=64)
Mar 28 17:25:03.363417: | Now let's proceed with payload (ISAKMP_NEXT_v2Ni)
Mar 28 17:25:03.365621: | ***parse IKEv2 Nonce Payload:
Mar 28 17:25:03.365691: | next payload type: ISAKMP_NEXT_v2N (0x29)
Mar 28 17:25:03.365736: | flags: none (0x0)
Mar 28 17:25:03.365778: | length: 36 (00 24)
Mar 28 17:25:03.366004: | processing payload: ISAKMP_NEXT_v2Ni (len=32)
Mar 28 17:25:03.366064: | Now let's proceed with payload (ISAKMP_NEXT_v2N)
Mar 28 17:25:03.368908: | ***parse IKEv2 Notify Payload:
Mar 28 17:25:03.368981: | next payload type: ISAKMP_NEXT_v2N (0x29)
Mar 28 17:25:03.369027: | flags: none (0x0)
Mar 28 17:25:03.369072: | length: 28 (00 1c)
Mar 28 17:25:03.369113: | Protocol ID: IKEv2_SEC_PROTO_NONE (0x0)
Mar 28 17:25:03.369154: | SPI size: 0 (00)
Mar 28 17:25:03.370837: | Notify Message Type: v2N_NAT_DETECTION_SOURCE_IP (0x4004)
Mar 28 17:25:03.370893: | processing payload: ISAKMP_NEXT_v2N (len=20)
Mar 28 17:25:03.370936: | Now let's proceed with payload (ISAKMP_NEXT_v2N)
Mar 28 17:25:03.370977: | ***parse IKEv2 Notify Payload:
Mar 28 17:25:03.371153: | next payload type: ISAKMP_NEXT_v2N (0x29)
Mar 28 17:25:03.371200: | flags: none (0x0)
Mar 28 17:25:03.371246: | length: 28 (00 1c)
Mar 28 17:25:03.371286: | Protocol ID: IKEv2_SEC_PROTO_NONE (0x0)
Mar 28 17:25:03.371327: | SPI size: 0 (00)
Mar 28 17:25:03.371368: | Notify Message Type: v2N_NAT_DETECTION_DESTINATION_IP (0x4005)
Mar 28 17:25:03.371412: | processing payload: ISAKMP_NEXT_v2N (len=20)
Mar 28 17:25:03.371453: | Now let's proceed with payload (ISAKMP_NEXT_v2N)
Mar 28 17:25:03.371495: | ***parse IKEv2 Notify Payload:
Mar 28 17:25:03.371535: | next payload type: ISAKMP_NEXT_v2N (0x29)
Mar 28 17:25:03.371576: | flags: none (0x0)
Mar 28 17:25:03.373907: | length: 16 (00 10)
Mar 28 17:25:03.376043: | Protocol ID: IKEv2_SEC_PROTO_NONE (0x0)
Mar 28 17:25:03.376115: | SPI size: 0 (00)
Mar 28 17:25:03.376168: | Notify Message Type: v2N_SIGNATURE_HASH_ALGORITHMS (0x402f)
Mar 28 17:25:03.376213: | processing payload: ISAKMP_NEXT_v2N (len=8)
Mar 28 17:25:03.376254: | Now let's proceed with payload (ISAKMP_NEXT_v2N)
Mar 28 17:25:03.376467: | ***parse IKEv2 Notify Payload:
Mar 28 17:25:03.376517: | next payload type: ISAKMP_NEXT_v2NONE (0x0)
Mar 28 17:25:03.376531: | flags: none (0x0)
Mar 28 17:25:03.376616: | length: 8 (00 08)
Mar 28 17:25:03.376631: | Protocol ID: IKEv2_SEC_PROTO_NONE (0x0)
Mar 28 17:25:03.376641: | SPI size: 0 (00)
Mar 28 17:25:03.376651: | Notify Message Type: v2N_REDIRECT_SUPPORTED (0x4016)
Mar 28 17:25:03.376661: | processing payload: ISAKMP_NEXT_v2N (len=0)
Mar 28 17:25:03.376674: | DDOS disabled and no cookie sent, continuing
Mar 28 17:25:03.376691: | looking for transition from PARENT_R0 matching IKE_SA_INIT request: SA,KE,Ni,N(NAT_DETECTION_SOURCE_IP),N(NAT_DETECTION_DESTINATION_IP),N(SIGNATURE_HASH_ALGORITHMS),N(REDIRECT_SUPPORTED)
Mar 28 17:25:03.376701: | trying: Respond to IKE_SA_INIT
Mar 28 17:25:03.376710: | unsecured message matched
Mar 28 17:25:03.376727: | ikev2_find_host_connection() 192.168.1.126->192.168.1.10 remote_authby=ECDSA
Mar 28 17:25:03.376767: | FOR_EACH_CONNECTION[local=192.168.1.10,remote=192.168.1.126].... in (ikev2_find_host_connection() +139 programs/pluto/ikev2_host_pair.c)
Mar 28 17:25:03.376781: | matches: 0
Mar 28 17:25:03.376794: | FOR_EACH_CONNECTION[local=192.168.1.10,remote=<unset-address>].... in (ikev2_find_host_connection() +214 programs/pluto/ikev2_host_pair.c)
Mar 28 17:25:03.376821: | found "tunnel1"
Mar 28 17:25:03.376833: | skipping "tunnel1", PSK missing required authby ECDSA
Mar 28 17:25:03.376842: | matches: 1
Mar 28 17:25:03.376856: | ISAKMP_v2_IKE_SA_INIT message received on 192.168.1.10:500 but no connection has been authorized with policy ECDSA, sending reject response
Mar 28 17:25:03.376871: | ikev2_find_host_connection() 192.168.1.126->192.168.1.10 remote_authby=RSASIG
Mar 28 17:25:03.376886: | FOR_EACH_CONNECTION[local=192.168.1.10,remote=192.168.1.126].... in (ikev2_find_host_connection() +139 programs/pluto/ikev2_host_pair.c)
Mar 28 17:25:03.376896: | matches: 0
Mar 28 17:25:03.376908: | FOR_EACH_CONNECTION[local=192.168.1.10,remote=<unset-address>].... in (ikev2_find_host_connection() +214 programs/pluto/ikev2_host_pair.c)
Mar 28 17:25:03.376918: | found "tunnel1"
Mar 28 17:25:03.376928: | skipping "tunnel1", PSK missing required authby RSASIG
Mar 28 17:25:03.376939: | matches: 1
Mar 28 17:25:03.376956: | ISAKMP_v2_IKE_SA_INIT message received on 192.168.1.10:500 but no connection has been authorized with policy RSASIG, sending reject response
Mar 28 17:25:03.376973: | ikev2_find_host_connection() 192.168.1.126->192.168.1.10 remote_authby=RSASIG_v1_5
Mar 28 17:25:03.377110: | FOR_EACH_CONNECTION[local=192.168.1.10,remote=192.168.1.126].... in (ikev2_find_host_connection() +139 programs/pluto/ikev2_host_pair.c)
Mar 28 17:25:03.377124: | matches: 0
Mar 28 17:25:03.377140: | FOR_EACH_CONNECTION[local=192.168.1.10,remote=<unset-address>].... in (ikev2_find_host_connection() +214 programs/pluto/ikev2_host_pair.c)
Mar 28 17:25:03.377151: | found "tunnel1"
Mar 28 17:25:03.377162: | skipping "tunnel1", PSK missing required authby RSASIG_v1_5
Mar 28 17:25:03.377171: | matches: 1
Mar 28 17:25:03.377184: | ISAKMP_v2_IKE_SA_INIT message received on 192.168.1.10:500 but no connection has been authorized with policy RSASIG_v1_5, sending reject response
Mar 28 17:25:03.377199: | ikev2_find_host_connection() 192.168.1.126->192.168.1.10 remote_authby=PSK
Mar 28 17:25:03.377214: | FOR_EACH_CONNECTION[local=192.168.1.10,remote=192.168.1.126].... in (ikev2_find_host_connection() +139 programs/pluto/ikev2_host_pair.c)
Mar 28 17:25:03.377224: | matches: 0
Mar 28 17:25:03.377236: | FOR_EACH_CONNECTION[local=192.168.1.10,remote=<unset-address>].... in (ikev2_find_host_connection() +214 programs/pluto/ikev2_host_pair.c)
Mar 28 17:25:03.377246: | found "tunnel1"
Mar 28 17:25:03.377256: | instant winner with non-opportunistic template "tunnel1"
Mar 28 17:25:03.377265: | instantiate roadwarrior winner "tunnel1"
Mar 28 17:25:03.377281: | "tunnel1": rw_responder_instantiate: remote=192.168.1.126 id=<null-id> kind=TEMPLATE sec_label= (ikev2_find_host_connection() +319 programs/pluto/ikev2_host_pair.c)
Mar 28 17:25:03.377292: | connection $1: "tunnel1"
Mar 28 17:25:03.377301: | routing+kind: UNROUTED TEMPLATE
Mar 28 17:25:03.377315: | host: 192.168.1.10->0.0.0.0
Mar 28 17:25:03.377328: | selectors: 192.168.10.0/24 -> <unset-selector>
Mar 28 17:25:03.377337: | spds: <unset-selectors>
Mar 28 17:25:03.377349: | policy: IKEv2+PSK+ENCRYPT+TUNNEL+PFS+IKE_FRAG_ALLOW+ESN_NO+ESN_YES
Mar 28 17:25:03.377364: | struct connection: newref @0x563a7894be28(0->1) (ikev2_find_host_connection() +319 programs/pluto/ikev2_host_pair.c)
Mar 28 17:25:03.377379: | alloc logger: newref @0x563a78944b48(0->1) (ikev2_find_host_connection() +319 programs/pluto/ikev2_host_pair.c)
Mar 28 17:25:03.377389: | "tunnel1"[2]: no whack to attach
Mar 28 17:25:03.377398: | "tunnel1": template .instance_serial_next updated to 3; instance 2
Mar 28 17:25:03.377412: | "tunnel1": addref @0x563a78943438(1->2) "tunnel1"[2] <unset-address>: (alloc_connection() +2100 programs/pluto/connections.c)
Mar 28 17:25:03.377424: | struct iface: addref @0x563a78948838(4->5) (duplicate_connection() +78 programs/pluto/instantiate.c)
Mar 28 17:25:03.377435: | left.child.has_client: no -> yes (duplicate_connection() +87 programs/pluto/instantiate.c)
Mar 28 17:25:03.377460: | right.child.has_client: no -> no (duplicate_connection() +87 programs/pluto/instantiate.c)
Mar 28 17:25:03.377473: | updating host ends from right.host.addr 192.168.1.126
Mar 28 17:25:03.377483: | updated right.host_port from 0 to 500
Mar 28 17:25:03.377497: | updated left.host_nexthop from 0.0.0.0 to 192.168.1.126
Mar 28 17:25:03.377511: | "tunnel1"[2] 192.168.1.126: tunnel1 .child.reqid=16396 because t.config.sa_requid=0 (generate)
Mar 28 17:25:03.377546: | "tunnel1"[2] 192.168.1.126: 192.168.1.10->192.168.1.126 oriented=yes
Mar 28 17:25:03.377560: | update_selectors() left selectors from 1 child.selectors
Mar 28 17:25:03.377570: | update_selectors() right.child selector formed from host address+protoport
Mar 28 17:25:03.377585: | append_end_selector() right.child.selectors.proposed[0] 192.168.1.126/32 (update_selectors() +397 programs/pluto/instantiate.c)
Mar 28 17:25:03.377595: | adding connection spds using proposed
Mar 28 17:25:03.377604: | left=1 right=1
Mar 28 17:25:03.377614: | left[IPv4]=1 right[IPv4]=1
Mar 28 17:25:03.377624: | left[IPv6]=0 right[IPv6]=0
Mar 28 17:25:03.377633: | allocating 1 SPDs
Mar 28 17:25:03.377650: | 192.168.10.0/24===192.168.1.126/32
Mar 28 17:25:03.377663: | left child spd from selector 192.168.10.0/24 left.spd.has_client=yes virt=no
Mar 28 17:25:03.377676: | right child spd from selector 192.168.1.126/32 right.spd.has_client=no virt=no
Mar 28 17:25:03.377767: | "tunnel1"[2] 192.168.1.126: rw_responder_instantiate: from "tunnel1" (ikev2_find_host_connection() +319 programs/pluto/ikev2_host_pair.c)
Mar 28 17:25:03.377780: | connection $3 clonedfrom $1: "tunnel1"[2] 192.168.1.126
Mar 28 17:25:03.377790: | routing+kind: UNROUTED INSTANCE
Mar 28 17:25:03.377807: | host: 192.168.1.10->192.168.1.126
Mar 28 17:25:03.377822: | selectors: 192.168.10.0/24 -> 192.168.1.126/32
Mar 28 17:25:03.377839: | spds: 192.168.10.0/24===192.168.1.126/32
Mar 28 17:25:03.377887: | policy: IKEv2+PSK+ENCRYPT+TUNNEL+PFS+IKE_FRAG_ALLOW+ESN_NO+ESN_YES
Mar 28 17:25:03.377906: | found connection: "tunnel1"[2] 192.168.1.126 with remote authby PSK
Mar 28 17:25:03.377918: | struct iface_endpoint: addref @0x563a789493d8(2->3) (get_responder_endpoints() +610 programs/pluto/state.c)
Mar 28 17:25:03.377960: | alloc logger: newref @0x563a78944668(0->1) (new_v2_ike_sa() +666 programs/pluto/state.c)
Mar 28 17:25:03.377971: | #0: no whack to attach
Mar 28 17:25:03.377986: | "tunnel1"[2] 192.168.1.126: addref @0x563a7894be28(1->2) #2: (new_state() +491 programs/pluto/state.c)
Mar 28 17:25:03.377997: | creating state object #2 at 0x563a7894c3d8
Mar 28 17:25:03.378016: | pstats #2 ikev2.ike started
Mar 28 17:25:03.378027: | parent state #2: UNDEFINED(ignore) => PARENT_R0(half-open IKE SA)
Mar 28 17:25:03.378040: | #2.st_v2_transition NULL -> PARENT_R0->PARENT_R1 (new_v2_ike_sa() +669 programs/pluto/state.c)
Mar 28 17:25:03.378068: | Message ID: IKE #2 initializing (initiator: .sent=0->-1 .recv=0->-1 .wip=0->-1 .last_sent=0->989.672257 .last_recv=0->989.672257 responder: .sent=0->-1 .recv=0->-1 .wip=0->-1 .last_sent=0->989.672257 .last_recv=0->989.672257)
Mar 28 17:25:03.378081: | event_schedule_where: newref EVENT_v2_DISCARD-pe at 0x563a78948248 timeout in 200 seconds for #2
Mar 28 17:25:03.378093: | tt: newref @0x563a78948408(0->1) (schedule_timeout() +557 programs/pluto/server.c)
Mar 28 17:25:03.378116: | #2 spent 4.33 (42) milliseconds
Mar 28 17:25:03.378128: | #2.st_v2_transition PARENT_R0->PARENT_R1 -> PARENT_R0->PARENT_R1 (v2_dispatch() +2308 programs/pluto/ikev2.c)
Mar 28 17:25:03.378151: | Message ID: IKE #2 responder starting message request 0 (initiator: .sent=-1 .recv=-1 .recv_frags=0 .wip=-1 .last_sent=989.672257 .last_recv=989.672257 responder: .sent=-1 .recv=-1 .recv_frags=0 .wip=0 .last_sent=989.672257 .last_recv=989.672257)
Mar 28 17:25:03.378162: | calling processor Respond to IKE_SA_INIT
Mar 28 17:25:03.378179: | #2 spent 4.4 (42) milliseconds
Mar 28 17:25:03.378293: | #2 updating local interface from 192.168.1.10:500 to 192.168.1.10:500 using md->iface (update_ike_endpoints() +1714 programs/pluto/state.c)
Mar 28 17:25:03.378309: | delref @0x563a789493d8(3->2) (update_ike_endpoints() +1719 programs/pluto/state.c)
Mar 28 17:25:03.378321: | struct iface_endpoint: addref @0x563a789493d8(2->3) (update_ike_endpoints() +1720 programs/pluto/state.c)
Mar 28 17:25:03.378331: | comparing remote proposals against IKE responder 5 local proposals
Mar 28 17:25:03.378350: | local proposal 1 type ENCR has 1 transforms
Mar 28 17:25:03.378373: | local proposal 1 type PRF has 2 transforms
Mar 28 17:25:03.378384: | local proposal 1 type INTEG has 1 transforms
Mar 28 17:25:03.378394: | local proposal 1 type DH has 8 transforms
Mar 28 17:25:03.378404: | local proposal 1 type ESN has 0 transforms
Mar 28 17:25:03.378414: | local proposal 1 transforms: required: ENCR+PRF+DH; optional: INTEG
Mar 28 17:25:03.378424: | local proposal 2 type ENCR has 1 transforms
Mar 28 17:25:03.378434: | local proposal 2 type PRF has 2 transforms
Mar 28 17:25:03.378444: | local proposal 2 type INTEG has 1 transforms
Mar 28 17:25:03.378454: | local proposal 2 type DH has 8 transforms
Mar 28 17:25:03.378463: | local proposal 2 type ESN has 0 transforms
Mar 28 17:25:03.378474: | local proposal 2 transforms: required: ENCR+PRF+DH; optional: INTEG
Mar 28 17:25:03.378484: | local proposal 3 type ENCR has 1 transforms
Mar 28 17:25:03.378508: | local proposal 3 type PRF has 2 transforms
Mar 28 17:25:03.378523: | local proposal 3 type INTEG has 1 transforms
Mar 28 17:25:03.378533: | local proposal 3 type DH has 8 transforms
Mar 28 17:25:03.378543: | local proposal 3 type ESN has 0 transforms
Mar 28 17:25:03.378580: | local proposal 3 transforms: required: ENCR+PRF+DH; optional: INTEG
Mar 28 17:25:03.378591: | local proposal 4 type ENCR has 1 transforms
Mar 28 17:25:03.378601: | local proposal 4 type PRF has 2 transforms
Mar 28 17:25:03.378613: | local proposal 4 type INTEG has 2 transforms
Mar 28 17:25:03.378648: | local proposal 4 type DH has 8 transforms
Mar 28 17:25:03.378660: | local proposal 4 type ESN has 0 transforms
Mar 28 17:25:03.378671: | local proposal 4 transforms: required: ENCR+PRF+INTEG+DH; optional: none
Mar 28 17:25:03.378681: | local proposal 5 type ENCR has 1 transforms
Mar 28 17:25:03.378690: | local proposal 5 type PRF has 2 transforms
Mar 28 17:25:03.378700: | local proposal 5 type INTEG has 2 transforms
Mar 28 17:25:03.378710: | local proposal 5 type DH has 8 transforms
Mar 28 17:25:03.399090: | local proposal 5 type ESN has 0 transforms
Mar 28 17:25:03.399198: | local proposal 5 transforms: required: ENCR+PRF+INTEG+DH; optional: none
Mar 28 17:25:03.399248: | ****parse IKEv2 Proposal Substructure Payload:
Mar 28 17:25:03.399291: | last proposal: v2_PROPOSAL_NON_LAST (0x2)
Mar 28 17:25:03.399336: | length: 136 (00 88)
Mar 28 17:25:03.399378: | prop #: 1 (01)
Mar 28 17:25:03.399583: | proto ID: IKEv2_SEC_PROTO_IKE (0x1)
Mar 28 17:25:03.399646: | spi size: 0 (00)
Mar 28 17:25:03.399854: | # transforms: 15 (0f)
Mar 28 17:25:03.399994: | Comparing remote proposal 1 containing 15 transforms against local proposal [1..5] of 5 local proposals
Mar 28 17:25:03.401848: | *****parse IKEv2 Transform Substructure Payload:
Mar 28 17:25:03.401906: | last transform: v2_TRANSFORM_NON_LAST (0x3)
Mar 28 17:25:03.401972: | length: 12 (00 0c)
Mar 28 17:25:03.403892: | IKEv2 transform type: IKEv2_TRANS_TYPE_ENCR (0x1)
Mar 28 17:25:03.403952: | IKEv2 transform ID: AES_CBC (0xc)
Mar 28 17:25:03.404068: | ******parse IKEv2 Attribute Substructure Payload:
Mar 28 17:25:03.404267: | af+type: AF+IKEv2_KEY_LENGTH (0x800e)
Mar 28 17:25:03.404313: | length/value: 256 (01 00)
Mar 28 17:25:03.404359: | remote proposal 1 transform 0 (ENCR=AES_CBC_256) matches local proposal 4 type 1 (ENCR) transform 0
Mar 28 17:25:03.404406: | *****parse IKEv2 Transform Substructure Payload:
Mar 28 17:25:03.404539: | last transform: v2_TRANSFORM_NON_LAST (0x3)
Mar 28 17:25:03.404586: | length: 12 (00 0c)
Mar 28 17:25:03.404761: | IKEv2 transform type: IKEv2_TRANS_TYPE_ENCR (0x1)
Mar 28 17:25:03.406865: | IKEv2 transform ID: AES_CBC (0xc)
Mar 28 17:25:03.406937: | ******parse IKEv2 Attribute Substructure Payload:
Mar 28 17:25:03.407128: | af+type: AF+IKEv2_KEY_LENGTH (0x800e)
Mar 28 17:25:03.407196: | length/value: 128 (00 80)
Mar 28 17:25:03.407241: | remote proposal 1 transform 1 (ENCR=AES_CBC_128) matches local proposal 5 type 1 (ENCR) transform 0
Mar 28 17:25:03.407522: | *****parse IKEv2 Transform Substructure Payload:
Mar 28 17:25:03.409097: | last transform: v2_TRANSFORM_NON_LAST (0x3)
Mar 28 17:25:03.409157: | length: 8 (00 08)
Mar 28 17:25:03.409278: | IKEv2 transform type: IKEv2_TRANS_TYPE_INTEG (0x3)
Mar 28 17:25:03.409328: | IKEv2 transform ID: AUTH_HMAC_SHA2_512_256 (0xe)
Mar 28 17:25:03.409489: | remote proposal 1 transform 2 (INTEG=HMAC_SHA2_512_256) matches local proposal 4 type 3 (INTEG) transform 0
Mar 28 17:25:03.411757: | remote proposal 1 transform 2 (INTEG=HMAC_SHA2_512_256) matches local proposal 5 type 3 (INTEG) transform 0
Mar 28 17:25:03.411856: | *****parse IKEv2 Transform Substructure Payload:
Mar 28 17:25:03.411903: | last transform: v2_TRANSFORM_NON_LAST (0x3)
Mar 28 17:25:03.411947: | length: 8 (00 08)
Mar 28 17:25:03.411987: | IKEv2 transform type: IKEv2_TRANS_TYPE_INTEG (0x3)
Mar 28 17:25:03.412027: | IKEv2 transform ID: AUTH_HMAC_SHA2_384_192 (0xd)
Mar 28 17:25:03.412069: | *****parse IKEv2 Transform Substructure Payload:
Mar 28 17:25:03.412114: | last transform: v2_TRANSFORM_NON_LAST (0x3)
Mar 28 17:25:03.412163: | length: 8 (00 08)
Mar 28 17:25:03.412204: | IKEv2 transform type: IKEv2_TRANS_TYPE_INTEG (0x3)
Mar 28 17:25:03.412244: | IKEv2 transform ID: AUTH_HMAC_SHA2_256_128 (0xc)
Mar 28 17:25:03.413837: | *****parse IKEv2 Transform Substructure Payload:
Mar 28 17:25:03.413976: | last transform: v2_TRANSFORM_NON_LAST (0x3)
Mar 28 17:25:03.414190: | length: 8 (00 08)
Mar 28 17:25:03.414236: | IKEv2 transform type: IKEv2_TRANS_TYPE_INTEG (0x3)
Mar 28 17:25:03.414440: | IKEv2 transform ID: AUTH_HMAC_SHA1_96 (0x2)
Mar 28 17:25:03.414494: | *****parse IKEv2 Transform Substructure Payload:
Mar 28 17:25:03.414537: | last transform: v2_TRANSFORM_NON_LAST (0x3)
Mar 28 17:25:03.414605: | length: 8 (00 08)
Mar 28 17:25:03.414668: | IKEv2 transform type: IKEv2_TRANS_TYPE_PRF (0x2)
Mar 28 17:25:03.414714: | IKEv2 transform ID: PRF_HMAC_SHA2_512 (0x7)
Mar 28 17:25:03.414790: | remote proposal 1 transform 6 (PRF=HMAC_SHA2_512) matches local proposal 1 type 2 (PRF) transform 0
Mar 28 17:25:03.416848: | remote proposal 1 transform 6 (PRF=HMAC_SHA2_512) matches local proposal 2 type 2 (PRF) transform 0
Mar 28 17:25:03.416962: | remote proposal 1 transform 6 (PRF=HMAC_SHA2_512) matches local proposal 3 type 2 (PRF) transform 0
Mar 28 17:25:03.417013: | remote proposal 1 transform 6 (PRF=HMAC_SHA2_512) matches local proposal 4 type 2 (PRF) transform 0
Mar 28 17:25:03.419539: | remote proposal 1 transform 6 (PRF=HMAC_SHA2_512) matches local proposal 5 type 2 (PRF) transform 0
Mar 28 17:25:03.421884: | *****parse IKEv2 Transform Substructure Payload:
Mar 28 17:25:03.421951: | last transform: v2_TRANSFORM_NON_LAST (0x3)
Mar 28 17:25:03.421997: | length: 8 (00 08)
Mar 28 17:25:03.422038: | IKEv2 transform type: IKEv2_TRANS_TYPE_PRF (0x2)
Mar 28 17:25:03.422079: | IKEv2 transform ID: PRF_HMAC_SHA2_384 (0x6)
Mar 28 17:25:03.422121: | *****parse IKEv2 Transform Substructure Payload:
Mar 28 17:25:03.422163: | last transform: v2_TRANSFORM_NON_LAST (0x3)
Mar 28 17:25:03.422205: | length: 8 (00 08)
Mar 28 17:25:03.423847: | IKEv2 transform type: IKEv2_TRANS_TYPE_PRF (0x2)
Mar 28 17:25:03.423905: | IKEv2 transform ID: PRF_HMAC_SHA2_256 (0x5)
Mar 28 17:25:03.423960: | *****parse IKEv2 Transform Substructure Payload:
Mar 28 17:25:03.424222: | last transform: v2_TRANSFORM_NON_LAST (0x3)
Mar 28 17:25:03.424271: | length: 8 (00 08)
Mar 28 17:25:03.425841: | IKEv2 transform type: IKEv2_TRANS_TYPE_PRF (0x2)
Mar 28 17:25:03.425898: | IKEv2 transform ID: PRF_HMAC_SHA1 (0x2)
Mar 28 17:25:03.426068: | *****parse IKEv2 Transform Substructure Payload:
Mar 28 17:25:03.427360: | last transform: v2_TRANSFORM_NON_LAST (0x3)
Mar 28 17:25:03.427428: | length: 8 (00 08)
Mar 28 17:25:03.427471: | IKEv2 transform type: IKEv2_TRANS_TYPE_DH (0x4)
Mar 28 17:25:03.427512: | IKEv2 transform ID: OAKLEY_GROUP_ECP_256 (0x13)
Mar 28 17:25:03.427555: | remote proposal 1 transform 10 (DH=ECP_256) matches local proposal 1 type 4 (DH) transform 0
Mar 28 17:25:03.427598: | remote proposal 1 transform 10 (DH=ECP_256) matches local proposal 2 type 4 (DH) transform 0
Mar 28 17:25:03.427641: | remote proposal 1 transform 10 (DH=ECP_256) matches local proposal 3 type 4 (DH) transform 0
Mar 28 17:25:03.427708: | remote proposal 1 transform 10 (DH=ECP_256) matches local proposal 4 type 4 (DH) transform 0
Mar 28 17:25:03.427759: | remote proposal 1 transform 10 (DH=ECP_256) matches local proposal 5 type 4 (DH) transform 0
Mar 28 17:25:03.427802: | *****parse IKEv2 Transform Substructure Payload:
Mar 28 17:25:03.427843: | last transform: v2_TRANSFORM_NON_LAST (0x3)
Mar 28 17:25:03.427885: | length: 8 (00 08)
Mar 28 17:25:03.427925: | IKEv2 transform type: IKEv2_TRANS_TYPE_DH (0x4)
Mar 28 17:25:03.427965: | IKEv2 transform ID: OAKLEY_GROUP_DH24 (0x18)
Mar 28 17:25:03.428007: | *****parse IKEv2 Transform Substructure Payload:
Mar 28 17:25:03.428047: | last transform: v2_TRANSFORM_NON_LAST (0x3)
Mar 28 17:25:03.428089: | length: 8 (00 08)
Mar 28 17:25:03.428129: | IKEv2 transform type: IKEv2_TRANS_TYPE_DH (0x4)
Mar 28 17:25:03.428170: | IKEv2 transform ID: OAKLEY_GROUP_ECP_384 (0x14)
Mar 28 17:25:03.428211: | *****parse IKEv2 Transform Substructure Payload:
Mar 28 17:25:03.428342: | last transform: v2_TRANSFORM_NON_LAST (0x3)
Mar 28 17:25:03.428395: | length: 8 (00 08)
Mar 28 17:25:03.429323: | IKEv2 transform type: IKEv2_TRANS_TYPE_DH (0x4)
Mar 28 17:25:03.431272: | IKEv2 transform ID: OAKLEY_GROUP_MODP2048 (0xe)
Mar 28 17:25:03.431340: | *****parse IKEv2 Transform Substructure Payload:
Mar 28 17:25:03.431385: | last transform: v2_TRANSFORM_LAST (0x0)
Mar 28 17:25:03.431428: | length: 8 (00 08)
Mar 28 17:25:03.431729: | IKEv2 transform type: IKEv2_TRANS_TYPE_DH (0x4)
Mar 28 17:25:03.438507: | IKEv2 transform ID: OAKLEY_GROUP_MODP1536 (0x5)
Mar 28 17:25:03.438614: | remote proposal 1 proposed transforms: ENCR+PRF+INTEG+DH; matched: ENCR+PRF+INTEG+DH; unmatched: none
Mar 28 17:25:03.438673: | comparing remote proposal 1 containing ENCR+PRF+INTEG+DH transforms to local proposal 1; required: ENCR+PRF+DH; optional: INTEG; matched: PRF+DH
Mar 28 17:25:03.438720: | remote proposal 1 does not match local proposal 1; unmatched transforms: ENCR+INTEG; missing transforms: ENCR
Mar 28 17:25:03.438802: | comparing remote proposal 1 containing ENCR+PRF+INTEG+DH transforms to local proposal 2; required: ENCR+PRF+DH; optional: INTEG; matched: PRF+DH
Mar 28 17:25:03.439082: | remote proposal 1 does not match local proposal 2; unmatched transforms: ENCR+INTEG; missing transforms: ENCR
Mar 28 17:25:03.439139: | comparing remote proposal 1 containing ENCR+PRF+INTEG+DH transforms to local proposal 3; required: ENCR+PRF+DH; optional: INTEG; matched: PRF+DH
Mar 28 17:25:03.439352: | remote proposal 1 does not match local proposal 3; unmatched transforms: ENCR+INTEG; missing transforms: ENCR
Mar 28 17:25:03.439484: | comparing remote proposal 1 containing ENCR+PRF+INTEG+DH transforms to local proposal 4; required: ENCR+PRF+INTEG+DH; optional: none; matched: ENCR+PRF+INTEG+DH
Mar 28 17:25:03.439603: | remote proposal 1 matches local proposal 4
Mar 28 17:25:03.439762: | ****parse IKEv2 Proposal Substructure Payload:
Mar 28 17:25:03.440900: | last proposal: v2_PROPOSAL_LAST (0x0)
Mar 28 17:25:03.442875: | length: 104 (00 68)
Mar 28 17:25:03.444955: | prop #: 2 (02)
Mar 28 17:25:03.445003: | proto ID: IKEv2_SEC_PROTO_IKE (0x1)
Mar 28 17:25:03.445045: | spi size: 0 (00)
Mar 28 17:25:03.445192: | # transforms: 11 (0b)
Mar 28 17:25:03.445418: | Comparing remote proposal 2 containing 11 transforms against local proposal [1..3] of 5 local proposals
Mar 28 17:25:03.447884: | *****parse IKEv2 Transform Substructure Payload:
Mar 28 17:25:03.447939: | last transform: v2_TRANSFORM_NON_LAST (0x3)
Mar 28 17:25:03.447976: | length: 12 (00 0c)
Mar 28 17:25:03.448016: | IKEv2 transform type: IKEv2_TRANS_TYPE_ENCR (0x1)
Mar 28 17:25:03.448060: | IKEv2 transform ID: AES_GCM_C (0x14)
Mar 28 17:25:03.448101: | ******parse IKEv2 Attribute Substructure Payload:
Mar 28 17:25:03.448276: | af+type: AF+IKEv2_KEY_LENGTH (0x800e)
Mar 28 17:25:03.448323: | length/value: 256 (01 00)
Mar 28 17:25:03.448441: | remote proposal 2 transform 0 (ENCR=AES_GCM_C_256) matches local proposal 1 type 1 (ENCR) transform 0
Mar 28 17:25:03.448485: | *****parse IKEv2 Transform Substructure Payload:
Mar 28 17:25:03.448628: | last transform: v2_TRANSFORM_NON_LAST (0x3)
Mar 28 17:25:03.448908: | length: 12 (00 0c)
Mar 28 17:25:03.449044: | IKEv2 transform type: IKEv2_TRANS_TYPE_ENCR (0x1)
Mar 28 17:25:03.449087: | IKEv2 transform ID: AES_GCM_C (0x14)
Mar 28 17:25:03.449135: | ******parse IKEv2 Attribute Substructure Payload:
Mar 28 17:25:03.449356: | af+type: AF+IKEv2_KEY_LENGTH (0x800e)
Mar 28 17:25:03.451813: | length/value: 128 (00 80)
Mar 28 17:25:03.451873: | remote proposal 2 transform 1 (ENCR=AES_GCM_C_128) matches local proposal 2 type 1 (ENCR) transform 0
Mar 28 17:25:03.453732: | *****parse IKEv2 Transform Substructure Payload:
Mar 28 17:25:03.453867: | last transform: v2_TRANSFORM_NON_LAST (0x3)
Mar 28 17:25:03.453910: | length: 8 (00 08)
Mar 28 17:25:03.453949: | IKEv2 transform type: IKEv2_TRANS_TYPE_PRF (0x2)
Mar 28 17:25:03.453988: | IKEv2 transform ID: PRF_HMAC_SHA2_512 (0x7)
Mar 28 17:25:03.454030: | remote proposal 2 transform 2 (PRF=HMAC_SHA2_512) matches local proposal 1 type 2 (PRF) transform 0
Mar 28 17:25:03.454072: | remote proposal 2 transform 2 (PRF=HMAC_SHA2_512) matches local proposal 2 type 2 (PRF) transform 0
Mar 28 17:25:03.454114: | remote proposal 2 transform 2 (PRF=HMAC_SHA2_512) matches local proposal 3 type 2 (PRF) transform 0
Mar 28 17:25:03.454155: | *****parse IKEv2 Transform Substructure Payload:
Mar 28 17:25:03.454194: | last transform: v2_TRANSFORM_NON_LAST (0x3)
Mar 28 17:25:03.454235: | length: 8 (00 08)
Mar 28 17:25:03.454273: | IKEv2 transform type: IKEv2_TRANS_TYPE_PRF (0x2)
Mar 28 17:25:03.456448: | IKEv2 transform ID: PRF_HMAC_SHA2_384 (0x6)
Mar 28 17:25:03.456505: | *****parse IKEv2 Transform Substructure Payload:
Mar 28 17:25:03.456546: | last transform: v2_TRANSFORM_NON_LAST (0x3)
Mar 28 17:25:03.458680: | length: 8 (00 08)
Mar 28 17:25:03.458738: | IKEv2 transform type: IKEv2_TRANS_TYPE_PRF (0x2)
Mar 28 17:25:03.458806: | IKEv2 transform ID: PRF_HMAC_SHA2_256 (0x5)
Mar 28 17:25:03.458881: | *****parse IKEv2 Transform Substructure Payload:
Mar 28 17:25:03.458922: | last transform: v2_TRANSFORM_NON_LAST (0x3)
Mar 28 17:25:03.459056: | length: 8 (00 08)
Mar 28 17:25:03.459168: | IKEv2 transform type: IKEv2_TRANS_TYPE_PRF (0x2)
Mar 28 17:25:03.459212: | IKEv2 transform ID: PRF_HMAC_SHA1 (0x2)
Mar 28 17:25:03.459252: | *****parse IKEv2 Transform Substructure Payload:
Mar 28 17:25:03.459292: | last transform: v2_TRANSFORM_NON_LAST (0x3)
Mar 28 17:25:03.459336: | length: 8 (00 08)
Mar 28 17:25:03.459514: | IKEv2 transform type: IKEv2_TRANS_TYPE_DH (0x4)
Mar 28 17:25:03.461839: | IKEv2 transform ID: OAKLEY_GROUP_ECP_256 (0x13)
Mar 28 17:25:03.461924: | remote proposal 2 transform 6 (DH=ECP_256) matches local proposal 1 type 4 (DH) transform 0
Mar 28 17:25:03.462043: | remote proposal 2 transform 6 (DH=ECP_256) matches local proposal 2 type 4 (DH) transform 0
Mar 28 17:25:03.463843: | remote proposal 2 transform 6 (DH=ECP_256) matches local proposal 3 type 4 (DH) transform 0
Mar 28 17:25:03.463926: | *****parse IKEv2 Transform Substructure Payload:
Mar 28 17:25:03.464039: | last transform: v2_TRANSFORM_NON_LAST (0x3)
Mar 28 17:25:03.465841: | length: 8 (00 08)
Mar 28 17:25:03.466479: | IKEv2 transform type: IKEv2_TRANS_TYPE_DH (0x4)
Mar 28 17:25:03.466521: | IKEv2 transform ID: OAKLEY_GROUP_DH24 (0x18)
Mar 28 17:25:03.467882: | *****parse IKEv2 Transform Substructure Payload:
Mar 28 17:25:03.467936: | last transform: v2_TRANSFORM_NON_LAST (0x3)
Mar 28 17:25:03.467980: | length: 8 (00 08)
Mar 28 17:25:03.468019: | IKEv2 transform type: IKEv2_TRANS_TYPE_DH (0x4)
Mar 28 17:25:03.468058: | IKEv2 transform ID: OAKLEY_GROUP_ECP_384 (0x14)
Mar 28 17:25:03.468327: | *****parse IKEv2 Transform Substructure Payload:
Mar 28 17:25:03.468373: | last transform: v2_TRANSFORM_NON_LAST (0x3)
Mar 28 17:25:03.468414: | length: 8 (00 08)
Mar 28 17:25:03.468548: | IKEv2 transform type: IKEv2_TRANS_TYPE_DH (0x4)
Mar 28 17:25:03.468706: | IKEv2 transform ID: OAKLEY_GROUP_MODP2048 (0xe)
Mar 28 17:25:03.468966: | *****parse IKEv2 Transform Substructure Payload:
Mar 28 17:25:03.469795: | last transform: v2_TRANSFORM_LAST (0x0)
Mar 28 17:25:03.469844: | length: 8 (00 08)
Mar 28 17:25:03.471864: | IKEv2 transform type: IKEv2_TRANS_TYPE_DH (0x4)
Mar 28 17:25:03.471921: | IKEv2 transform ID: OAKLEY_GROUP_MODP1536 (0x5)
Mar 28 17:25:03.471966: | remote proposal 2 proposed transforms: ENCR+PRF+DH; matched: ENCR+PRF+DH; unmatched: none
Mar 28 17:25:03.472011: | comparing remote proposal 2 containing ENCR+PRF+DH transforms to local proposal 1; required: ENCR+PRF+DH; optional: INTEG; matched: ENCR+PRF+DH
Mar 28 17:25:03.472052: | remote proposal 2 matches local proposal 1
Mar 28 17:25:03.472269: "tunnel1"[2] 192.168.1.126 #2: proposal 2:IKE=AES_GCM_C_256-HMAC_SHA2_512-ECP_256 chosen from remote proposals 1:IKE:ENCR=AES_CBC_256;ENCR=AES_CBC_128;INTEG=HMAC_SHA2_512_256;INTEG=HMAC_SHA2_384_192;INTEG=HMAC_SHA2_256_128;INTEG=HMAC_SHA1_96;PRF=HMAC_SHA2_512;PRF=HMAC_SHA2_384;PRF=HMAC_SHA2_256;PRF=HMAC_SHA1;DH=ECP_256;DH=DH24;DH=ECP_384;DH=MODP2048;DH=MODP1536[first-match] 2:IKE:ENCR=AES_GCM_C_256;ENCR=AES_GCM_C_128;PRF=HMAC_SHA2_512;PRF=HMAC_SHA2_384;PRF=HMAC_SHA2_256;PRF=HMAC_SHA1;DH=ECP_256;DH=DH24;DH=ECP_384;DH=MODP2048;DH=MODP1536[better-match]
Mar 28 17:25:03.472337: | accepted IKE proposal ikev2_proposal: 2:IKE=AES_GCM_C_256-HMAC_SHA2_512-ECP_256
Mar 28 17:25:03.472439: | converting proposal to internal trans attrs
Mar 28 17:25:03.472493: | IKEV2_FRAGMENTATION_SUPPORTED neither requested nor accepted
Mar 28 17:25:03.472536: | USE_PPK neither requested nor accepted
Mar 28 17:25:03.472769: | nat: IKE.SPIr is zero
Mar 28 17:25:03.472927: | natd_hash: hasher=0x563a77c9ec40(20)
Mar 28 17:25:03.476422: | natd_hash: icookie=
Mar 28 17:25:03.478814: | 3b 78 77 0a dd f4 4e 5e ;xw...N^
Mar 28 17:25:03.478952: | natd_hash: rcookie=
Mar 28 17:25:03.478999: | 00 00 00 00 00 00 00 00 ........
Mar 28 17:25:03.479039: | natd_hash: ip=
Mar 28 17:25:03.479093: | c0 a8 01 0a ....
Mar 28 17:25:03.479136: | natd_hash: port=
Mar 28 17:25:03.479256: | 01 f4 ..
Mar 28 17:25:03.481045: | natd_hash: hash=
Mar 28 17:25:03.481126: | 4c d8 c7 a9 e4 03 0f 9b 19 88 df b0 ce bb 42 14 L.............B.
Mar 28 17:25:03.481240: | f2 89 1a 33 ...3
Mar 28 17:25:03.482914: | nat: IKE.SPIr is zero
Mar 28 17:25:03.484912: | natd_hash: hasher=0x563a77c9ec40(20)
Mar 28 17:25:03.486886: | natd_hash: icookie=
Mar 28 17:25:03.486969: | 3b 78 77 0a dd f4 4e 5e ;xw...N^
Mar 28 17:25:03.487013: | natd_hash: rcookie=
Mar 28 17:25:03.487186: | 00 00 00 00 00 00 00 00 ........
Mar 28 17:25:03.487228: | natd_hash: ip=
Mar 28 17:25:03.487274: | c0 a8 01 7e ...~
Mar 28 17:25:03.487317: | natd_hash: port=
Mar 28 17:25:03.487357: | ea 3c .<
Mar 28 17:25:03.487397: | natd_hash: hash=
Mar 28 17:25:03.487437: | 55 61 3e 68 d5 88 0f eb 3e b1 3c 08 d1 a1 be c7 Ua>h....>.<.....
Mar 28 17:25:03.487499: | 37 08 95 06 7...
Mar 28 17:25:03.487540: | NAT_TRAVERSAL encaps using auto-detect
Mar 28 17:25:03.487580: | NAT_TRAVERSAL this end is NOT behind NAT
Mar 28 17:25:03.487623: | NAT_TRAVERSAL that end is behind NAT 192.168.1.126:59964
Mar 28 17:25:03.487672: | NAT_TRAVERSAL nat-keepalive enabled 192.168.1.126:59964
Mar 28 17:25:03.487797: | NAT: responder so initiator gets to switch ports
Mar 28 17:25:03.487897: | parsing 2 raw bytes of IKEv2 Notify Payload into hash algorithm identifier (network ordered)
Mar 28 17:25:03.487942: | 00 02 ..
Mar 28 17:25:03.487983: | digsig: received and ignored unacceptable hash algorithm SHA2_256
Mar 28 17:25:03.488023: | parsing 2 raw bytes of IKEv2 Notify Payload into hash algorithm identifier (network ordered)
Mar 28 17:25:03.488063: | 00 03 ..
Mar 28 17:25:03.488102: | digsig: received and ignored unacceptable hash algorithm SHA2_384
Mar 28 17:25:03.488141: | parsing 2 raw bytes of IKEv2 Notify Payload into hash algorithm identifier (network ordered)
Mar 28 17:25:03.488180: | 00 04 ..
Mar 28 17:25:03.488219: | digsig: received and ignored unacceptable hash algorithm SHA2_512
Mar 28 17:25:03.488258: | parsing 2 raw bytes of IKEv2 Notify Payload into hash algorithm identifier (network ordered)
Mar 28 17:25:03.488298: | 00 05 ..
Mar 28 17:25:03.488337: | digsig: received and ignored unacceptable hash algorithm IDENTITY
Mar 28 17:25:03.488894: | job: newref @0x563a7894e0b8(0->1) (submit_task() +331 programs/pluto/server_pool.c)
Mar 28 17:25:03.488953: | clone logger: newref @0x563a78943b58(0->1) (submit_task() +358 programs/pluto/server_pool.c)
Mar 28 17:25:03.488996: | job 1 helper 0 #2 process_v2_IKE_SA_INIT_request (dh): added to pending queue
Mar 28 17:25:03.489036: | #2 deleting EVENT_v2_DISCARD
Mar 28 17:25:03.489079: | tt: delref @0x563a78948408(1->0) (destroy_timeout() +575 programs/pluto/server.c)
Mar 28 17:25:03.489121: | state-event: delref @0x563a78948248(1->0) (delete_event() +534 programs/pluto/timer.c)
Mar 28 17:25:03.489255: | event_schedule_where: newref EVENT_CRYPTO_TIMEOUT-pe at 0x563a78948248 timeout in 60 seconds for #2
Mar 28 17:25:03.489359: | tt: newref @0x563a7894e158(0->1) (schedule_timeout() +557 programs/pluto/server.c)
Mar 28 17:25:03.489505: | job 1 helper 1 #2 process_v2_IKE_SA_INIT_request (dh): started
Mar 28 17:25:03.526661: | struct dh_local_secret: newref @0x7fd8980016f8(0->1) (calc_dh_local_secret() +85 programs/pluto/crypt_dh.c)
Mar 28 17:25:03.528464: | job 1 helper 1 #2 process_v2_IKE_SA_INIT_request (dh): finished
Mar 28 17:25:03.528546: | "tunnel1"[2] 192.168.1.126 #2: spent 4.19 (39) milliseconds in job 1 helper 1 #2 process_v2_IKE_SA_INIT_request (dh)
Mar 28 17:25:03.529944: | scheduling resume sending job back to main thread for #2
Mar 28 17:25:03.530009: | tt: newref @0x7fd898004278(0->1) (schedule_timeout() +557 programs/pluto/server.c)
Mar 28 17:25:03.530107: | helper 1: waiting for work
Mar 28 17:25:03.530158: | #2 complete_v2_state_transition() PARENT_R0->PARENT_R1 with status STF_SUSPEND
Mar 28 17:25:03.530204: | suspend: saving MD at 0x563a7894a418 in state #2 (complete_v2_state_transition() +2702 programs/pluto/ikev2.c)
Mar 28 17:25:03.530428: | struct msg_digest: addref @0x563a7894a418(1->2) (complete_v2_state_transition() +2702 programs/pluto/ikev2.c)
Mar 28 17:25:03.530554: | #2 is busy; has suspended MD 0x563a7894a418
Mar 28 17:25:03.530836: | #2 spent 9.29 (153) milliseconds in processing: Respond to IKE_SA_INIT in v2_dispatch()
Mar 28 17:25:03.530894: | #2 spent 13.7 (195) milliseconds in process_v2_IKE_SA_INIT()
Mar 28 17:25:03.531867: | "tunnel1"[2] 192.168.1.126: delref @0x563a7894be28(2->1) packet from 192.168.1.126:59964: (process_v2_IKE_SA_INIT() +449 programs/pluto/ikev2_ike_sa_init.c)
Mar 28 17:25:03.531929: | packet from 192.168.1.126:59964: delref @0x563a7894a418(2->1) (process_iface_packet() +296 programs/pluto/demux.c)
Mar 28 17:25:03.532892: | spent 13.9 (197) milliseconds in process_iface_packet() reading and processing packet
Mar 28 17:25:03.536791: | processing resume sending job back to main thread for #2
Mar 28 17:25:03.536862: | suspend: restoring MD at 0x563a7894a418 from state #2 (resume_handler() +641 programs/pluto/server.c)
Mar 28 17:25:03.536966: | job 1 helper 1 #2 process_v2_IKE_SA_INIT_request (dh): calling state's callback function
Mar 28 17:25:03.537011: | process_v2_IKE_SA_INIT_request_continue() for #2 STATE_V2_PARENT_R0: calculated ke+nonce, sending R1
Mar 28 17:25:03.537293: | opening output PBS IKE_SA_INIT response
Mar 28 17:25:03.540979: | **emit ISAKMP Message:
Mar 28 17:25:03.541045: | initiator SPI: 3b 78 77 0a dd f4 4e 5e
Mar 28 17:25:03.541090: | responder SPI: e2 3b 12 02 9c 3e f8 c2
Mar 28 17:25:03.541130: | next payload type: ISAKMP_NEXT_NONE (0x0)
Mar 28 17:25:03.541169: | ISAKMP version: IKEv2 version 2.0 (rfc4306/rfc5996) (0x20)
Mar 28 17:25:03.541282: | exchange type: ISAKMP_v2_IKE_SA_INIT (0x22)
Mar 28 17:25:03.541326: | flags: ISAKMP_FLAG_v2_MSG_RESPONSE (0x20)
Mar 28 17:25:03.541398: | Message ID: 0 (00 00 00 00)
Mar 28 17:25:03.541443: | next payload chain: saving message location 'ISAKMP Message'.'next payload type'
Mar 28 17:25:03.542887: | emitting ikev2_proposal ...
Mar 28 17:25:03.542941: | ***emit IKEv2 Security Association Payload:
Mar 28 17:25:03.542982: | next payload type: ISAKMP_NEXT_v2NONE (0x0)
Mar 28 17:25:03.543022: | flags: none (0x0)
Mar 28 17:25:03.543062: | next payload chain: setting previous 'ISAKMP Message'.'next payload type' to current IKEv2 Security Association Payload (33:ISAKMP_NEXT_v2SA)
Mar 28 17:25:03.543211: | next payload chain: saving location 'IKEv2 Security Association Payload'.'next payload type' in 'IKE_SA_INIT response'
Mar 28 17:25:03.548848: | ****emit IKEv2 Proposal Substructure Payload:
Mar 28 17:25:03.548949: | last proposal: v2_PROPOSAL_LAST (0x0)
Mar 28 17:25:03.548993: | prop #: 2 (02)
Mar 28 17:25:03.549032: | proto ID: IKEv2_SEC_PROTO_IKE (0x1)
Mar 28 17:25:03.549072: | spi size: 0 (00)
Mar 28 17:25:03.549111: | # transforms: 3 (03)
Mar 28 17:25:03.549317: | last substructure: saving location 'IKEv2 Security Association Payload'.'IKEv2 Proposal Substructure Payload'.'last proposal'
Mar 28 17:25:03.549436: | *****emit IKEv2 Transform Substructure Payload:
Mar 28 17:25:03.549479: | last transform: v2_TRANSFORM_NON_LAST (0x3)
Mar 28 17:25:03.549518: | IKEv2 transform type: IKEv2_TRANS_TYPE_ENCR (0x1)
Mar 28 17:25:03.549563: | IKEv2 transform ID: AES_GCM_C (0x14)
Mar 28 17:25:03.549729: | last substructure: saving location 'IKEv2 Proposal Substructure Payload'.'IKEv2 Transform Substructure Payload'.'last transform'
Mar 28 17:25:03.549779: | ******emit IKEv2 Attribute Substructure Payload:
Mar 28 17:25:03.549914: | af+type: AF+IKEv2_KEY_LENGTH (0x800e)
Mar 28 17:25:03.550283: | length/value: 256 (01 00)
Mar 28 17:25:03.550428: | emitting length of IKEv2 Transform Substructure Payload: 12
Mar 28 17:25:03.550545: | *****emit IKEv2 Transform Substructure Payload:
Mar 28 17:25:03.550585: | last transform: v2_TRANSFORM_NON_LAST (0x3)
Mar 28 17:25:03.550649: | IKEv2 transform type: IKEv2_TRANS_TYPE_PRF (0x2)
Mar 28 17:25:03.550685: | IKEv2 transform ID: PRF_HMAC_SHA2_512 (0x7)
Mar 28 17:25:03.551038: | last substructure: checking 'IKEv2 Proposal Substructure Payload'.'IKEv2 Transform Substructure Payload'.'last transform' containing v2_TRANSFORM_NON_LAST (0x3) is v2_TRANSFORM_NON_LAST (0x3)
Mar 28 17:25:03.551080: | last substructure: saving location 'IKEv2 Proposal Substructure Payload'.'IKEv2 Transform Substructure Payload'.'last transform'
Mar 28 17:25:03.551275: | emitting length of IKEv2 Transform Substructure Payload: 8
Mar 28 17:25:03.554000: | *****emit IKEv2 Transform Substructure Payload:
Mar 28 17:25:03.554062: | last transform: v2_TRANSFORM_LAST (0x0)
Mar 28 17:25:03.554102: | IKEv2 transform type: IKEv2_TRANS_TYPE_DH (0x4)
Mar 28 17:25:03.554154: | IKEv2 transform ID: OAKLEY_GROUP_ECP_256 (0x13)
Mar 28 17:25:03.554337: | last substructure: checking 'IKEv2 Proposal Substructure Payload'.'IKEv2 Transform Substructure Payload'.'last transform' containing v2_TRANSFORM_NON_LAST (0x3) is v2_TRANSFORM_NON_LAST (0x3)
Mar 28 17:25:03.555914: | last substructure: saving location 'IKEv2 Proposal Substructure Payload'.'IKEv2 Transform Substructure Payload'.'last transform'
Mar 28 17:25:03.555973: | emitting length of IKEv2 Transform Substructure Payload: 8
Mar 28 17:25:03.556011: | emitting length of IKEv2 Proposal Substructure Payload: 36
Mar 28 17:25:03.556543: | last substructure: checking 'IKEv2 Proposal Substructure Payload'.'IKEv2 Transform Substructure Payload'.'last transform' is 0
Mar 28 17:25:03.556595: | emitting length of IKEv2 Security Association Payload: 40
Mar 28 17:25:03.556634: | last substructure: checking 'IKEv2 Security Association Payload'.'IKEv2 Proposal Substructure Payload'.'last proposal' is 0
Mar 28 17:25:03.556676: | struct dh_local_secret: addref @0x7fd8980016f8(1->2) (unpack_KE_from_helper() +155 programs/pluto/crypt_ke.c)
Mar 28 17:25:03.556712: | ***emit IKEv2 Key Exchange Payload:
Mar 28 17:25:03.556933: | next payload type: ISAKMP_NEXT_v2NONE (0x0)
Mar 28 17:25:03.556976: | flags: none (0x0)
Mar 28 17:25:03.557883: | DH group: OAKLEY_GROUP_ECP_256 (0x13)
Mar 28 17:25:03.559874: | next payload chain: setting previous 'IKEv2 Security Association Payload'.'next payload type' to current IKEv2 Key Exchange Payload (34:ISAKMP_NEXT_v2KE)
Mar 28 17:25:03.559936: | next payload chain: saving location 'IKEv2 Key Exchange Payload'.'next payload type' in 'IKE_SA_INIT response'
Mar 28 17:25:03.559977: | emitting 64 raw bytes of ikev2 g^x into IKEv2 Key Exchange Payload
Mar 28 17:25:03.560012: | 00 37 ee 40 c5 08 78 95 1a f7 0a da 77 56 0e 76 .7. at ..x.....wV.v
Mar 28 17:25:03.560047: | 21 2b 60 c1 66 36 64 0d 04 8e b5 75 39 4b ae 07 !+`.f6d....u9K..
Mar 28 17:25:03.560203: | ae 88 f7 c9 2c e4 7c 1b 0b d6 fa e7 b3 61 0a 39 ....,.|......a.9
Mar 28 17:25:03.561051: | e7 fc 65 e7 51 a1 2e 37 49 86 ba fd 80 15 4b b7 ..e.Q..7I.....K.
Mar 28 17:25:03.561139: | emitting length of IKEv2 Key Exchange Payload: 72
Mar 28 17:25:03.561890: | ***emit IKEv2 Nonce Payload:
Mar 28 17:25:03.563873: | next payload type: ISAKMP_NEXT_v2NONE (0x0)
Mar 28 17:25:03.563959: | flags: none (0x0)
Mar 28 17:25:03.563998: | next payload chain: setting previous 'IKEv2 Key Exchange Payload'.'next payload type' to current IKEv2 Nonce Payload (40:ISAKMP_NEXT_v2Ni)
Mar 28 17:25:03.565859: | next payload chain: saving location 'IKEv2 Nonce Payload'.'next payload type' in 'IKE_SA_INIT response'
Mar 28 17:25:03.565947: | emitting 32 raw bytes of IKEv2 nonce into IKEv2 Nonce Payload
Mar 28 17:25:03.566004: | ba ac 67 64 5e 21 4c 04 1a 5c 1e e0 5b f8 d7 12 ..gd^!L..\..[...
Mar 28 17:25:03.566040: | 56 be 20 15 95 51 a7 61 66 6d c7 01 bb ca a8 53 V. ..Q.afm.....S
Mar 28 17:25:03.566159: | emitting length of IKEv2 Nonce Payload: 36
Mar 28 17:25:03.566422: | INTERMEDIATE_EXCHANGE_SUPPORTED neither requested nor accepted
Mar 28 17:25:03.566576: | NAT-Traversal support [enabled] add v2N payloads.
Mar 28 17:25:03.566644: | natd_hash: hasher=0x563a77c9ec40(20)
Mar 28 17:25:03.566777: | natd_hash: icookie=
Mar 28 17:25:03.570972: | 3b 78 77 0a dd f4 4e 5e ;xw...N^
Mar 28 17:25:03.571036: | natd_hash: rcookie=
Mar 28 17:25:03.572925: | e2 3b 12 02 9c 3e f8 c2 .;...>..
Mar 28 17:25:03.572964: | natd_hash: ip=
Mar 28 17:25:03.572998: | c0 a8 01 0a ....
Mar 28 17:25:03.573032: | natd_hash: port=
Mar 28 17:25:03.573152: | 01 f4 ..
Mar 28 17:25:03.573327: | natd_hash: hash=
Mar 28 17:25:03.574933: | 5b 59 b9 4e a8 28 99 06 bb 1e 3e b9 7d ab 6a 9c [Y.N.(....>.}.j.
Mar 28 17:25:03.574979: | f5 db 39 1a ..9.
Mar 28 17:25:03.575041: | adding a v2N Payload
Mar 28 17:25:03.575237: | ***emit IKEv2 Notify Payload:
Mar 28 17:25:03.575433: | next payload type: ISAKMP_NEXT_v2NONE (0x0)
Mar 28 17:25:03.575484: | flags: none (0x0)
Mar 28 17:25:03.575589: | Protocol ID: IKEv2_SEC_PROTO_NONE (0x0)
Mar 28 17:25:03.575913: | SPI size: 0 (00)
Mar 28 17:25:03.575963: | Notify Message Type: v2N_NAT_DETECTION_SOURCE_IP (0x4004)
Mar 28 17:25:03.578529: | next payload chain: setting previous 'IKEv2 Nonce Payload'.'next payload type' to current IKEv2 Notify Payload (41:ISAKMP_NEXT_v2N)
Mar 28 17:25:03.578586: | next payload chain: saving location 'IKEv2 Notify Payload'.'next payload type' in 'IKE_SA_INIT response'
Mar 28 17:25:03.578622: | emitting 20 raw bytes of Notify data into IKEv2 Notify Payload
Mar 28 17:25:03.579876: | 5b 59 b9 4e a8 28 99 06 bb 1e 3e b9 7d ab 6a 9c [Y.N.(....>.}.j.
Mar 28 17:25:03.581636: | f5 db 39 1a ..9.
Mar 28 17:25:03.581692: | emitting length of IKEv2 Notify Payload: 28
Mar 28 17:25:03.581815: | natd_hash: hasher=0x563a77c9ec40(20)
Mar 28 17:25:03.581974: | natd_hash: icookie=
Mar 28 17:25:03.582145: | 3b 78 77 0a dd f4 4e 5e ;xw...N^
Mar 28 17:25:03.582188: | natd_hash: rcookie=
Mar 28 17:25:03.582299: | e2 3b 12 02 9c 3e f8 c2 .;...>..
Mar 28 17:25:03.582405: | natd_hash: ip=
Mar 28 17:25:03.582612: | c0 a8 01 7e ...~
Mar 28 17:25:03.582722: | natd_hash: port=
Mar 28 17:25:03.582857: | ea 3c .<
Mar 28 17:25:03.585837: | natd_hash: hash=
Mar 28 17:25:03.585919: | d2 30 49 7f 94 71 d7 bf 23 b8 fc db b7 78 8e 0a .0I..q..#....x..
Mar 28 17:25:03.585962: | e1 b3 21 75 ..!u
Mar 28 17:25:03.586001: | adding a v2N Payload
Mar 28 17:25:03.586040: | ***emit IKEv2 Notify Payload:
Mar 28 17:25:03.586287: | next payload type: ISAKMP_NEXT_v2NONE (0x0)
Mar 28 17:25:03.586334: | flags: none (0x0)
Mar 28 17:25:03.586438: | Protocol ID: IKEv2_SEC_PROTO_NONE (0x0)
Mar 28 17:25:03.586549: | SPI size: 0 (00)
Mar 28 17:25:03.586655: | Notify Message Type: v2N_NAT_DETECTION_DESTINATION_IP (0x4005)
Mar 28 17:25:03.586787: | next payload chain: setting previous 'IKEv2 Notify Payload'.'next payload type' to current IKEv2 Notify Payload (41:ISAKMP_NEXT_v2N)
Mar 28 17:25:03.586872: | next payload chain: saving location 'IKEv2 Notify Payload'.'next payload type' in 'IKE_SA_INIT response'
Mar 28 17:25:03.587886: | emitting 20 raw bytes of Notify data into IKEv2 Notify Payload
Mar 28 17:25:03.589932: | d2 30 49 7f 94 71 d7 bf 23 b8 fc db b7 78 8e 0a .0I..q..#....x..
Mar 28 17:25:03.589989: | e1 b3 21 75 ..!u
Mar 28 17:25:03.590034: | emitting length of IKEv2 Notify Payload: 28
Mar 28 17:25:03.590073: | adding a v2N Payload
Mar 28 17:25:03.590112: | ***emit IKEv2 Notify Payload:
Mar 28 17:25:03.590282: | next payload type: ISAKMP_NEXT_v2NONE (0x0)
Mar 28 17:25:03.591081: | flags: none (0x0)
Mar 28 17:25:03.591210: | Protocol ID: IKEv2_SEC_PROTO_NONE (0x0)
Mar 28 17:25:03.591258: | SPI size: 0 (00)
Mar 28 17:25:03.591297: | Notify Message Type: v2N_CHILDLESS_IKEV2_SUPPORTED (0x4022)
Mar 28 17:25:03.591685: | next payload chain: setting previous 'IKEv2 Notify Payload'.'next payload type' to current IKEv2 Notify Payload (41:ISAKMP_NEXT_v2N)
Mar 28 17:25:03.591734: | next payload chain: saving location 'IKEv2 Notify Payload'.'next payload type' in 'IKE_SA_INIT response'
Mar 28 17:25:03.591776: | emitting 0 raw bytes of Notify data into IKEv2 Notify Payload
Mar 28 17:25:03.591911: | Notify data:
Mar 28 17:25:03.593426: | emitting length of IKEv2 Notify Payload: 8
Mar 28 17:25:03.593483: | emitting length of ISAKMP Message: 240
Mar 28 17:25:03.593600: | job 1 helper 1 #2 process_v2_IKE_SA_INIT_request (dh): final status STF_OK; cleaning up
Mar 28 17:25:03.593935: | delref @0x7fd8980016f8(2->1) (cleanup_ke_and_nonce() +83 programs/pluto/crypt_ke.c)
Mar 28 17:25:03.594008: | "tunnel1"[2] 192.168.1.126 #2: releasing whack (but there are none) (free_job() +430 programs/pluto/server_pool.c)
Mar 28 17:25:03.594051: | logger: delref @0x563a78943b58(1->0) (free_job() +430 programs/pluto/server_pool.c)
Mar 28 17:25:03.594129: | job: delref @0x563a7894e0b8(1->0) (free_job() +431 programs/pluto/server_pool.c)
Mar 28 17:25:03.594175: | #2 complete_v2_state_transition() PARENT_R0->PARENT_R1 with status STF_OK
Mar 28 17:25:03.594215: | transitioning from state STATE_V2_PARENT_R0 to state STATE_V2_PARENT_R1
Mar 28 17:25:03.594254: | Message ID: updating counters for #2
Mar 28 17:25:03.594323: | Message ID: IKE #2 updating responder received message request 0 (initiator: responder: .recv=-1->0 .wip=0->-1 .last_recv=989.672257->989.888522)
Mar 28 17:25:03.595906: | Message ID: IKE #2 updating responder sent message response 0 (initiator: responder: .sent=-1->0 .last_sent=989.672257->989.890106)
Mar 28 17:25:03.599848: | parent state #2: PARENT_R0(half-open IKE SA) => PARENT_R1(half-open IKE SA)
Mar 28 17:25:03.601806: | Message ID: IKE #2 no pending message initiators to schedule (initiator: .sent=-1 .recv=-1 .recv_frags=0 .wip=-1 .last_sent=989.672257 .last_recv=989.672257 responder: .sent=0 .recv=0 .recv_frags=0 .wip=-1 .last_sent=989.890106 .last_recv=989.888522)
Mar 28 17:25:03.601917: | #2 deleting EVENT_CRYPTO_TIMEOUT
Mar 28 17:25:03.601968: | tt: delref @0x563a7894e158(1->0) (destroy_timeout() +575 programs/pluto/server.c)
Mar 28 17:25:03.602012: | state-event: delref @0x563a78948248(1->0) (delete_event() +534 programs/pluto/timer.c)
Mar 28 17:25:03.602056: | event_schedule_where: newref EVENT_v2_DISCARD-pe at 0x563a78948248 timeout in 200 seconds for #2
Mar 28 17:25:03.602116: | tt: newref @0x563a7894e558(0->1) (schedule_timeout() +557 programs/pluto/server.c)
Mar 28 17:25:03.602171: | sending 240 bytes for Respond to IKE_SA_INIT through enp0s3 from 192.168.1.10:500 to 192.168.1.126:59964 using UDP (for #2)
Mar 28 17:25:03.602213: | 3b 78 77 0a dd f4 4e 5e e2 3b 12 02 9c 3e f8 c2 ;xw...N^.;...>..
Mar 28 17:25:03.602253: | 21 20 22 20 00 00 00 00 00 00 00 f0 22 00 00 28 ! " ........"..(
Mar 28 17:25:03.602292: | 00 00 00 24 02 01 00 03 03 00 00 0c 01 00 00 14 ...$............
Mar 28 17:25:03.602331: | 80 0e 01 00 03 00 00 08 02 00 00 07 00 00 00 08 ................
Mar 28 17:25:03.602370: | 04 00 00 13 28 00 00 48 00 13 00 00 00 37 ee 40 ....(..H.....7.@
Mar 28 17:25:03.602410: | c5 08 78 95 1a f7 0a da 77 56 0e 76 21 2b 60 c1 ..x.....wV.v!+`.
Mar 28 17:25:03.602449: | 66 36 64 0d 04 8e b5 75 39 4b ae 07 ae 88 f7 c9 f6d....u9K......
Mar 28 17:25:03.602488: | 2c e4 7c 1b 0b d6 fa e7 b3 61 0a 39 e7 fc 65 e7 ,.|......a.9..e.
Mar 28 17:25:03.602527: | 51 a1 2e 37 49 86 ba fd 80 15 4b b7 29 00 00 24 Q..7I.....K.)..$
Mar 28 17:25:03.602566: | ba ac 67 64 5e 21 4c 04 1a 5c 1e e0 5b f8 d7 12 ..gd^!L..\..[...
Mar 28 17:25:03.602605: | 56 be 20 15 95 51 a7 61 66 6d c7 01 bb ca a8 53 V. ..Q.afm.....S
Mar 28 17:25:03.602645: | 29 00 00 1c 00 00 40 04 5b 59 b9 4e a8 28 99 06 )..... at .[Y.N.(..
Mar 28 17:25:03.602684: | bb 1e 3e b9 7d ab 6a 9c f5 db 39 1a 29 00 00 1c ..>.}.j...9.)...
Mar 28 17:25:03.602723: | 00 00 40 05 d2 30 49 7f 94 71 d7 bf 23 b8 fc db .. at ..0I..q..#...
Mar 28 17:25:03.602762: | b7 78 8e 0a e1 b3 21 75 00 00 00 08 00 00 40 22 .x....!u......@"
Mar 28 17:25:03.602886: | sent 1 messages
Mar 28 17:25:03.602954: "tunnel1"[2] 192.168.1.126 #2: processed IKE_SA_INIT request from 192.168.1.126:UDP/59964 {cipher=AES_GCM_16_256 integ=n/a prf=HMAC_SHA2_512 group=DH19}
Mar 28 17:25:03.605911: | packet from 192.168.1.126:59964: delref @0x563a7894a418(1->0) (resume_handler() +687 programs/pluto/server.c)
Mar 28 17:25:03.605974: | packet from 192.168.1.126:59964: releasing whack (but there are none) (resume_handler() +687 programs/pluto/server.c)
Mar 28 17:25:03.606036: | logger: delref @0x563a78943db8(1->0) (resume_handler() +687 programs/pluto/server.c)
Mar 28 17:25:03.606099: | delref @0x563a789493d8(3->2) (resume_handler() +687 programs/pluto/server.c)
Mar 28 17:25:03.606150: | #2 spent 6.6 (69.3) milliseconds in resume sending job back to main thread
Mar 28 17:25:03.606194: | tt: delref @0x7fd898004278(1->0) (destroy_timeout() +575 programs/pluto/server.c)
—
Saludos / Regards / Cumprimentos
António Silva
> On 28 Mar 2024, at 13:42, Paul Wouters <paul at nohats.ca> wrote:
>
> On Wed, 27 Mar 2024, antonio via Swan wrote:
>
>> I’m trying to connect an android device using native vpn and libreswan version 5.0rc2, it looks like a simple connection host - host/subnet but it
>> doesn’t connect… got the following log:
>
> Note that the logs provided do not yet indicate a problem.
>
>> Mar 27 17:55:02.739193: "tunnel1"[1] 192.168.1.126 #1: proposal 2:IKE=AES_GCM_C_256-HMAC_SHA2_512-ECP_256 chosen from remote proposals1:IKE:ENCR=AES_CBC_256;ENCR=AES_CBC_128;INTEG=HMAC_SHA2_512_256;INTEG=HMAC_SHA2_384_192;INTEG=HMAC_SHA2_256_128;INTEG=HMAC_SHA1_96;PRF=HMAC_SHA2_512;PRF=
>> HMAC_SHA2_384;PRF=HMAC_SHA2_256;PRF=HMAC_SHA1;DH=DH24;DH=ECP_384;DH=ECP_256;DH=MODP2048;DH=MODP1536[first-match]2:IKE:ENCR=AES_GCM_C_256;ENCR=AES_GCM_C_128;PRF=HMAC_SHA2_512;PRF=HMAC_SHA2_384;PRF=HMAC_SHA2_256;PRF=HMAC_SHA1;DH=DH24;DH=ECP_384;DH=ECP_256;DH=MODP2048
>> ;DH=MODP1536[better-match]
>> Mar 27 17:55:02.739254: "tunnel1"[1] 192.168.1.126 #1: initiator guessed wrong keying material group (DH24); responding with INVALID_KE_PAYLOAD requesting
>> DH19
>
> Both ends allow DH19 but libreswan as responder does not allow DH24
> (2048-bit MODP Group with 256-bit Prime Order Subgroup) Note that DH22-24
> is a strange group and is best avoided (see also RFC8247). These groups
> have not been vetted by the Cryptographic Community at large, and come
> directly from NIST without peer review. These groups are therefor at best
> "questionable" and libreswan does not add these to the default proposal
> list. Why is the client preferring DH24? It's a very odd choice.
>
>> Mar 27 17:55:02.739330: "tunnel1"[1] 192.168.1.126 #1: responding to IKE_SA_INIT message (ID 0) from 192.168.1.126:41943 with unencrypted notification
>> INVALID_KE_PAYLOAD
>
> This is the response, telling the initiator to retry with DH19 (ECP_256)
>
>> Mar 27 17:55:02.739356: "tunnel1"[1] 192.168.1.126 #1: encountered fatal error in state STATE_V2_PARENT_R0
>> Mar 27 17:55:02.739516: "tunnel1"[1] 192.168.1.126 #1: deleting IKE SA (processing IKE_SA_INIT request)
>> Mar 27 17:55:02.739710: "tunnel1"[1] 192.168.1.126: deleting connection instance with peer 192.168.1.126
>
> The connection is removed properly.
>
>> Mar 27 17:55:02.750583: "tunnel1"[2] 192.168.1.126 #2: proposal 2:IKE=AES_GCM_C_256-HMAC_SHA2_512-ECP_256 chosen from remote proposals1:IKE:ENCR=AES_CBC_256;ENCR=AES_CBC_128;INTEG=HMAC_SHA2_512_256;INTEG=HMAC_SHA2_384_192;INTEG=HMAC_SHA2_256_128;INTEG=HMAC_SHA1_96;PRF=HMAC_SHA2_512;PRF=
>> HMAC_SHA2_384;PRF=HMAC_SHA2_256;PRF=HMAC_SHA1;DH=ECP_256;DH=DH24;DH=ECP_384;DH=MODP2048;DH=MODP1536[first-match]2:IKE:ENCR=AES_GCM_C_256;ENCR=AES_GCM_C_128;PRF=HMAC_SHA2_512;PRF=HMAC_SHA2_384;PRF=HMAC_SHA2_256;PRF=HMAC_SHA1;DH=ECP_256;DH=DH24;DH=ECP_384;DH=MODP2048
>> ;DH=MODP1536[better-match]
>> Mar 27 17:55:02.754631: "tunnel1"[2] 192.168.1.126 #2: processed IKE_SA_INIT request from 192.168.1.126:UDP/41943 {cipher=AES_GCM_16_256 integ=n/a
>> prf=HMAC_SHA2_512 group=DH19}
>
> The IKE SA established properly with DH19 now. But you show no further
> log of the Child SA (IPsec SA) being established or not.
>
>> My tunnel configuration:
>> conn tunnel1
>> type=tunnel
>> authby=secret
>> auto=add
>> left=192.168.1.10
>> leftsubnet=192.168.10.0/24
>> leftid=192.168.101.2
>> keyingtries=3
>> ikelifetime=8h
>> salifetime=8h
>> right=%any
>> rightid=192.168.102.1
>
> Nothing to fix, although I would remove keyingtries, ikelifetime and
> salifetime and rely on our defaults.
>
> Although it is unclear what your tunnel is for. If you want
> 192.168.102.1 to reach 192.168.10.0/24, you need to add
> rightsubnet=192.168.102.1/32. Since you allow coming from "any"
> and you appear to be NATed based on your rightid=, you should
> configure the IP address that the client is going to use as
> source IP.
>
>> You can see pluto.log, debug = all here https://pastebin.com/4V26rLnw
>
> Based on those logs, it seems the client is trying to use EAP but you
> have not configured libreswan to use EAP.
>
> You should clarify what both ends want to use as authentication method
> and configure them both to use that same method.
>
> Paul
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <https://lists.libreswan.org/pipermail/swan/attachments/20240328/f888fbef/attachment-0001.htm>
More information about the Swan
mailing list