[strongSwan] questions on syslog output; linux server/mac client RSA certificate auth

Thu Dec 18 01:59:21 CET 2014

Yes, that's the public ip address of the client.

I went in and added
rightsourceip=
to the ipsec.conf (but that doesn't reflect in the syslog after doing
an ipsec restart)

I can't find anything in the vpn connection setup dialog on the mac.
I tried checking "send all traffic thru vpn" but there was nothing
about requesting a virtual ip.
I also checked "more logging" but the system.log output on the mac
client looks pretty much the same.  The relevant bits on server side
changed a little bit:

Dec 17 16:50:55 vpn charon: 03[CFG] looking for a child config for
[vpn ip]/32[udp/l2f] === [public client ip]/32[udp/51055]
Dec 17 16:50:55 vpn charon: 03[CFG] proposing traffic selectors for us:
Dec 17 16:50:55 vpn charon: 03[CFG]  0.0.0.0/0
Dec 17 16:50:55 vpn charon: 03[CFG] proposing traffic selectors for other:
Dec 17 16:50:55 vpn charon: 03[CFG]  [public client ip]/32
Dec 17 16:50:55 vpn charon: 03[CFG]   candidate "roadwarrior-ikev1"
with prio 1+1
Dec 17 16:50:55 vpn charon: 03[CFG] found matching child config
"roadwarrior-ikev1" with prio 2
Dec 17 16:50:55 vpn charon: 03[CFG]  config: [public client ip]/32,
received: [public client ip]/32[udp/51055] => match: [public client
ip]/32[udp/51055]
Dec 17 16:50:55 vpn charon: 03[CFG] selecting traffic selectors for us:
Dec 17 16:50:55 vpn charon: 03[CFG]  config: 0.0.0.0/0, received: [vpn
ip]/32[udp/l2f] => match: [vpn ip]/32[udp/l2f]
Dec 17 16:50:55 vpn charon: 03[IKE] no matching CHILD_SA config found

On Wed, Dec 17, 2014 at 1:26 PM, Noel Kuntze <noel at familie-kuntze.de> wrote:
>
> -----BEGIN PGP SIGNED MESSAGE-----
> Hash: SHA256
>
> Hello Cindy,
>
> Does that client_ip in [1] represent the exchanged virtual ip or
> the public IP of the client? If it does, then it doesn't work together with
> rightsourceip. Please unset it by specifying an empty value ("rightsourceip= ")
> and test it again.
> You might also want to look at the client settings to see if you can somehow
> make your client request a virtual IP.
>
> [1] Dec 17 07:33:46 vpn charon: 15[CFG] looking for a child config for vpn_ip/32[udp/l2f] === client_ip/32[udp/62338]
>
> Mit freundlichen Grüßen/Regards,
> Noel Kuntze
>
> GPG Key ID: 0x63EC6658
> Fingerprint: 23CA BB60 2146 05E7 7278 6592 3839 298F 63EC 6658
>
> Am 17.12.2014 um 21:36 schrieb Cindy Moore:
>> OK, ipsec.conf, strongswan.conf and mods:
>> https://bpaste.net/show/b25f29e5f4d0
>>
>> On Wed, Dec 17, 2014 at 12:24 PM, Noel Kuntze <noel at familie-kuntze.de> wrote:
>>>
>> Hello Cindy,
>>
>> Well, paste your ipsec.conf and strongswan.conf, as well as any files
>> you modified in /etc/strongswan.d/ to a pastebin service.
>> (bpaste.net for example).
>>
>> Mit freundlichen Grüßen/Regards,
>> Noel Kuntze
>>
>> GPG Key ID: 0x63EC6658
>> Fingerprint: 23CA BB60 2146 05E7 7278 6592 3839 298F 63EC 6658
>>
>> Am 17.12.2014 um 21:25 schrieb Cindy Moore:
>> >>> Not at all... what's the best way to show you that?  Eg ipsec listall?
>> >>>  The strongswan.conf just pulls in everything from strongswan.d/, I
>> >>> can list those.  Let me know.
>> >>>
>> >>> On Wed, Dec 17, 2014 at 12:19 PM, Noel Kuntze <noel at familie-kuntze.de> wrote:
>> >>>>
>> >>> Hello Cindy,
>> >>>
>> >>> Yes, I'm talking about setting up a daemon on the server.
>> >>> Do you mind posting the current configuration of strongSwan
>> >>> on the server?
>> >>>
>> >>> Mit freundlichen Grüßen/Regards,
>> >>> Noel Kuntze
>> >>>
>> >>> GPG Key ID: 0x63EC6658
>> >>> Fingerprint: 23CA BB60 2146 05E7 7278 6592 3839 298F 63EC 6658
>> >>>
>> >>> Am 17.12.2014 um 21:08 schrieb Cindy Moore:
>> >>>>>> Hm, I have leftsubnet=0.0.0.0/0
>> >>>>>> But since it's a roadwarrior configuration, I haven't set the
>> >>>>>> rightsubnet at all (on the server).
>> >>>>>> Are you talking about configuring xl2tp or another l2tp daemon on the
>> >>>>>> server or on the client?
>> >>>>>>
>> >>>>>> Thanks,
>> >>>>>> --Cindy
>> >>>>>>
>> >>>>>> On Wed, Dec 17, 2014 at 12:00 PM, Noel Kuntze <noel at familie-kuntze.de> wrote:
>> >>>>>>>
>> >>>>>> Hello Cindy,
>> >>>>>>
>> >>>>>> I think the client wants to negotiate a TS covering only the IPs with the udp port for l2tp
>> >>>>>> on the left and udp port 62338 on the other side. Make sure your configured
>> >>>>>> leftsubnet and rightsubnet contain that combination. It seems you'll probably also have to fiddle around
>> >>>>>> with xl2tp or another l2tp daemon to make your Mac OSX configuration work.
>> >>>>>>
>> >>>>>> Mit freundlichen Grüßen/Regards,
>> >>>>>> Noel Kuntze
>> >>>>>>
>> >>>>>> GPG Key ID: 0x63EC6658
>> >>>>>> Fingerprint: 23CA BB60 2146 05E7 7278 6592 3839 298F 63EC 6658
>> >>>>>>
>> >>>>>> Am 17.12.2014 um 19:30 schrieb Cindy Moore:
>> >>>>>>>>> Hm, can this portion be explained in a bit more detail?
>> >>>>>>>>>
>> >>>>>>>>> Dec 17 07:33:46 vpn charon: 15[ENC] parsed QUICK_MODE request
>> >>>>>>>>> 4114711345 [ HASH SA No ID ID NAT-OA NAT-OA ]
>> >>>>>>>>> Dec 17 07:33:46 vpn charon: 15[IKE] changing received traffic
>> >>>>>>>>> selectors 10.0.1.32/32[udp/62338]=== vpn_ip/32[udp/l2f] due to NAT
>> >>>>>>>>> Dec 17 07:33:46 vpn charon: 15[CFG] looking for a child config for
>> >>>>>>>>> vpn_ip/32[udp/l2f] === client_ip/32[udp/62338]
>> >>>>>>>>> Dec 17 07:33:46 vpn charon: 15[CFG] proposing traffic selectors for us:
>> >>>>>>>>> Dec 17 07:33:46 vpn charon: 15[CFG]  0.0.0.0/0
>> >>>>>>>>> Dec 17 07:33:46 vpn charon: 15[CFG] proposing traffic selectors for other:
>> >>>>>>>>> Dec 17 07:33:46 vpn charon: 15[CFG]  dynamic
>> >>>>>>>>> Dec 17 07:33:46 vpn charon: 15[IKE] no matching CHILD_SA config found
>> >>>>>>>>>
>> >>>>>>>>> Looks for a child config, doesn't find one, what's going on here?
>> >>>>>>>>>
>> >>>>>>>>> On Wed, Dec 17, 2014 at 7:57 AM, Cindy Moore <ctmoore at cs.ucsd.edu> wrote:
>> >>>>>>>>>> Maybe I'm just being dense, but what is "Main Mode"?
>> >>>>>>>>>>
>> >>>>>>>>>> OK, the reason I have xauth-noauth is that I was under the impression
>> >>>>>>>>>> mac os X *required* xauth because of ikev1. So removing this, I get
>> >>>>>>>>>>
>> >>>>>>>>>> Maybe I'm just being dense, but what is "Main Mode"?
>> >>>>>>>>>>
>> >>>>>>>>>> OK, the reason I had xauth-noauth is that I was under the impression
>> >>>>>>>>>> mac os X *required* xauth because of ikev1. So removing that line from
>> >>>>>>>>>> the conn, I get this.  It looks more successful on the server side
>> >>>>>>>>>> (I'm not seeing the messages I was asking about last time), and the
>> >>>>>>>>>> same on the client side.  At this point, it looks like they connect up
>> >>>>>>>>>> but then don't "hear" each other.  Any thoughts?
>> >>>>>>>>>>
>> >>>>>>>>>> (on linux server, /var/log/syslog)
>> >>>>>>>>>> Dec 17 07:33:45 vpn charon: 12[NET] received packet: from
>> >>>>>>>>>> client_ip[500] to vpn_ip[500] (300 bytes)
>> >>>>>>>>>> Dec 17 07:33:45 vpn charon: 12[ENC] parsed ID_PROT request 0 [ SA V V
>> >>>>>>>>>> V V V V V V V V V ]
>> >>>>>>>>>> Dec 17 07:33:45 vpn charon: 12[CFG] looking for an ike confi for
>> >>>>>>>>>> vpn_ip...client_ip
>> >>>>>>>>>> Dec 17 07:33:45 vpn charon: 12[CFG]   candidate: vpn_ip...%any, prio 1052
>> >>>>>>>>>> Dec 17 07:33:45 vpn charon: 12[CFG]   candidate: vpn_ip...%any, prio 1052
>> >>>>>>>>>> Dec 17 07:33:45 vpn charon: 12[CFG] found matching ike config:
>> >>>>>>>>>> vpn_ip...%any with prio 1052
>> >>>>>>>>>> Dec 17 07:33:45 vpn charon: 12[IKE] received NAT-T (RFC 3947) vendor ID
>> >>>>>>>>>> Dec 17 07:33:45 vpn charon: 12[IKE] received
>> >>>>>>>>>> draft-ietf-ipsec-nat-t-ike vendor ID
>> >>>>>>>>>> Dec 17 07:33:45 vpn charon: 12[IKE] received
>> >>>>>>>>>> draft-ietf-ipsec-nat-t-ike-08 vendor ID
>> >>>>>>>>>> Dec 17 07:33:45 vpn charon: 12[IKE] received
>> >>>>>>>>>> draft-ietf-ipsec-nat-t-ike-07 vendor ID
>> >>>>>>>>>> Dec 17 07:33:45 vpn charon: 12[IKE] received
>> >>>>>>>>>> draft-ietf-ipsec-nat-t-ike-06 vendor ID
>> >>>>>>>>>> Dec 17 07:33:45 vpn charon: 12[IKE] received
>> >>>>>>>>>> draft-ietf-ipsec-nat-t-ike-05 vendor ID
>> >>>>>>>>>> Dec 17 07:33:45 vpn charon: 12[IKE] received
>> >>>>>>>>>> draft-ietf-ipsec-nat-t-ike-04 vendor ID
>> >>>>>>>>>> Dec 17 07:33:45 vpn charon: 12[IKE] received
>> >>>>>>>>>> draft-ietf-ipsec-nat-t-ike-03 vendor ID
>> >>>>>>>>>> Dec 17 07:33:45 vpn charon: 12[IKE] received
>> >>>>>>>>>> draft-ietf-ipsec-nat-t-ike-02 vendor ID
>> >>>>>>>>>> Dec 17 07:33:45 vpn charon: 12[IKE] received
>> >>>>>>>>>> draft-ietf-ipsec-nat-t-ike-02\n vendor ID
>> >>>>>>>>>> Dec 17 07:33:45 vpn charon: 12[IKE] received DPD vendor ID
>> >>>>>>>>>> Dec 17 07:33:45 vpn charon: 12[IKE] client_ip is initiating a Main Mode IKE_SA
>> >>>>>>>>>> Dec 17 07:33:45 vpn charon: 12[IKE] IKE_SA (unnamed)[1] state change:
>> >>>>>>>>>> CREATED => CONNECTING
>> >>>>>>>>>> Dec 17 07:33:45 vpn charon: 12[CFG] selecting proposal:
>> >>>>>>>>>> Dec 17 07:33:45 vpn charon: 12[CFG]   no acceptable ENCRYPTION_ALGORITHM found
>> >>>>>>>>>> Dec 17 07:33:45 vpn charon: 12[CFG] selecting proposal:
>> >>>>>>>>>> Dec 17 07:33:45 vpn charon: 12[CFG]   no acceptable DIFFIE_HELLMAN_GROUP found
>> >>>>>>>>>> Dec 17 07:33:45 vpn charon: 12[CFG] selecting proposal:
>> >>>>>>>>>> Dec 17 07:33:45 vpn charon: 12[CFG]   proposal matches
>> >>>>>>>>>> Dec 17 07:33:45 vpn charon: 12[CFG] received proposals:
>> >>>>>>>>>> IKE:3DES_CBC/HMAC_SHA1_96/PRF_HMAC_SHA1/MODP_1024
>> >>>>>>>>>> Dec 17 07:33:45 vpn charon: 12[CFG] configured proposals:
>> >>>>>>>>>> IKE:AES_CBC_128/HMAC_SHA1_96/PRF_HMAC_SHA1/MODP_2048,
>> >>>>>>>>>> IKE:3DES_CBC/HMAC_SHA1_96/PRF_HMAC_SHA1/MODP_1536,
>> >>>>>>>>>> IKE:AES_CBC_128/AES_CBC_192/AES_CBC_256/3DES_CBC/AES_XCBC_96/AES_CMAC_96/HMAC_SHA1_96/HMAC_MD5_96/HMAC_SHA2_256_128/HMAC_SHA2_384_192/HMAC_SHA2_512_256/PRF_AES128_XCBC/PRF_AES128_CMAC/PRF_HMAC_SHA1/PRF_HMAC_MD5/PRF_HMAC_SHA2_256/PRF_HMAC_SHA2_384/PRF_HMAC_SHA2_512/MODP_2048/MODP_2048_224/MODP_2048_256/MODP_1536/MODP_3072/MODP_4096/MODP_8192/MODP_1024/MODP_1024_160
>> >>>>>>>>>> Dec 17 07:33:45 vpn charon: 12[CFG] selected proposal:
>> >>>>>>>>>> IKE:3DES_CBC/HMAC_SHA1_96/PRF_HMAC_SHA1/MODP_1024
>> >>>>>>>>>> Dec 17 07:33:45 vpn charon: 12[IKE] sending XAuth vendor ID
>> >>>>>>>>>> Dec 17 07:33:45 vpn charon: 12[IKE] sending DPD vendor ID
>> >>>>>>>>>> Dec 17 07:33:45 vpn charon: 12[IKE] sending NAT-T (RFC 3947) vendor ID
>> >>>>>>>>>> Dec 17 07:33:45 vpn charon: 12[ENC] generating ID_PROT response 0 [ SA V V V ]
>> >>>>>>>>>> Dec 17 07:33:45 vpn charon: 12[NET] sending packet: from vpn_ip[500]
>> >>>>>>>>>> to client_ip[500] (132 bytes)
>> >>>>>>>>>> Dec 17 07:33:45 vpn charon: 03[NET] sending packet: from vpn_ip[500]
>> >>>>>>>>>> to client_ip[500]
>> >>>>>>>>>> Dec 17 07:33:45 vpn charon: 01[NET] received packet: from
>> >>>>>>>>>> client_ip[500] to vpn_ip[500]
>> >>>>>>>>>> Dec 17 07:33:45 vpn charon: 01[NET] waiting for data on sockets
>> >>>>>>>>>> Dec 17 07:33:45 vpn charon: 04[NET] received packet: from
>> >>>>>>>>>> client_ip[500] to vpn_ip[500] (228 bytes)
>> >>>>>>>>>> Dec 17 07:33:45 vpn charon: 04[ENC] parsed ID_PROT request 0 [ KE No
>> >>>>>>>>>> NAT-D NAT-D ]
>> >>>>>>>>>> Dec 17 07:33:45 vpn charon: 04[IKE] remote host is behind NAT
>> >>>>>>>>>> Dec 17 07:33:45 vpn charon: 04[IKE] sending cert request for "C=US,
>> >>>>>>>>>> O=ThatsUs, CN=strongSwan Root CA"
>> >>>>>>>>>> Dec 17 07:33:45 vpn charon: 04[ENC] generating ID_PROT response 0 [ KE
>> >>>>>>>>>> No CERTREQ NAT-D NAT-D ]
>> >>>>>>>>>> Dec 17 07:33:45 vpn charon: 04[NET] sending packet: from vpn_ip[500]
>> >>>>>>>>>> to client_ip[500] (310 bytes)
>> >>>>>>>>>> Dec 17 07:33:45 vpn charon: 03[NET] sending packet: from vpn_ip[500]
>> >>>>>>>>>> to client_ip[500]
>> >>>>>>>>>> Dec 17 07:33:45 vpn charon: 01[NET] received packet: from
>> >>>>>>>>>> client_ip[38391] to vpn_ip[4500]
>> >>>>>>>>>> Dec 17 07:33:45 vpn charon: 01[NET] waiting for data on sockets
>> >>>>>>>>>> Dec 17 07:33:45 vpn charon: 13[NET] received packet: from
>> >>>>>>>>>> client_ip[38391] to vpn_ip[4500] (1492 bytes)
>> >>>>>>>>>> Dec 17 07:33:45 vpn charon: 13[ENC] parsed ID_PROT request 0 [ ID CERT
>> >>>>>>>>>> SIG CERTREQ N(INITIAL_CONTACT) ]
>> >>>>>>>>>> Dec 17 07:33:45 vpn charon: 13[IKE] ignoring certificate request without data
>> >>>>>>>>>> Dec 17 07:33:45 vpn charon: 13[IKE] received end entity cert "C=US,
>> >>>>>>>>>> O=ThatsUs, CN=cindy at example.com"
>> >>>>>>>>>> Dec 17 07:33:45 vpn charon: 13[CFG] looking for RSA signature peer
>> >>>>>>>>>> configs matching vpn_ip...client_ip[C=US, O=ThatsUs,
>> >>>>>>>>>> CN=cindy at example.com]
>> >>>>>>>>>> Dec 17 07:33:45 vpn charon: 13[CFG]   candidate "roadwarrior-ikev1",
>> >>>>>>>>>> match: 1/1/1052 (me/other/ike)
>> >>>>>>>>>> Dec 17 07:33:45 vpn charon: 13[CFG]   candidate "rw-ctmoore", match:
>> >>>>>>>>>> 1/20/1052 (me/other/ike)
>> >>>>>>>>>> Dec 17 07:33:45 vpn charon: 13[CFG] selected peer config "roadwarrior-ikev1"
>> >>>>>>>>>> Dec 17 07:33:45 vpn charon: 13[CFG]   using certificate "C=US,
>> >>>>>>>>>> O=ThatsUs, CN=cindy at example.com"
>> >>>>>>>>>> Dec 17 07:33:45 vpn charon: 13[CFG]   certificate "C=US, O=ThatsUs,
>> >>>>>>>>>> CN=cindy at example.com" key: 2048 bit RSA
>> >>>>>>>>>> Dec 17 07:33:45 vpn charon: 13[CFG]   using trusted ca certificate
>> >>>>>>>>>> "C=US, O=ThatsUs, CN=strongSwan Root CA"
>> >>>>>>>>>> Dec 17 07:33:45 vpn charon: 13[CFG] checking certificate status of
>> >>>>>>>>>> "C=US, O=ThatsUs, CN=cindy at example.com"
>> >>>>>>>>>> Dec 17 07:33:45 vpn charon: 13[CFG] ocsp check skipped, no ocsp found
>> >>>>>>>>>> Dec 17 07:33:45 vpn charon: 13[CFG] certificate status is not available
>> >>>>>>>>>> Dec 17 07:33:45 vpn charon: 13[CFG]   certificate "C=US, O=ThatsUs,
>> >>>>>>>>>> CN=strongSwan Root CA" key: 4096 bit RSA
>> >>>>>>>>>> Dec 17 07:33:45 vpn charon: 13[CFG]   reached self-signed root ca with
>> >>>>>>>>>> a path length of 0
>> >>>>>>>>>> Dec 17 07:33:45 vpn charon: 13[IKE] authentication of 'C=US,
>> >>>>>>>>>> O=ThatsUs, CN=cindy at example.com' with RSA successful
>> >>>>>>>>>> Dec 17 07:33:45 vpn charon: 13[IKE] authentication of 'C=US,
>> >>>>>>>>>> O=ThatsUs, CN=vpn.example.com' (myself) successful
>> >>>>>>>>>> Dec 17 07:33:45 vpn charon: 13[IKE] IKE_SA roadwarrior-ikev1[1]
>> >>>>>>>>>> established between vpn_ip[C=US, O=ThatsUs,
>> >>>>>>>>>> CN=vpn.example.com]...client_ip[C=US, O=ThatsUs, CN=cindy at example.com]
>> >>>>>>>>>> Dec 17 07:33:45 vpn charon: 13[IKE] IKE_SA roadwarrior-ikev1[1] state
>> >>>>>>>>>> change: CONNECTING => ESTABLISHED
>> >>>>>>>>>> Dec 17 07:33:45 vpn charon: 13[IKE] scheduling reauthentication in 3293s
>> >>>>>>>>>> Dec 17 07:33:45 vpn charon: 13[IKE] maximum IKE_SA lifetime 3473s
>> >>>>>>>>>> Dec 17 07:33:45 vpn charon: 13[IKE] sending end entity cert "C=US,
>> >>>>>>>>>> O=ThatsUs, CN=vpn.example.com"
>> >>>>>>>>>> Dec 17 07:33:45 vpn charon: 13[ENC] generating ID_PROT response 0 [ ID
>> >>>>>>>>>> CERT SIG ]
>> >>>>>>>>>> Dec 17 07:33:45 vpn charon: 13[NET] sending packet: from vpn_ip[4500]
>> >>>>>>>>>> to client_ip[38391] (1484 bytes)
>> >>>>>>>>>> Dec 17 07:33:45 vpn charon: 03[NET] sending packet: from vpn_ip[4500]
>> >>>>>>>>>> to client_ip[38391]
>> >>>>>>>>>> Dec 17 07:33:46 vpn charon: 01[NET] received packet: from
>> >>>>>>>>>> client_ip[38391] to vpn_ip[4500]
>> >>>>>>>>>> Dec 17 07:33:46 vpn charon: 01[NET] waiting for data on sockets
>> >>>>>>>>>> Dec 17 07:33:46 vpn charon: 15[NET] received packet: from
>> >>>>>>>>>> client_ip[38391] to vpn_ip[4500] (252 bytes)
>> >>>>>>>>>> Dec 17 07:33:46 vpn charon: 15[ENC] parsed QUICK_MODE request
>> >>>>>>>>>> 4114711345 [ HASH SA No ID ID NAT-OA NAT-OA ]
>> >>>>>>>>>> Dec 17 07:33:46 vpn charon: 15[IKE] changing received traffic
>> >>>>>>>>>> selectors 10.0.1.32/32[udp/62338]=== vpn_ip/32[udp/l2f] due to NAT
>> >>>>>>>>>> Dec 17 07:33:46 vpn charon: 15[CFG] looking for a child config for
>> >>>>>>>>>> vpn_ip/32[udp/l2f] === client_ip/32[udp/62338]
>> >>>>>>>>>> Dec 17 07:33:46 vpn charon: 15[CFG] proposing traffic selectors for us:
>> >>>>>>>>>> Dec 17 07:33:46 vpn charon: 15[CFG]  0.0.0.0/0
>> >>>>>>>>>> Dec 17 07:33:46 vpn charon: 15[CFG] proposing traffic selectors for other:
>> >>>>>>>>>> Dec 17 07:33:46 vpn charon: 15[CFG]  dynamic
>> >>>>>>>>>> Dec 17 07:33:46 vpn charon: 15[IKE] no matching CHILD_SA config found
>> >>>>>>>>>> Dec 17 07:33:46 vpn charon: 15[IKE] queueing INFORMATIONAL task
>> >>>>>>>>>> Dec 17 07:33:46 vpn charon: 15[IKE] activating new tasks
>> >>>>>>>>>> Dec 17 07:33:46 vpn charon: 15[IKE]   activating INFORMATIONAL task
>> >>>>>>>>>> Dec 17 07:33:46 vpn charon: 15[ENC] generating INFORMATIONAL_V1
>> >>>>>>>>>> request 2161614569 [ HASH N(INVAL_ID) ]
>> >>>>>>>>>> Dec 17 07:33:46 vpn charon: 15[NET] sending packet: from vpn_ip[4500]
>> >>>>>>>>>> to client_ip[38391] (76 bytes)
>> >>>>>>>>>> Dec 17 07:33:46 vpn charon: 15[IKE] activating new tasks
>> >>>>>>>>>> Dec 17 07:33:46 vpn charon: 15[IKE] nothing to initiate
>> >>>>>>>>>> Dec 17 07:33:46 vpn charon: 03[NET] sending packet: from vpn_ip[4500]
>> >>>>>>>>>> to client_ip[38391]
>> >>>>>>>>>> Dec 17 07:33:49 vpn charon: 01[NET] received packet: from
>> >>>>>>>>>> client_ip[38391] to vpn_ip[4500]
>> >>>>>>>>>> Dec 17 07:33:49 vpn charon: 01[NET] waiting for data on sockets
>> >>>>>>>>>> Dec 17 07:33:49 vpn charon: 05[NET] received packet: from
>> >>>>>>>>>> client_ip[38391] to vpn_ip[4500] (252 bytes)
>> >>>>>>>>>> Dec 17 07:33:49 vpn charon: 05[IKE] received retransmit of request
>> >>>>>>>>>> with ID 4114711345, but no response to retransmit
>> >>>>>>>>>> Dec 17 07:33:52 vpn charon: 01[NET] received packet: from
>> >>>>>>>>>> client_ip[38391] to vpn_ip[4500]
>> >>>>>>>>>> Dec 17 07:33:52 vpn charon: 01[NET] waiting for data on sockets
>> >>>>>>>>>> Dec 17 07:33:52 vpn charon: 06[NET] received packet: from
>> >>>>>>>>>> client_ip[38391] to vpn_ip[4500] (252 bytes)
>> >>>>>>>>>> Dec 17 07:33:52 vpn charon: 06[IKE] received retransmit of request
>> >>>>>>>>>> with ID 4114711345, but no response to retransmit
>> >>>>>>>>>> Dec 17 07:33:55 vpn charon: 01[NET] received packet: from
>> >>>>>>>>>> client_ip[38391] to vpn_ip[4500]
>> >>>>>>>>>> Dec 17 07:33:55 vpn charon: 01[NET] waiting for data on sockets
>> >>>>>>>>>> Dec 17 07:33:55 vpn charon: 07[NET] received packet: from
>> >>>>>>>>>> client_ip[38391] to vpn_ip[4500] (252 bytes)
>> >>>>>>>>>> Dec 17 07:33:55 vpn charon: 07[IKE] received retransmit of request
>> >>>>>>>>>> with ID 4114711345, but no response to retransmit
>> >>>>>>>>>> Dec 17 07:33:58 vpn charon: 01[NET] received packet: from
>> >>>>>>>>>> client_ip[38391] to vpn_ip[4500]
>> >>>>>>>>>> Dec 17 07:33:58 vpn charon: 01[NET] waiting for data on sockets
>> >>>>>>>>>> Dec 17 07:33:58 vpn charon: 08[NET] received packet: from
>> >>>>>>>>>> client_ip[38391] to vpn_ip[4500] (252 bytes)
>> >>>>>>>>>> Dec 17 07:33:58 vpn charon: 08[IKE] received retransmit of request
>> >>>>>>>>>> with ID 4114711345, but no response to retransmit
>> >>>>>>>>>> Dec 17 07:34:01 vpn charon: 01[NET] received packet: from
>> >>>>>>>>>> client_ip[38391] to vpn_ip[4500]
>> >>>>>>>>>> Dec 17 07:34:01 vpn charon: 01[NET] waiting for data on sockets
>> >>>>>>>>>> Dec 17 07:34:01 vpn charon: 09[NET] received packet: from
>> >>>>>>>>>> client_ip[38391] to vpn_ip[4500] (252 bytes)
>> >>>>>>>>>> Dec 17 07:34:01 vpn charon: 09[IKE] received retransmit of request
>> >>>>>>>>>> with ID 4114711345, but no response to retransmit
>> >>>>>>>>>> Dec 17 07:34:04 vpn charon: 01[NET] received packet: from
>> >>>>>>>>>> client_ip[38391] to vpn_ip[4500]
>> >>>>>>>>>> Dec 17 07:34:04 vpn charon: 01[NET] waiting for data on sockets
>> >>>>>>>>>> Dec 17 07:34:04 vpn charon: 10[NET] received packet: from
>> >>>>>>>>>> client_ip[38391] to vpn_ip[4500] (252 bytes)
>> >>>>>>>>>> Dec 17 07:34:04 vpn charon: 10[IKE] received retransmit of request
>> >>>>>>>>>> with ID 4114711345, but no response to retransmit
>> >>>>>>>>>> Dec 17 07:34:07 vpn charon: 01[NET] received packet: from
>> >>>>>>>>>> client_ip[38391] to vpn_ip[4500]
>> >>>>>>>>>> Dec 17 07:34:07 vpn charon: 01[NET] waiting for data on sockets
>> >>>>>>>>>> Dec 17 07:34:07 vpn charon: 11[NET] received packet: from
>> >>>>>>>>>> client_ip[38391] to vpn_ip[4500] (252 bytes)
>> >>>>>>>>>> Dec 17 07:34:07 vpn charon: 11[IKE] received retransmit of request
>> >>>>>>>>>> with ID 4114711345, but no response to retransmit
>> >>>>>>>>>> Dec 17 07:34:10 vpn charon: 01[NET] received packet: from
>> >>>>>>>>>> client_ip[38391] to vpn_ip[4500]
>> >>>>>>>>>> Dec 17 07:34:10 vpn charon: 01[NET] waiting for data on sockets
>> >>>>>>>>>> Dec 17 07:34:10 vpn charon: 12[NET] received packet: from
>> >>>>>>>>>> client_ip[38391] to vpn_ip[4500] (252 bytes)
>> >>>>>>>>>> Dec 17 07:34:10 vpn charon: 12[IKE] received retransmit of request
>> >>>>>>>>>> with ID 4114711345, but no response to retransmit
>> >>>>>>>>>> Dec 17 07:34:13 vpn charon: 01[NET] received packet: from
>> >>>>>>>>>> client_ip[38391] to vpn_ip[4500]
>> >>>>>>>>>> Dec 17 07:34:13 vpn charon: 01[NET] waiting for data on sockets
>> >>>>>>>>>> Dec 17 07:34:13 vpn charon: 04[NET] received packet: from
>> >>>>>>>>>> client_ip[38391] to vpn_ip[4500] (252 bytes)
>> >>>>>>>>>> Dec 17 07:34:13 vpn charon: 04[IKE] received retransmit of request
>> >>>>>>>>>> with ID 4114711345, but no response to retransmit
>> >>>>>>>>>> Dec 17 07:34:16 vpn charon: 01[NET] received packet: from
>> >>>>>>>>>> client_ip[38391] to vpn_ip[4500]
>> >>>>>>>>>> Dec 17 07:34:16 vpn charon: 01[NET] waiting for data on sockets
>> >>>>>>>>>> Dec 17 07:34:16 vpn charon: 14[NET] received packet: from
>> >>>>>>>>>> client_ip[38391] to vpn_ip[4500] (84 bytes)
>> >>>>>>>>>> Dec 17 07:34:16 vpn charon: 14[ENC] parsed INFORMATIONAL_V1 request
>> >>>>>>>>>> 2185990223 [ HASH D ]
>> >>>>>>>>>> Dec 17 07:34:16 vpn charon: 14[IKE] received DELETE for IKE_SA
>> >>>>>>>>>> roadwarrior-ikev1[1]
>> >>>>>>>>>> Dec 17 07:34:16 vpn charon: 14[IKE] deleting IKE_SA
>> >>>>>>>>>> roadwarrior-ikev1[1] between vpn_ip[C=US, O=ThatsUs,
>> >>>>>>>>>> CN=vpn.example.com]...client_ip[C=US, O=ThatsUs, CN=cindy at example.com]
>> >>>>>>>>>> Dec 17 07:34:16 vpn charon: 14[IKE] IKE_SA roadwarrior-ikev1[1] state
>> >>>>>>>>>> change: ESTABLISHED => DELETING
>> >>>>>>>>>> Dec 17 07:34:16 vpn charon: 14[IKE] IKE_SA roadwarrior-ikev1[1] state
>> >>>>>>>>>> change: DELETING => DELETING
>> >>>>>>>>>> Dec 17 07:34:16 vpn charon: 14[IKE] IKE_SA roadwarrior-ikev1[1] state
>> >>>>>>>>>> change: DELETING => DESTROYING
>> >>>>>>>>>>
>> >>>>>>>>>>
>> >>>>>>>>>> (on mac client, /var/log/system.log)
>> >>>>>>>>>> Dec 17 07:33:44 macbook pro pppd[4619]: pppd 2.4.2 (Apple version
>> >>>>>>>>>> 412.5.70) started by mac_owner, uid 501
>> >>>>>>>>>> Dec 17 07:33:44 macbook pro pppd[4619]: L2TP connecting to server
>> >>>>>>>>>> 'vpn.example.com' (vpn_ip)...
>> >>>>>>>>>> Dec 17 07:33:44 macbook pro pppd[4619]: IPSec connection started
>> >>>>>>>>>> Dec 17 07:33:45 macbook pro racoon[4620]: Connecting.
>> >>>>>>>>>> Dec 17 07:33:45 macbook pro racoon[4620]: IKE Packet: transmit
>> >>>>>>>>>> success. (Initiator, Main-Mode message 1).
>> >>>>>>>>>> Dec 17 07:33:45 macbook pro racoon[4620]: IKE Packet: receive success.
>> >>>>>>>>>> (Initiator, Main-Mode message 2).
>> >>>>>>>>>> Dec 17 07:33:45 macbook pro racoon[4620]: IKE Packet: transmit
>> >>>>>>>>>> success. (Initiator, Main-Mode message 3).
>> >>>>>>>>>> Dec 17 07:33:45 macbook pro racoon[4620]: IKE Packet: receive success.
>> >>>>>>>>>> (Initiator, Main-Mode message 4).
>> >>>>>>>>>> Dec 17 07:33:45 macbook pro racoon[4620]: IKE Packet: transmit
>> >>>>>>>>>> success. (Initiator, Main-Mode message 5).
>> >>>>>>>>>> Dec 17 07:33:45 macbook pro racoon[4620]: IKEv1 Phase1 AUTH: success.
>> >>>>>>>>>> (Initiator, Main-Mode Message 6).
>> >>>>>>>>>> Dec 17 07:33:45 macbook pro racoon[4620]: IKE Packet: receive success.
>> >>>>>>>>>> (Initiator, Main-Mode message 6).
>> >>>>>>>>>> Dec 17 07:33:45 macbook pro racoon[4620]: IKEv1 Phase1 Initiator:
>> >>>>>>>>>> success. (Initiator, Main-Mode).
>> >>>>>>>>>> Dec 17 07:33:46 macbook pro racoon[4620]: IKE Packet: transmit
>> >>>>>>>>>> success. (Initiator, Quick-Mode message 1).
>> >>>>>>>>>> Dec 17 07:33:46 macbook pro racoon[4620]: IKE Packet: receive success.
>> >>>>>>>>>> (Information message).
>> >>>>>>>>>> Dec 17 07:33:49 macbook pro racoon[4620]: IKE Packet: transmit
>> >>>>>>>>>> success. (Phase2 Retransmit).
>> >>>>>>>>>> Dec 17 07:33:55 macbook pro racoon[4620]: IKE Packet: transmit
>> >>>>>>>>>> success. (Phase2 Retransmit).
>> >>>>>>>>>> Dec 17 07:34:04 macbook pro racoon[4620]: IKE Packet: transmit
>> >>>>>>>>>> success. (Phase2 Retransmit).
>> >>>>>>>>>> Dec 17 07:34:13 macbook pro racoon[4620]: IKE Packet: transmit
>> >>>>>>>>>> success. (Phase2 Retransmit).
>> >>>>>>>>>> Dec 17 07:34:16 macbook pro pppd[4619]: IPSec connection failed
>> >>>>>>>>>> Dec 17 07:34:16 macbook pro racoon[4620]: IKE Packet: transmit
>> >>>>>>>>>> success. (Information message).
>> >>>>>>>>>> Dec 17 07:34:16 macbook pro racoon[4620]: IKEv1 Information-Notice:
>> >>>>>>>>>> transmit success. (Delete ISAKMP-SA).
>> >>>>>>>>>> Dec 17 07:34:16 macbook pro racoon[4620]: Disconnecting. (Connection
>> >>>>>>>>>> tried to negotiate for, 31.608495 seconds).
>> >>>>>>>>>>
>> >>>>>>>>>>
>> >>>>>>>>>>
>> >>>>>>>>>> On Wed, Dec 17, 2014 at 1:08 AM, Martin Willi <martin at strongswan.org> wrote:
>> >>>>>>>>>>> Cindy,
>> >>>>>>>>>>>
>> >>>>>>>>>>>> 14[CFG] looking for RSA signature peer configs matching vpn_ip...client_ip[C=US, O=ThatsUs, CN=myemailaddr]
>> >>>>>>>>>>>>
>> >>>>>>>>>>>> Would this be as expected?  I can't figure out why it isn't trying to
>> >>>>>>>>>>>> match to the vpn host certificate.
>> >>>>>>>>>>>
>> >>>>>>>>>>> Before looking for certificates, strongSwan looks for a configuration
>> >>>>>>>>>>> that matches the proposed identities and authentication method.
>> >>>>>>>>>>>
>> >>>>>>>>>>>> 14[IKE] found 1 matching config, but none allows RSA signature authentication using Main Mode
>> >>>>>>>>>>>>
>> >>>>>>>>>>>> Can anyone tell me what this means?
>> >>>>>>>>>>>
>> >>>>>>>>>>> It means that the daemon couldn't find a configuration for that client
>> >>>>>>>>>>> that uses RSA authentication with Main Mode.
>> >>>>>>>>>>>
>> >>>>>>>>>>>> 07[CFG]   rightauth=pubkey
>> >>>>>>>>>>>> 07[CFG]   rightauth2=xauth-noauth
>> >>>>>>>>>>>
>> >>>>>>>>>>> Your config uses XAuth, that is RSA followed by username/password
>> >>>>>>>>>>> authentication. This is not the same as the client expects, try to
>> >>>>>>>>>>> remove the rightauth2 line to use RSA authentication only.
>> >>>>>>>>>>>
>> >>>>>>>>>>> Regards
>> >>>>>>>>>>> Martin
>> >>>>>>>>>>>
>> >>>>>>>>> _______________________________________________
>> >>>>>>>>> Users mailing list
>> >>>>>>>>> Users at lists.strongswan.org
>> >>>>>>>>> https://lists.strongswan.org/mailman/listinfo/users
>> >>>>>>
>> >>>>>>>
>> >>>>>>>
>> >>>>>>> _______________________________________________
>> >>>>>>> Users mailing list
>> >>>>>>> Users at lists.strongswan.org
>> >>>>>>> https://lists.strongswan.org/mailman/listinfo/users
>> >>>
>> >>>>
>>
>>>
>
> -----BEGIN PGP SIGNATURE-----
> Version: GnuPG v2
>
> iQIcBAEBCAAGBQJUkfTzAAoJEDg5KY9j7GZYy6YP/2iHBRl6UtKtAW03q+AyStvP
> h8Z69vRJqmnXJP77zAKedUK9zQ1W2Qh2r4uTpR1hVHyZkGLw0bJAaBXqQN1QYDiN
> 7jT2HQVtent2/pvj1RPECN6hMAICbrr6sNZ3viFi7sKG/WoIGimbw6l/DUX5d95d
> L7jNoRuqb+xnba5vCZkz0Pkwow+5feKyaPhYNW+2bn+LJUoG1LQRy0Or6/j9ksew
> ueotzyyYoIO2INO/1NoetKuYwom0oSAvPT8UWQARvGH5bGlG5prZSZVQSBsP6TGW
> f/yCNo5nQ76MWJ9/bZjJI01HDo5847Kry/lsBiRmZOECI+nT+ZLa29iEZfFvoQy0
> H/2lSgneWsXb5eCO4jKEvzjAbFUFOpFq4bhyUjsQGY85oi3n265QfsM47iuPfa6m
> HSMXIOjGJGvJmbLin88Mh1TK+LHUj33VNTpOLaBQQk0NZJzmYqGBU9HpRrDEK3fE
> h0gOcrNAF8JmV/22rA/4F6/yA2ZEKoalok8uLHW6rJDRSTXnhP6spOkFoQIEB7gC
> 4GoQmUKU5wWDmGg2Ybl7k3Eioqg5vjtJ8Fk8/DMMkyDU7vTTFZGw6kewwstQ/aHr
> hHcn6xVG07Evwn/ipF2Pvo2NH3jgtbhyYdcTHeZ7Qc/kKzDW1bPNFKOzKsfIyUiX
> lIg+LhWxIBb+kZzlqlPn
> =/TyF
> -----END PGP SIGNATURE-----
>