[Swan] Problems converting from OpenSWAN to LibreSWAN

[Nels Lindquist]

-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA1

On 5/6/2014 3:33 PM, Paul Wouters wrote:

> Can you give me a new plutodebug=all log? The previous one just 
> shows no match. It might also help me if you add the output of 
> "ipsec barf".

Looking through the debug log myself, I noticed a couple of things.
The first was that I was seeing "Both are NATted", which is incorrect.

I changed forceencaps to "no", but that didn't fix the issue.

The other thing I noticed was this:

May  7 07:57:00 mail pluto[28834]: | emitting length of ISAKMP NAT-D
Payload: 24
May  7 07:57:00 mail pluto[28834]: | padding IKE message with 3 bytes
May  7 07:57:00 mail pluto[28834]: | emitting 3 zero bytes of message
padding into ISAKMP Message
May  7 07:57:00 mail pluto[28834]: | emitting length of ISAKMP
Message: 572
May  7 07:57:00 mail pluto[28834]: | main inI2_outR2: starting async
DH calculation (group=14)
May  7 07:57:00 mail pluto[28834]: | started looking for secret for
@mail.maei.ca->209.82.26.89 of kind PPK_PSK
May  7 07:57:00 mail pluto[28834]: | actually looking for secret for
@mail.maei.ca->209.82.26.89 of kind PPK_PSK
May  7 07:57:00 mail pluto[28834]: | line 1: key type
PPK_PSK(@mail.maei.ca) to type PPK_RSA
May  7 07:57:00 mail pluto[28834]: | concluding with best_match=0
best=(nil) (lineno=-1)
May  7 07:57:00 mail pluto[28834]: | parent1 type: 7 group: 14 len: 2776
May  7 07:57:00 mail pluto[28834]: | Copying DH pub key pointer to be
sent to a thread helper
May  7 07:57:00 mail pluto[28834]: | 0: w->pcw_dead: 0 w->pcw_work: 0
cnt: 1
May  7 07:57:00 mail pluto[28834]: | asking helper 0 to do compute
dh+iv op on seq: 2 (len=2776, pcw_work=1)
May  7 07:57:00 mail pluto[28834]: | crypto helper write of request:
cnt=2776<wlen=2776.
May  7 07:57:00 mail pluto[28834]: | deleting event for #1
May  7 07:57:00 mail pluto[28834]: | inserting event
EVENT_CRYPTO_FAILED, timeout in 300 seconds for #1
May  7 07:57:00 mail pluto[28834]: | event added after event
EVENT_PENDING_PHASE2
May  7 07:57:00 mail pluto[28834]: | started dh_secretiv, returned:
stf=STF_SUSPEND
May  7 07:57:00 mail pluto[28834]: | complete state transition with STF_OK
May  7 07:57:00 mail pluto[28834]: "L2TP-Win2KXP"[1] 209.82.26.89 #1:
transition from state STATE_MAIN_R1 to state STATE_MAIN_R2
May  7 07:57:00 mail pluto[28834]: | deleting event for #1

Just in case, I changed leftid to "%fromcert", and now it's doing this:

May  7 10:26:57 mail pluto[12925]: | padding IKE message with 3 bytes
May  7 10:26:57 mail pluto[12925]: | emitting 3 zero bytes of message
padding into ISAKMP Message
May  7 10:26:57 mail pluto[12925]: | emitting length of ISAKMP
Message: 572
May  7 10:26:57 mail pluto[12925]: | main inI2_outR2: starting async
DH calculation (group=14)
May  7 10:26:57 mail pluto[12925]: | started looking for secret for
C=CA, ST=Alberta, L=Edmonton, O=Morningstar Air Express Inc.,
OU=Information Technology, CN=mail.maei.ca->209.82.26.89 of kind PPK_PSK
May  7 10:26:57 mail pluto[12925]: | actually looking for secret for
C=CA, ST=Alberta, L=Edmonton, O=Morningstar Air Express Inc.,
OU=Information Technology, CN=mail.maei.ca->209.82.26.89 of kind PPK_PSK
May  7 10:26:57 mail pluto[12925]: | line 1: key type PPK_PSK(C=CA,
ST=Alberta, L=Edmonton, O=Morningstar Air Express Inc., OU=Information
Technology, CN=mail.maei.ca) to type PPK_RSA
May  7 10:26:57 mail pluto[12925]: | concluding with best_match=0
best=(nil) (lineno=-1)
May  7 10:26:57 mail pluto[12925]: | parent1 type: 7 group: 14 len: 2776
May  7 10:26:57 mail pluto[12925]: | Copying DH pub key pointer to be
sent to a thread helper
May  7 10:26:57 mail pluto[12925]: | 0: w->pcw_dead: 0 w->pcw_work: 0
cnt: 1
May  7 10:26:57 mail pluto[12925]: | asking helper 0 to do compute
dh+iv op on seq: 2 (len=2776, pcw_work=1)
May  7 10:26:57 mail pluto[12925]: | crypto helper write of request:
cnt=2776<wlen=2776.
May  7 10:26:57 mail pluto[12925]: | deleting event for #1
May  7 10:26:57 mail pluto[12925]: | inserting event
EVENT_CRYPTO_FAILED, timeout in 300 seconds for #1
May  7 10:26:57 mail pluto[12925]: | event added after event
EVENT_PENDING_PHASE2
May  7 10:26:57 mail pluto[12925]: | started dh_secretiv, returned:
stf=STF_SUSPEND
May  7 10:26:57 mail pluto[12925]: | complete state transition with STF_OK
May  7 10:26:57 mail pluto[12925]: "L2TP-Win2KXP"[1] 209.82.26.89 #1:
transition from state STATE_MAIN_R1 to state STATE_MAIN_R2
May  7 10:26:57 mail pluto[12925]: | deleting event for #1

So why is it looking for key type PPK_PSK? I'm assuming "best_match=0
best=(nil) (lineno=-1)" means it didn't like the certificate for some
reason.

Just in case, I also tried setting "leftsendcert=always" (it doesn't
like "leftsendcert=yes", by the way, despite the man page claiming
they're synonyms) but it made no difference.


- -- 
Nels Lindquist
<nlindq at maei.ca>

-----BEGIN PGP SIGNATURE-----
Version: GnuPG v2.0.20 (MingW32)
Comment: Using GnuPG with Thunderbird - http://www.enigmail.net/

iEYEARECAAYFAlNqZrsACgkQh6z5POoOLgTP7wCgpeztJqRAxs9Pz2abcRBg3ASU
0QQAnRqPW3LykjyZ2nFPawqN6mj69xS4
=HlIR
-----END PGP SIGNATURE-----