[Swan] private key for cert Thor not found in local cache; loading from NSS DB
rayv33n
rayv33n at gmail.com
Thu Oct 4 15:11:11 UTC 2018
No sure that to make of this message. Originally I thought it was a warning
letting me know that after restarting ipsec that cache was check and then
private key
had to be loaded again from NSS. I'm not sure where to begin to
troubleshoot this and would appreciate some guidance. I'm fairly certain
this is a NAT issue but tcpdump
show 4500/UDP being used immediately after initial handshake. I'm still not
quiet sure where the apparatus is breaking down so unsure of where to look
After days of
unsuccessfully troubleshoot I'm finally coming to the list. Goals it so
make a mesh network hosts only and not servers across lots of divers
infrastructure.
network setup.* ipsechost1(172.16.1.61)---> Netgate(76.1XX.2XX.2XX.2xx)
<--> AWS(13.57.XXX.XX) --> Thor(10.0.0.47)*
Using NSS of course with /etc/ipsec.d/nsspassword(NSS Certificate
DB:12345678)
#Thor god of thunder
conn private
# IPsec mandatory
hostaddrfamily=ipv4
rightrsasigkey=%cert
right=%opportunisticgroup
rightid=%fromcert
rightca=%same
rightmodecfgclient=yes
leftsubnet=10.0.0.47/32
left=%defaultroute
leftcert=Thor
leftsendcert=always
leftid=%cert
leftnexthop=13.57.xxx.xx
leftrsasigkey=%cert
#narrowing=yes
type=tunnel
ikev2=insist
negotiationshunt=hold
failureshunt=drop
keyingtries=0
retransmit-timeout=3s
auto=ondemand
ike=aes256-sha1;modp2048
phase2alg=aes256-sha1;modp2048
#ipsechost1 7 of 9 tertiary 12
conn private
# IPsec mandatory
hostaddrfamily=ipv4
rightrsasigkey=%cert
right=%opportunisticgroup
rightid=%fromcert
rightca=%same
left=%defaultroute
leftcert=ipsechost1
leftsendcert=always
leftid=%fromcert
leftrsasigkey=%cert
#narrowing=yes
type=tunnel
ikev2=insist
negotiationshunt=hold
failureshunt=drop
keyingtries=0
retransmit-timeout=3s
auto=ondemand
ike=aes256-sha1;modp2048
phase2alg=aes256-sha1;modp2048
#debug "control"
oppo instantiate d="private#0.0.0.0/0" from c="private#0.0.0.0/0" with
c->routing prospective erouted, d->routing unrouted
new oppo instance:
10.0.0.47/32===10.0.0.47---13.57.XXX.XX...76.1XX.2XX.2XX.2xx[%fromcert,+MC+S=C]
oppo_instantiate() instantiated "[1] *...76.1XX.2XX.2XX.2xx"private#0.0.0.0/0
<http://0.0.0.0/0>:
10.0.0.47/32===10.0.0.47---13.57.XXX.XX...76.1XX.2XX.2XX.2xx[%fromcert,+MC+S=C]*
found connection: private#0.0.0.0/0[1] ...76.1XX.2XX.2XX.2xx with policy
RSASIG+IKEV2_ALLOW
constructing local IKE proposals for private#0.0.0.0/0 (IKE SA responder
matching remote proposals)
Oct 4 14:38:50.476485: packet from 76.1XX.2XX.2XX.2xx:500: constructed
local IKE proposals for private#0.0.0.0/0 (IKE SA responder matching remote
proposals):
1:IKE:ENCR=AES_CBC_256;PRF=HMAC_SHA1;INTEG=HMAC_SHA1_96;DH=MODP2048
processing: start state #1 connection "private#0.0.0.0/0"[1]
...76.1XX.2XX.2XX.2xx (in initialize_new_state() at ipsec_doi.c:483)
processing: [RE]START state #1 connection "private#0.0.0.0/0"[1]
...76.1XX.2XX.2XX.2xx (in initialize_new_state() at ipsec_doi.c:501)
processing: [RE]START state #1 connection "private#0.0.0.0/0"[1]
...76.1XX.2XX.2XX.2xx (in log_stf_suspend() at ikev2.c:2690)
"private#0.0.0.0/0"[1] ...76.1XX.2XX.2XX.2xx #1 complete v2 state
STATE_PARENT_R1 transition with STF_SUSPEND suspended from
complete_v2_state_transition:2763
processing: stop state #1 connection "private#0.0.0.0/0"[1]
...76.1XX.2XX.2XX.2xx (in process_md() at demux.c:395)
processing: start state #1 connection "private#0.0.0.0/0"[1]
...76.1XX.2XX.2XX.2xx (in schedule_event_now_cb() at server.c:558)
going to send a certreq
processing: [RE]START state #1 connection "private#0.0.0.0/0"[1]
...76.1XX.2XX.2XX.2xx (in complete_v2_state_transition() at ikev2.c:2788)
processing: stop state #1 connection "private#0.0.0.0/0"[1]
...76.1XX.2XX.2XX.2xx (in schedule_event_now_cb() at server.c:561)
processing: start state #1 connection "private#0.0.0.0/0"[1]
...76.1XX.2XX.2XX.2xx (in processed_retransmit() at ikev2.c:1182)
processing: [RE]START state #1 connection "private#0.0.0.0/0"[1]
...76.1XX.2XX.2XX.2xx (in ikev2_process_packet() at ikev2.c:1552)
processing: start connection "private#0.0.0.0/0"[1] ...76.1XX.2XX.2XX.2xx
(BACKGROUND) (in ikev2_process_packet() at ikev2.c:1557)
processing: stop state #1 connection "private#0.0.0.0/0"[1]
...76.1XX.2XX.2XX.2xx (in process_md() at demux.c:395)
processing: resume connection "private#0.0.0.0/0"[1] ...76.1XX.2XX.2XX.2xx
(in process_md() at demux.c:395)
processing: stop connection "private#0.0.0.0/0"[1] ...76.1XX.2XX.2XX.2xx
(in process_md() at demux.c:396)
processing: start state #1 connection "private#0.0.0.0/0"[1]
...76.1XX.2XX.2XX.2xx (in processed_retransmit() at ikev2.c:1182)
processing: [RE]START state #1 connection "private#0.0.0.0/0"[1]
...76.1XX.2XX.2XX.2xx (in ikev2_process_packet() at ikev2.c:1552)
processing: start connection "private#0.0.0.0/0"[1] ...76.1XX.2XX.2XX.2xx
(BACKGROUND) (in ikev2_process_packet() at ikev2.c:1557)
processing: stop state #1 connection "private#0.0.0.0/0"[1]
...76.1XX.2XX.2XX.2xx (in process_md() at demux.c:395)
processing: resume connection "private#0.0.0.0/0"[1] ...76.1XX.2XX.2XX.2xx
(in process_md() at demux.c:395)
processing: stop connection "private#0.0.0.0/0"[1] ...76.1XX.2XX.2XX.2xx
(in process_md() at demux.c:396)
processing: start state #1 connection "private#0.0.0.0/0"[1]
...76.1XX.2XX.2XX.2xx (in processed_retransmit() at ikev2.c:1182)
processing: [RE]START state #1 connection "private#0.0.0.0/0"[1]
...76.1XX.2XX.2XX.2xx (in ikev2_process_packet() at ikev2.c:1552)
processing: start connection "private#0.0.0.0/0"[1] ...76.1XX.2XX.2XX.2xx
(BACKGROUND) (in ikev2_process_packet() at ikev2.c:1557)
processing: stop state #1 connection "private#0.0.0.0/0"[1]
...76.1XX.2XX.2XX.2xx (in process_md() at demux.c:395)
processing: resume connection "private#0.0.0.0/0"[1] ...76.1XX.2XX.2XX.2xx
(in process_md() at demux.c:395)
processing: stop connection "private#0.0.0.0/0"[1] ...76.1XX.2XX.2XX.2xx
(in process_md() at demux.c:396)
processing: start state #1 connection "private#0.0.0.0/0"[1]
...76.1XX.2XX.2XX.2xx (in processed_retransmit() at ikev2.c:1182)
processing: [RE]START state #1 connection "private#0.0.0.0/0"[1]
...76.1XX.2XX.2XX.2xx (in ikev2_process_packet() at ikev2.c:1552)
processing: start connection "private#0.0.0.0/0"[1] ...76.1XX.2XX.2XX.2xx
(BACKGROUND) (in ikev2_process_packet() at ikev2.c:1557)
processing: [RE]START state #1 connection "private#0.0.0.0/0"[1]
...76.1XX.2XX.2XX.2xx (in log_stf_suspend() at ikev2.c:2690)
"private#0.0.0.0/0"[1] ...76.1XX.2XX.2XX.2xx #1 suspended from
complete_v2_state_transition:2763
processing: stop state #1 connection "private#0.0.0.0/0"[1]
...76.1XX.2XX.2XX.2xx (in process_md() at demux.c:395)
processing: resume connection "private#0.0.0.0/0"[1] ...76.1XX.2XX.2XX.2xx
(in process_md() at demux.c:395)
processing: stop connection "private#0.0.0.0/0"[1] ...76.1XX.2XX.2XX.2xx
(in process_md() at demux.c:396)
processing: start state #1 connection "private#0.0.0.0/0"[1]
...76.1XX.2XX.2XX.2xx (in schedule_event_now_cb() at server.c:558)
Now let's proceed with payload (ISAKMP_NEXT_v2CERT)
Now let's proceed with payload (ISAKMP_NEXT_v2CERTREQ)
processing: [RE]START state #1 connection "private#0.0.0.0/0"[1]
...76.1XX.2XX.2XX.2xx (in for_each_state() at state.c:1600)
processing: stop state #1 connection "private#0.0.0.0/0"[1]
...76.1XX.2XX.2XX.2xx (in for_each_state() at state.c:1600)
processing: resume state #1 connection "private#0.0.0.0/0"[1]
...76.1XX.2XX.2XX.2xx (in for_each_state() at state.c:1600)
Oct 4 14:38:50.506799: "private#0.0.0.0/0"[1] ...76.1XX.2XX.2XX.2xx
#1: c*ertificate
verified OK: E=admin at mycompany.com
<admin at mycompany.com>,CN=ipsechost1,OU=Level5,O=mycompany,L=Palo
Alto,ST=CA,C=US*
Oct 4 14:38:50.507848: "private#0.0.0.0/0"[1] ...76.1XX.2XX.2XX.2xx
#1: *Authenticated
using RSA*
* private key for cert Thor not found in local cache; loading from NSS DB*
searching for certificate PKK_RSA:AwEAAeaaN vs PKK_RSA:AwEAAeaaN
*Oct 4 14:38:50.512359: "private#0.0.0.0/0 <http://0.0.0.0/0>"[1]
...76.1XX.2XX.2XX.2xx #1: responding to AUTH message (ID 1) from
76.1XX.2XX.2XX.2xx:61427 with encrypted notification AUTHENTICATION_FAILED*
processing: [RE]START state #1 connection "private#0.0.0.0/0"[1]
...76.1XX.2XX.2XX.2xx (in complete_v2_state_transition() at ikev2.c:2788)
processing: [RE]START state #1 connection "private#0.0.0.0/0"[1]
...76.1XX.2XX.2XX.2xx (in delete_state() at state.c:969)
Oct 4 14:38:50.512478: "private#0.0.0.0/0"[1] ...76.1XX.2XX.2XX.2xx #1:
deleting state (STATE_PARENT_R2) and sending notification
in connection_discard for connection private#0.0.0.0/0
processing: start connection "private#0.0.0.0/0"[1] ...76.1XX.2XX.2XX.2xx
(BACKGROUND) (in delete_connection() at connections.c:263)
left=76.1XX.2XX.2XX.2xx
processing: stop connection "private#0.0.0.0/0" (BACKGROUND) (in
delete_connection() at connections.c:313)
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <https://lists.libreswan.org/pipermail/swan/attachments/20181004/a287a741/attachment-0001.html>
More information about the Swan
mailing list