[Swan] private key for cert Thor not found in local cache; loading from NSS DB

rayv33n rayv33n at gmail.com
Mon Oct 8 00:12:59 UTC 2018 

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 at 192.168.57.3
esp.67e30a4c at 192.168.56.109 tun.0 at 192.168.57.3 tun.0 at 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=admin at mycompany.com' for match
with 'C=US, ST=CA, L=Palo Alto, O=mycompany, OU=Level5, CN=ipsechost1, E=
admin at 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
Oct  7 16:42:43.310129: "private#0.0.0.0/0"[2] ...13.57.200.87 #4: IKE SA
authentication request rejected: AUTHENTICATION_FAILED
Oct  7 16:42:43.310241: | v2 state object #3 found, in STATE_PARENT_I2
Oct  7 16:42:43.310249: | found state #3
Oct  7 16:42:43.310266: | no useful state microcode entry found
Oct  7 16:42:46.289302: "private#0.0.0.0/0"[2] ...13.57.200.87 #4:
STATE_PARENT_I2: 3 second timeout exceeded after 0 retransmits.  Possible
authentication failure: no acceptable response to our first encrypted
message
Oct  7 16:42:46.289344: | OE: delete_state orphaning hold with failureshunt
drop (negotiation shunt would have been trap)
Oct  7 16:42:46.289346: | failureshunt == negotiationshunt, no replace
needed
Oct  7 16:42:46.289363: | add bare shunt 0x55f75a704a58 172.16.1.61/32:0
--0--> 13.57.200.87/32:0 => %drop 0    oe-failing
Oct  7 16:42:46.289378: | No need to replace negotiation_shunt with
failure_shunt - they are the same
Oct  7 16:42:48.526882: | keeping recent bare shunt 0x55f75a704a58
172.16.1.61/32:0 --0--> 13.57.200.87/32:0 => %drop 0    oe-failing

On Sun, Oct 7, 2018 at 2:50 PM Paul Wouters <paul at nohats.ca> wrote:

> On Sun, 7 Oct 2018, rayv33n wrote:
>
> > Followed all your suggestions and the connection information shows the
> that the oppo sees that IP addresses across
> > the connection down to the %fromcert. What's different this time is the
> +MS+S=C which I have no idea what that is.
> > I blew away the /etc/ipsec.d/*.db and when back to the instruction on
> how to create it.
>
> That string is a clumpsy way to show identifications used, ignore it.
>
> > Oct  7 18:54:28.198237: | private key for cert Thor not found in local
> cache; loading from NSS DB
>
> I am still very confused about this. It is abnormal and other people
> don't run into this issue at all. So I am really trying to see what
> is different in your setup. Can you configure a static ip to ip
> connection with the same certificates? Does that work?
>
> Maybe try adding leftsendca=all ? Although the intermediary should
> not be needed since it appears in your NSS and is marked as trusted
> already. Perhaps you are missing some expected flags in the EKU or KU
> for NSS?
>
> > The regular config I have work if there is not NAT involved.
>
> So whether or not there is NAT should not affect the authentication at
> all?
>
> Paul
>


-- 
You are FREE to become a slave

Key ID: 9A452ABAA4593489
Finger Print: 7A8A 5849 ED44 52B1 0D8A EDAC 9A45 2ABA A459 3489
*Pub Key: *
http://pgp.mit.edu:11371/pks/lookup?search=rayv33n%40gmail.com&op=index
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <https://lists.libreswan.org/pipermail/swan/attachments/20181007/c554a041/attachment.html>

More information about the Swan mailing list