Re: [Swan] private key for cert Thor not found in local cache; loading from NSS DB
On Sun, 7 Oct 2018, rayv33n wrote: Yes, sir. That actually helps me understand and confirm a few things. My lab setup has two hosts. Each host is in a different network routed through a firewall with no NAT. They work perfectly creating SA and having no problems. But when ipsechost01 tries to talk to the AWS instances check out ipsechost01 to Thor(AWS). Which is AWS NAT with ipsechost behind a firewall, also NAT. Feel free to give me example configs or anything else you want me to try this is all lab stuff and I have time so I can be your lab monkey. We do have various test cases covering all these IPv4 scenarios, see test results at: http://testing.libreswan.org/results/testing/v3.26-79-g41cda6b-master/ and the list of test cases and their configs: https://github.com/libreswan/libreswan/tree/master/testing/pluto The newoe-* testcases do a bunch of anonymous OE tests the certoe-* test cases do opportunistic encryption using certificates For example, certoe-06-nat-packet-cop seems to be the test case that covers connecting from behind NAT to a server. I don't think we have a testcase for a server behind a portforward like AWS. I'll see about adding that in the near future. Paul ___ Swan mailing list Swan@lists.libreswan.org https://lists.libreswan.org/mailman/listinfo/swan
Re: [Swan] private key for cert Thor not found in local cache; loading from NSS DB
On Mon, 8 Oct 2018, rayv33n wrote: Is there anything you guys would recommend I do to debug or troubleshoot this or is this as simple as mismatching info due to NAT? Oct 8 18:04:08.189602: "private#0.0.0.0/0"[1] ...XX.XXX.XXX.205 #3: responding to AUTH message (ID 1) from XX.XXX.XXX.205:22311 with encrypted notification AUTHENTICATION_FAILED Can you show more previous debug logs? It seems that we decided to fail for some reason, but then we went out to encrypt the failure payload and sent it. so the actual error causing this end to want to fail was not in your mail to the list. Paul ___ Swan mailing list Swan@lists.libreswan.org https://lists.libreswan.org/mailman/listinfo/swan
Re: [Swan] private key for cert Thor not found in local cache; loading from NSS DB
Thanks Nick! I was following a sub Reddit that suggested this can't be
done. I think the problem is always going to be the IGW and NAT aware stuff
we have no control over. But I'm looking into it.
This thread started out in confusion about Thor's private key which I've no
solved by completely wiping and redoing the ipsec NSS DB. I have no idea
why it broke but here's what I can now thankfully. Unfortunately now
ipsechost1 says " private key for cert ipsechost1 not found in local cache;
loading from NSS DB" which of course I know is got to be miss leading since
ipsechost1 has active SA's created with the other host in my lab. I think
this statement is miss leading and maybe it could be clarified later on so
noobs like me don't gravitate towards it.
Is there anything you guys would recommend I do to debug or troubleshoot
this or is this as simple as mismatching info due to NAT?
- Logs from Thor(AWS instance) Receiving end---
Oct 8 18:04:00.985391: XAUTH PAM support [enabled]
Oct 8 18:04:00.985798: | encryption algorithm NULL_AUTH_AES_GMAC, IKEv1
OAKLEY id: -1, IKEv1 ESP_INFO id: 23, IKEv2 id: 21
Oct 8 18:04:00.985803: | IKEv1 ESP ID id: 23 enum name: NULL_AUTH_AES_GMAC
Oct 8 18:04:00.985806: | IKEv2 ID id: 21 enum name: NULL_AUTH_AES_GMAC
Oct 8 18:04:00.985899: NULL_AUTH_AES_GMAC IKEv1: ESP
IKEv2: ESP {256,192,*128} aes_gmac
Oct 8 18:04:01.010590: | extracting the RSA private key for Thor
Oct 8 18:04:01.026495: | DH ike_alg_lookup_by_id id: MODP2048=14, found
MODP2048
Oct 8 18:04:05.039048: | DH ike_alg_lookup_by_id id: MODP2048=14, found
MODP2048
Oct 8 18:04:08.147322: | encryption ike_alg_lookup_by_id id: AES_CBC=12,
found AES_CBC
Oct 8 18:04:08.147330: | PRF ike_alg_lookup_by_id id: HMAC_SHA1=2, found
HMAC_SHA1
Oct 8 18:04:08.147335: | integrity ike_alg_lookup_by_id id:
HMAC_SHA1_96=2, found HMAC_SHA1_96
Oct 8 18:04:08.147339: | DH ike_alg_lookup_by_id id: MODP2048=14, found
MODP2048
Oct 8 18:04:08.184824: "private#0.0.0.0/0"[1] ...76.102.236.205 #3:
Authenticated using RSA
Oct 8 18:04:08.185023: | extracting the RSA private key for Thor
Oct 8 18:04:08.185502: | RSA key AwEAAeaaN found
Oct 8 18:04:08.185674: | NSS: Authentication to NSS successful
Oct 8 18:04:08.189602: "private#0.0.0.0/0"[1] ...XX.XXX.XXX.205 #3:
responding to AUTH message (ID 1) from XX.XXX.XXX.205:22311 with encrypted
notification AUTHENTICATION_FAILED
Oct 8 18:04:09.045268: | DH ike_alg_lookup_by_id id: MODP2048=14, found
MODP2048
Oct 8 18:04:09.066730: | encryption ike_alg_lookup_by_id id: AES_CBC=12,
found AES_CBC
Oct 8 18:04:09.066735: | PRF ike_alg_lookup_by_id id: HMAC_SHA1=2, found
HMAC_SHA1
Oct 8 18:04:09.066739: | integrity ike_alg_lookup_by_id id:
HMAC_SHA1_96=2, found HMAC_SHA1_96
Oct 8 18:04:09.066743: | DH ike_alg_lookup_by_id id: MODP2048=14, found
MODP2048
Oct 8 18:04:09.068964: | RSA key AwEAAeaaN found
Oct 8 18:04:09.069137: | NSS: Authentication to NSS successful
Oct 8 18:04:13.079020: "private#0.0.0.0/0"[1] ...XX.XXX.XXX.205 #5:
STATE_PARENT_I2: 3 second timeout exceeded after 3 retransmits. Possible
authentication failure: no acceptable response to our first encrypted
message
Logs from ipsechost1(Behind home office NAT/FW) initiating
connection
Oct 8 11:04:06.912445: | cmd( 640):TIME='0'
PLUTO_CONN_POLICY='AUTH_NEVER+GROUPINSTANCE+PASS+NEVER_NEGOTIATE' PLUTO:
Oct 8 11:04:06.912449: | cmd( 720):_CONN_KIND='CK_INSTANCE'
PLUTO_CONN_ADDRFAMILY='ipv4' XAUTH_FAILED=0 PLUTO_IS_PE:
Oct 8 11:04:08.108299: | established-authenticated-ike states: 0
Oct 8 11:04:08.108304: | authenticated-ipsec states: 0
Oct 8 11:04:08.110246: |IKEv2 transform ID: AUTH_HMAC_SHA2_512_256
(0xe)
Oct 8 11:04:08.110266: |IKEv2 transform ID: AUTH_HMAC_SHA2_256_128
(0xc)
Oct 8 11:04:08.110286: |IKEv2 transform ID: AUTH_HMAC_SHA1_96 (0x2)
Oct 8 11:04:08.110517: |IKEv2 transform ID: AUTH_HMAC_SHA2_512_256
(0xe)
Oct 8 11:04:08.110537: |IKEv2 transform ID: AUTH_HMAC_SHA2_256_128
(0xc)
Oct 8 11:04:08.110557: |IKEv2 transform ID: AUTH_HMAC_SHA1_96 (0x2)
Oct 8 11:04:08.110976: | established-authenticated-ike states: 0
Oct 8 11:04:08.110981: | authenticated-ipsec states: 0
Oct 8 11:04:08.125827: | v2 state object #1 found, in STATE_PARENT_I1
Oct 8 11:04:08.125839: | found state #1
Oct 8 11:04:08.126016: | selected state microcode Initiator: process
IKE_SA_INIT reply, initiate IKE_AUTH
Oct 8 11:04:08.126021: | calling processor Initiator: process IKE_SA_INIT
reply, initiate IKE_AUTH
Oct 8 11:04:08.126398: |IKEv2 transform ID: AUTH_HMAC_SHA1_96 (0x2)
Oct 8 11:04:08.128316: | established-authenticated-ike states: 0
Oct 8 11:04:08.128321: | authenticated-ipsec states: 0
Oct 8 11:04:08.128356: |exchange type: ISAKMP_v2_AUTH (0x23)
Oct 8 11:04:08.128686: | next payload type: setting 'IKEv2 Certificate
Request Payload'.'next payload type' to IKEv2 Authentication Payload
(39:ISAKMP_NEXT_v2AUTH)
Oct 8
Re: [Swan] private key for cert Thor not found in local cache; loading from NSS DB
Yes, sir. That actually helps me understand and confirm a few things. My lab setup has two hosts. Each host is in a different network routed through a firewall with no NAT. They work perfectly creating SA and having no problems. But when ipsechost01 tries to talk to the AWS instances check out ipsechost01 to Thor(AWS). Which is AWS NAT with ipsechost behind a firewall, also NAT. Feel free to give me example configs or anything else you want me to try this is all lab stuff and I have time so I can be your lab monkey. * This is ipsechost01 and ejbca working in OE action* 000 #1: "private#0.0.0.0/0"[1] ...192.168.57.3:500 STATE_PARENT_R2 (received v2I2, PARENT SA established); EVENT_v2_SA_REPLACE_IF_USED_IKE in 3328s; newest ISAKMP; idle; 000 #2: "private#0.0.0.0/0"[1] ...192.168.57.3:500 STATE_V2_IPSEC_R (IPsec SA established); EVENT_v2_SA_REPLACE_IF_USED in 28528s; newest IPSEC; eroute owner; isakmp#1; idle; 000 #2: "private#0.0.0.0/0"[1] ...192.168.57.3 esp.84f01efa@192.168.57.3 esp.67e30a4c@192.168.56.109 tun.0@192.168.57.3 tun.0@192.168.56.109 ref=0 refhim=0 Traffic: ESPin=84B ESPout=84B! ESPmax=0B 000 logs from ejbca with ipsechost01 as source of connection Oct 7 17:02:27.658858: | returning since no better match then original best_found Oct 7 17:02:27.658864: | Peer ID matches and no better connection found - continuing with existing connection Oct 7 17:02:27.658902: | checking keyid 'C=US, ST=CA, L=Palo Alto, O=mycompany, OU=Level5, CN=ipsechost1, E=ad...@mycompany.com' for match with 'C=US, ST=CA, L=Palo Alto, O=mycompany, OU=Level5, CN=ipsechost1, E= ad...@mycompany.com' Oct 7 17:02:27.658972: "private#0.0.0.0/0"[2] ...192.168.57.3 #3: Authenticated using RSA Oct 7 17:02:27.659070: | private key for cert ejbca not found in local cache; loading from NSS DB Oct 7 17:02:27.662565: |tsi[0] 0-65535: exact port match with 0. fitness 65536 Oct 7 17:02:27.662568: |tsr[0] 0-65535: exact port match with 0. fitness 65536 Oct 7 17:02:27.662571: | best ports fit so far: tsi[0] fitrange_i 65536, tsr[0] fitrange_r 65536, matchiness 131072 Oct 7 17:02:27.662575: | protocol 0 and tsi[0].ipprotoid 0: exact match Oct 7 17:02:27.662578: | protocol 0 and tsr[0].ipprotoid 0: exact match Oct 7 17:02:27.662580: | best protocol fit so far: tsi[0] fitrange_i 255, tsr[0] fitrange_r 255, matchiness 510 Oct 7 17:02:27.662608: | selecting default construvted local ESP/AH proposals for private#0.0.0.0/0 (IKE SA responder matching remote ESP/AH proposals) Oct 7 17:02:27.662620: "private#0.0.0.0/0"[2] ...192.168.57.3 #3: constructed local ESP/AH proposals for private#0.0.0.0/0 (IKE SA responder matching remote ESP/AH proposals): 1:ESP:ENCR=AES_GCM_C_256;INTEG=NONE;ESN=DISABLED 2:ESP:ENCR=AES_GCM_C_128;INTEG=NONE;ESN=DISABLED 3:ESP:ENCR=AES_CBC_256;INTEG=HMAC_SHA2_512_256,HMAC_SHA2_256_128;ESN=DISABLED 4:ESP:ENCR=AES_CBC_128;INTEG=HMAC_SHA2_512_256,HMAC_SHA2_256_128;ESN=DISABLED 5:ESP:ENCR=AES_CBC_128;INTEG=HMAC_SHA1_96;ESN=DISABLED (default) Oct 7 17:02:27.662624: | Comparing remote proposals against IKE SA responder matching remote ESP/AH proposals 5 local proposals Oct 7 17:02:27.662632: | remote proposal 1 matches local proposal 1 Oct 7 17:02:27.662639: | remote proposal 2 does not match; unmatched remote transforms: ENCR+ESN Oct 7 17:02:27.662645: | remote proposal 3 does not match; unmatched remote transforms: ENCR+INTEG+ESN Oct 7 17:02:27.662651: | remote proposal 4 does not match; unmatched remote transforms: ENCR+INTEG+ESN Oct 7 17:02:27.662657: | remote proposal 5 does not match; unmatched remote transforms: ENCR+INTEG+ESN - *Here's ipsechost01 tries to talk to Thor(AWS instance) * Oct 7 16:42:43.277322: | v2 state object #3 found, in STATE_PARENT_I1 Oct 7 16:42:43.277332: | found state #3 Oct 7 16:42:43.279975: | next payload type: setting 'IKEv2 Certificate Request Payload'.'next payload type' to IKEv2 Authentication Payload (39:ISAKMP_NEXT_v2AUTH) Oct 7 16:42:43.279978: | *emit IKEv2 Authentication Payload: Oct 7 16:42:43.279988: | next payload type: saving payload location 'IKEv2 Authentication Payload'.'next payload type' Oct 7 16:42:43.283436: | emitting 256 raw bytes of rsa signature into IKEv2 Authentication Payload Oct 7 16:42:43.283492: | emitting length of IKEv2 Authentication Payload: 264 Oct 7 16:42:43.283543: | next payload type: previous 'IKEv2 Authentication Payload'.'next payload type' matches 'IKEv2 Security Association Payload' (33:ISAKMP_NEXT_v2SA) Oct 7 16:42:43.309983: | v2 state object #4 found, in STATE_PARENT_I2 Oct 7 16:42:43.309985: | found state #4 Oct 7 16:42:43.310116: |Notify Message Type: v2N_AUTHENTICATION_FAILED (0x18) Oct 7 16:42:43.310121: | selected state microcode Initiator: process AUTHENTICATION_FAILED AUTH notification Oct 7 16:42:43.310125: | calling processor Initiator: process AUTHENTICATION_FAILED AUTH notification
