[strongSwan] IPSEC/l2TP Chrome OS

[Ilan Caspi]

Tobias thank you so much for your reply!

On the bottom you'll find the attached logs from the chromebook machine,
please let me know if you require any pocket sniffing

Cheers,
Ilan

2015-02-12T10:22:13.896043-08:00 charon[2428]: 00[CFG] loading ca
certificates from '/etc/ipsec.d/cacerts'
2015-02-12T10:22:13.900278-08:00 charon[2428]: 00[CFG]   loaded ca
certificate "CN=domain Dev Root CA G1, O=domain, C=US" from
'/etc/ipsec.d/cacerts/cacert.der'
2015-02-12T10:22:13.900904-08:00 charon[2428]: 00[CFG] loading aa
certificates from '/etc/ipsec.d/aacerts'
2015-02-12T10:22:13.901409-08:00 charon[2428]: 00[CFG] loading ocsp signer
certificates from '/etc/ipsec.d/ocspcerts'
2015-02-12T10:22:13.901910-08:00 charon[2428]: 00[CFG] loading attribute
certificates from '/etc/ipsec.d/acerts'
2015-02-12T10:22:13.902417-08:00 charon[2428]: 00[CFG] loading crls from
'/etc/ipsec.d/crls'
2015-02-12T10:22:13.902953-08:00 charon[2428]: 00[CFG] loading secrets from
'/etc/ipsec.secrets'
2015-02-12T10:22:13.911338-08:00 charon[2428]: 00[CFG]   loaded private key
from %smartcard1 at crypto_module:719D7F5687E27E8DAD5E37FD84CFFA1027B29878
2015-02-12T10:22:13.912395-08:00 charon[2428]: 00[DMN] loaded plugins:
charon pkcs11 aes des sha1 sha2 md5 random nonce x509 revocation
constraints pubkey pkcs1 pkcs8 pgp dnskey pem openssl fips-prf gmp xcbc
cmac hmac attr kernel-netlink resolve socket-default stroke updown
xauth-generic
2015-02-12T10:22:13.913424-08:00 charon[2428]: 00[LIB] dropped
capabilities, running as uid 212, gid 212
2015-02-12T10:22:13.913935-08:00 charon[2428]: 00[JOB] spawning 16 worker
threads
2015-02-12T10:22:13.925508-08:00 charon[2428]: 01[CFG] received stroke: add
connection 'managed'
2015-02-12T10:22:13.926009-08:00 charon[2428]: 01[CFG] left nor right host
is our side, assuming left=local
2015-02-12T10:22:13.930950-08:00 charon[2428]: 01[CFG]   loaded certificate
"CN=right_cn, OU=1957, O=domain.com, C=US" from '%smartcard1 at crypto_module
:719D7F5687E27E8DAD5E37FD84CFFA1027B29878'
2015-02-12T10:22:13.931524-08:00 charon[2428]: 01[CFG]   id '%any' not
confirmed by certificate, defaulting to 'CN=right_cn, OU=1957, O=domain.com,
C=US'
2015-02-12T10:22:13.932301-08:00 charon[2428]: 01[CFG] added configuration
'managed'
2015-02-12T10:22:13.933065-08:00 charon[2428]: 12[CFG] received stroke:
initiate 'managed'
2015-02-12T10:22:13.933964-08:00 charon[2428]: 12[IKE] initiating Main Mode
IKE_SA managed[1] to 162.243.137.92
2015-02-12T10:22:13.937160-08:00 charon[2428]: 12[ENC] generating ID_PROT
request 0 [ SA V V V V ]
2015-02-12T10:22:13.937898-08:00 charon[2428]: 12[NET] sending packet: from
10.0.1.186[500] to 162.243.137.92[500] (188 bytes)
2015-02-12T10:22:13.956699-08:00 charon[2428]: 09[NET] received packet:
from 162.243.137.92[500] to 10.0.1.186[500] (132 bytes)
2015-02-12T10:22:13.957266-08:00 charon[2428]: 09[ENC] parsed ID_PROT
response 0 [ SA V V V ]
2015-02-12T10:22:13.957296-08:00 charon[2428]: 09[IKE] received XAuth
vendor ID
2015-02-12T10:22:13.957310-08:00 charon[2428]: 09[IKE] received DPD vendor
ID
2015-02-12T10:22:13.957323-08:00 charon[2428]: 09[IKE] received NAT-T (RFC
3947) vendor ID
2015-02-12T10:22:13.964554-08:00 charon[2428]: 09[ENC] generating ID_PROT
request 0 [ KE No NAT-D NAT-D ]
2015-02-12T10:22:13.964647-08:00 charon[2428]: 09[NET] sending packet: from
10.0.1.186[500] to 162.243.137.92[500] (244 bytes)
2015-02-12T10:22:13.987288-08:00 charon[2428]: 02[NET] received packet:
from 162.243.137.92[500] to 10.0.1.186[500] (468 bytes)
2015-02-12T10:22:13.987330-08:00 charon[2428]: 02[ENC] parsed ID_PROT
response 0 [ KE No CERTREQ CERTREQ CERTREQ NAT-D NAT-D ]
2015-02-12T10:22:13.987345-08:00 charon[2428]: 02[IKE] received cert
request for unknown ca 'CN=domain Dev Issuing CA G1, O=domain, C=US'
2015-02-12T10:22:13.987359-08:00 charon[2428]: 02[IKE] received cert
request for 'CN=domain Dev Root CA G1, O=domain, C=US'
2015-02-12T10:22:13.987373-08:00 charon[2428]: 02[IKE] received cert
request for unknown ca 'CN=domain Dev Intermediate CA G1, O=domain, C=US'
2015-02-12T10:22:13.994140-08:00 charon[2428]: 02[IKE] local host is behind
NAT, sending keep alives
2015-02-12T10:22:13.999718-08:00 charon[2428]: 02[IKE] sending cert request
for "CN=domain Dev Root CA G1, O=domain, C=US"
2015-02-12T10:22:14.012951-08:00 shill[1076]: [ERROR:error.cc(103)]
Operation failed (no other information)
2015-02-12T10:22:14.365615-08:00 shill[1076]: last message repeated 25 times
2015-02-12T10:22:14.365013-08:00 charon[2428]: 02[IKE] authentication of
'CN=right_cn, OU=1957, O=domain.com, C=US' (myself) successful
2015-02-12T10:22:14.365056-08:00 charon[2428]: 02[IKE] sending end entity
cert "CN=right_cn, OU=1957, O=domain.com, C=US"
2015-02-12T10:22:14.365078-08:00 charon[2428]: 02[ENC] generating ID_PROT
request 0 [ ID CERT SIG CERTREQ ]
2015-02-12T10:22:14.365098-08:00 charon[2428]: 02[NET] sending packet: from
10.0.1.186[4500] to 162.243.137.92[4500] (1092 bytes)
2015-02-12T10:22:14.622824-08:00 charon[2428]: 07[NET] received packet:
from 162.243.137.92[4500] to 10.0.1.186[4500] (2092 bytes)
2015-02-12T10:22:14.623526-08:00 charon[2428]: 07[ENC] payload of type
CERTIFICATE_V1 more than 2 times (3) occurred in current message
2015-02-12T10:22:14.623568-08:00 charon[2428]: 07[IKE] message verification
failed
2015-02-12T10:22:14.623584-08:00 charon[2428]: 07[ENC] generating
INFORMATIONAL_V1 request 3294627211 [ HASH N(PLD_MAL) ]
2015-02-12T10:22:14.623603-08:00 charon[2428]: 07[NET] sending packet: from
10.0.1.186[4500] to 162.243.137.92[4500] (68 bytes)
2015-02-12T10:22:14.623625-08:00 charon[2428]: 07[IKE] ID_PROT response
with message ID 0 processing failed
2015-02-12T10:22:18.365205-08:00 charon[2428]: 14[IKE] sending retransmit 1
of request message ID 0, seq 3
2015-02-12T10:22:18.365250-08:00 charon[2428]: 14[NET] sending packet: from
10.0.1.186[4500] to 162.243.137.92[4500] (1092 bytes)
2015-02-12T10:22:18.378092-08:00 charon[2428]: 01[NET] received packet:
from 162.243.137.92[4500] to 10.0.1.186[4500] (2092 bytes)
2015-02-12T10:22:18.379109-08:00 charon[2428]: 01[ENC] payload of type
CERTIFICATE_V1 more than 2 times (3) occurred in current message
2015-02-12T10:22:18.379147-08:00 charon[2428]: 01[IKE] message verification
failed
2015-02-12T10:22:18.379165-08:00 charon[2428]: 01[ENC] generating
INFORMATIONAL_V1 request 3308765307 [ HASH N(PLD_MAL) ]
2015-02-12T10:22:18.379179-08:00 charon[2428]: 01[NET] sending packet: from
10.0.1.186[4500] to 162.243.137.92[4500] (68 bytes)
2015-02-12T10:22:18.379192-08:00 charon[2428]: 01[IKE] ID_PROT response
with message ID 0 processing failed
2015-02-12T10:22:25.565876-08:00 charon[2428]: 12[IKE] sending retransmit 2
of request message ID 0, seq 3
2015-02-12T10:22:25.565915-08:00 charon[2428]: 12[NET] sending packet: from
10.0.1.186[4500] to 162.243.137.92[4500] (1092 bytes)
2015-02-12T10:22:25.577716-08:00 charon[2428]: 09[NET] received packet:
from 162.243.137.92[4500] to 10.0.1.186[4500] (2092 bytes)
2015-02-12T10:22:25.578064-08:00 charon[2428]: 09[ENC] payload of type
CERTIFICATE_V1 more than 2 times (3) occurred in current message
2015-02-12T10:22:25.578096-08:00 charon[2428]: 09[IKE] message verification
failed
2015-02-12T10:22:25.578114-08:00 charon[2428]: 09[ENC] generating
INFORMATIONAL_V1 request 4041721436 [ HASH N(PLD_MAL) ]
2015-02-12T10:22:25.578130-08:00 charon[2428]: 09[NET] sending packet: from
10.0.1.186[4500] to 162.243.137.92[4500] (68 bytes)
2015-02-12T10:22:25.578147-08:00 charon[2428]: 09[IKE] ID_PROT response
with message ID 0 processing failed
2015-02-12T10:22:26.942623-08:00 periodic_scheduler[2475]: crash_sender:
running /sbin/crash_sender
2015-02-12T10:22:27.011533-08:00 periodic_scheduler[2492]: crash_sender:
job completed
2015-02-12T10:22:38.526907-08:00 charon[2428]: 07[IKE] sending retransmit 3
of request message ID 0, seq 3
2015-02-12T10:22:38.526950-08:00 charon[2428]: 07[NET] sending packet: from
10.0.1.186[4500] to 162.243.137.92[4500] (1092 bytes)
2015-02-12T10:22:38.559165-08:00 charon[2428]: 05[NET] received packet:
from 162.243.137.92[4500] to 10.0.1.186[4500] (2092 bytes)
2015-02-12T10:22:38.559214-08:00 charon[2428]: 05[ENC] payload of type
CERTIFICATE_V1 more than 2 times (3) occurred in current message
2015-02-12T10:22:38.559237-08:00 charon[2428]: 05[IKE] message verification
failed
2015-02-12T10:22:38.559256-08:00 charon[2428]: 05[ENC] generating
INFORMATIONAL_V1 request 2462622163 [ HASH N(PLD_MAL) ]
2015-02-12T10:22:38.559571-08:00 charon[2428]: 05[NET] sending packet: from
10.0.1.186[4500] to 162.243.137.92[4500] (68 bytes)
2015-02-12T10:22:38.559592-08:00 charon[2428]: 05[IKE] ID_PROT response
with message ID 0 processing failed
2015-02-12T10:22:43.948434-08:00 l2tpipsec_vpn[2415]: IPsec connection
timed out
2015-02-12T10:22:44.950783-08:00 charon[2428]: 00[DMN] signal of type
SIGINT received. Shutting down
2015-02-12T10:22:44.950822-08:00 charon[2428]: 00[IKE] destroying IKE_SA in
state CONNECTING without notification
2015-02-12T10:22:44.970725-08:00 l2tpipsec_vpn[2415]: Unable to send signal
to 2417 error 3
2015-02-12T10:22:44.970758-08:00 l2tpipsec_vpn[2415]: Unable to send signal
to 2428 error 3
2015-02-12T10:22:45.002783-08:00 shill[1076]: [ERROR:error.cc(103)]
Operation failed (no other information)

On Thu Feb 12 2015 at 12:44:06 AM Tobias Brunner <tobias at strongswan.org>
wrote:

> Hi Ilan,
>
> >>> 06[ENC] invalid HASH_V1 payload length, decryption failed?
> >>> 06[ENC] could not decrypt payloads
> >>> 06[IKE] message parsing failed
> >>> 06[IKE] ignore malformed INFORMATIONAL request
>
> This looks like #836 (or #570).  Do you have any logs from the client?
> It seems it might not like the server's certificate and then maybe sends
> a DELETE or some other notify to the server.  Could you try to determine
> what is contained in that INFORMATIONAL request (e.g. via Wireshark)?
>
> Regards,
> Tobias
>
> [1] https://wiki.strongswan.org/issues/836
> [2] https://wiki.strongswan.org/issues/570
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.strongswan.org/pipermail/users/attachments/20150212/894b377a/attachment-0001.html>