[Swan] Trouble connecting to libreswan from iOS 12 ikev2

Ian Dobson ird at oob.id.au
Tue May 28 00:01:55 UTC 2019


> Do you have a logfile= set in "config setup" in /etc/ipsec.conf ? Then
> all logs will go to the file instead of syslog. If not, perhaps set
> logfile=/var/log/pluto.log to gather the logs.

I've made that change but there is still nothing at all being logged when
I attempt the ikev2 connection from an iphone. After changing the logfile
parameter per above, I'm seeing in this file exactly what was previously
going into /var/log/secure through syslog.

Log on startup:

May 28 09:32:13.778217: FIPS Product: NO
May 28 09:32:13.778501: FIPS Kernel: NO
May 28 09:32:13.778526: FIPS Mode: NO
May 28 09:32:13.778550: NSS DB directory: sql:/etc/ipsec.d
May 28 09:32:13.778860: Initializing NSS
May 28 09:32:13.778905: Opening NSS database "sql:/etc/ipsec.d" read-only
May 28 09:32:13.971135: NSS initialized
May 28 09:32:13.971175: NSS crypto library initialized
May 28 09:32:13.971189: FIPS HMAC integrity support [enabled]
May 28 09:32:13.971202: FIPS mode disabled for pluto daemon
May 28 09:32:14.153921: FIPS HMAC integrity verification self-test passed
May 28 09:32:14.154314: libcap-ng support [enabled]
May 28 09:32:14.154335: Linux audit support [enabled]
May 28 09:32:14.154455: Linux audit activated
May 28 09:32:14.154472: Starting Pluto (Libreswan Version 3.23
XFRM(netkey) KLIPS
FORK PTHREAD_SETSCHEDPRIO GCC_EXCEPTIONS NSS DNSSEC SYSTEMD_WATCHDOG
FIPS_CHECK
LABELED_IPSEC SECCOMP LIBCAP_NG LINUX_AUDIT XAUTH_PAM NETWORKMANAGER
CURL(non-NSS)
LDAP(non-NSS)) pid:32759
May 28 09:32:14.154486: core dump dir: /var/run/pluto/
May 28 09:32:14.154499: secrets file: /etc/ipsec.secrets
May 28 09:32:14.154512: leak-detective enabled
May 28 09:32:14.154524: NSS crypto [enabled]
May 28 09:32:14.154536: XAUTH PAM support [enabled]
May 28 09:32:14.154688: NAT-Traversal support  [enabled]
May 28 09:32:14.154764: Initializing libevent in pthreads mode: headers:
2.0.21-stable (2001500); library: 2.0.21-stable (2001500)
May 28 09:32:14.155278: Encryption algorithms:
May 28 09:32:14.155320:   AES_CCM_16          IKEv1:     ESP     IKEv2:   
 ESP
FIPS  {256,192,*128}  (aes_ccm aes_ccm_c)
May 28 09:32:14.155351:   AES_CCM_12          IKEv1:     ESP     IKEv2:   
 ESP
FIPS  {256,192,*128}  (aes_ccm_b)
May 28 09:32:14.155380:   AES_CCM_8           IKEv1:     ESP     IKEv2:   
 ESP
FIPS  {256,192,*128}  (aes_ccm_a)
May 28 09:32:14.155409:   3DES_CBC            IKEv1: IKE ESP     IKEv2:
IKE ESP
FIPS  [*192]  (3des)
May 28 09:32:14.155437:   CAMELLIA_CTR        IKEv1:     ESP     IKEv2:   
 ESP
     {256,192,*128}
May 28 09:32:14.155467:   CAMELLIA_CBC        IKEv1: IKE ESP     IKEv2:
IKE ESP
     {256,192,*128}  (camellia)
May 28 09:32:14.155496:   AES_GCM_16          IKEv1:     ESP     IKEv2:
IKE ESP
FIPS  {256,192,*128}  (aes_gcm aes_gcm_c)
May 28 09:32:14.155525:   AES_GCM_12          IKEv1:     ESP     IKEv2:
IKE ESP
FIPS  {256,192,*128}  (aes_gcm_b)
May 28 09:32:14.155554:   AES_GCM_8           IKEv1:     ESP     IKEv2:
IKE ESP
FIPS  {256,192,*128}  (aes_gcm_a)
May 28 09:32:14.155583:   AES_CTR             IKEv1: IKE ESP     IKEv2:
IKE ESP
FIPS  {256,192,*128}  (aesctr)
May 28 09:32:14.155631:   AES_CBC             IKEv1: IKE ESP     IKEv2:
IKE ESP
FIPS  {256,192,*128}  (aes)
May 28 09:32:14.155665:   SERPENT_CBC         IKEv1: IKE ESP     IKEv2:
IKE ESP
     {256,192,*128}  (serpent)
May 28 09:32:14.155723:   TWOFISH_CBC         IKEv1: IKE ESP     IKEv2:
IKE ESP
     {256,192,*128}  (twofish)
May 28 09:32:14.155753:   TWOFISH_SSH         IKEv1: IKE         IKEv2:
IKE ESP
     {256,192,*128}  (twofish_cbc_ssh)
May 28 09:32:14.155780:   CAST_CBC            IKEv1:     ESP     IKEv2:   
 ESP
     {*128}  (cast)
May 28 09:32:14.155808:   NULL_AUTH_AES_GMAC  IKEv1:     ESP     IKEv2:   
 ESP
     {256,192,*128}  (aes_gmac)
May 28 09:32:14.155833:   NULL                IKEv1:     ESP     IKEv2:   
 ESP
     []
May 28 09:32:14.155872: Hash algorithms:
May 28 09:32:14.155899:   MD5                 IKEv1: IKE         IKEv2:

May 28 09:32:14.155924:   SHA1                IKEv1: IKE         IKEv2:
FIPS  (sha)
May 28 09:32:14.155949:   SHA2_256            IKEv1: IKE         IKEv2:
FIPS  (sha2 sha256)
May 28 09:32:14.155974:   SHA2_384            IKEv1: IKE         IKEv2:
FIPS  (sha384)
May 28 09:32:14.156000:   SHA2_512            IKEv1: IKE         IKEv2:
FIPS  (sha512)
May 28 09:32:14.156035: PRF algorithms:
May 28 09:32:14.156061:   HMAC_MD5            IKEv1: IKE         IKEv2: IKE
     (md5)
May 28 09:32:14.156087:   HMAC_SHA1           IKEv1: IKE         IKEv2: IKE
FIPS  (sha sha1)
May 28 09:32:14.156113:   HMAC_SHA2_256       IKEv1: IKE         IKEv2: IKE
FIPS  (sha2 sha256 sha2_256)
May 28 09:32:14.156137:   HMAC_SHA2_384       IKEv1: IKE         IKEv2: IKE
FIPS  (sha384 sha2_384)
May 28 09:32:14.156162:   HMAC_SHA2_512       IKEv1: IKE         IKEv2: IKE
FIPS  (sha512 sha2_512)
May 28 09:32:14.156208: Integrity algorithms:
May 28 09:32:14.156235:   HMAC_MD5_96         IKEv1: IKE ESP AH  IKEv2:
IKE ESP AH
     (md5 hmac_md5)
May 28 09:32:14.156262:   HMAC_SHA1_96        IKEv1: IKE ESP AH  IKEv2:
IKE ESP AH
FIPS  (sha sha1 sha1_96 hmac_sha1)
May 28 09:32:14.156288:   HMAC_SHA2_512_256   IKEv1: IKE ESP AH  IKEv2:
IKE ESP AH
FIPS  (sha512 sha2_512 hmac_sha2_512)
May 28 09:32:14.156314:   HMAC_SHA2_384_192   IKEv1: IKE ESP AH  IKEv2:
IKE ESP AH
FIPS  (sha384 sha2_384 hmac_sha2_384)
May 28 09:32:14.156340:   HMAC_SHA2_256_128   IKEv1: IKE ESP AH  IKEv2:
IKE ESP AH
FIPS  (sha2 sha256 sha2_256 hmac_sha2_256)
May 28 09:32:14.156365:   AES_XCBC_96         IKEv1:     ESP AH  IKEv2:   
 ESP AH
FIPS  (aes_xcbc)
May 28 09:32:14.156390:   AES_CMAC_96         IKEv1:     ESP AH  IKEv2:   
 ESP AH
FIPS  (aes_cmac)
May 28 09:32:14.156415:   NONE                IKEv1:     ESP     IKEv2:   
 ESP
FIPS  (null)
May 28 09:32:14.156465: DH algorithms:
May 28 09:32:14.156492:   MODP1024            IKEv1: IKE ESP AH  IKEv2:
IKE ESP AH
     (dh2)
May 28 09:32:14.156517:   MODP1536            IKEv1: IKE ESP AH  IKEv2:
IKE ESP AH
     (dh5)
May 28 09:32:14.156542:   MODP2048            IKEv1: IKE ESP AH  IKEv2:
IKE ESP AH
FIPS  (dh14)
May 28 09:32:14.156567:   MODP3072            IKEv1: IKE ESP AH  IKEv2:
IKE ESP AH
FIPS  (dh15)
May 28 09:32:14.156591:   MODP4096            IKEv1: IKE ESP AH  IKEv2:
IKE ESP AH
FIPS  (dh16)
May 28 09:32:14.156629:   MODP6144            IKEv1: IKE ESP AH  IKEv2:
IKE ESP AH
FIPS  (dh17)
May 28 09:32:14.156659:   MODP8192            IKEv1: IKE ESP AH  IKEv2:
IKE ESP AH
FIPS  (dh18)
May 28 09:32:14.156685:   DH19                IKEv1: IKE         IKEv2:
IKE ESP AH
FIPS  (ecp_256)
May 28 09:32:14.156710:   DH20                IKEv1: IKE         IKEv2:
IKE ESP AH
FIPS  (ecp_384)
May 28 09:32:14.156736:   DH21                IKEv1: IKE         IKEv2:
IKE ESP AH
FIPS  (ecp_521)
May 28 09:32:14.156761:   DH22                IKEv1: IKE ESP AH  IKEv2:
IKE ESP AH

May 28 09:32:14.156785:   DH23                IKEv1: IKE ESP AH  IKEv2:
IKE ESP AH
FIPS
May 28 09:32:14.156810:   DH24                IKEv1: IKE ESP AH  IKEv2:
IKE ESP AH
FIPS
May 28 09:32:14.159718: starting up 3 crypto helpers
May 28 09:32:14.159898: started thread for crypto helper 0
May 28 09:32:14.159984: started thread for crypto helper 1
May 28 09:32:14.160065: started thread for crypto helper 2
May 28 09:32:14.160241: Using Linux XFRM/NETKEY IPsec interface code on
3.10.0-327.18.2.el7.x86_64
May 28 09:32:14.212535: | selinux support is enabled.
May 28 09:32:14.213045: systemd watchdog for ipsec service configured with
timeout
of 200000000 usecs
May 28 09:32:14.213084: watchdog: sending probes every 100 secs
May 28 09:32:15.297587: added connection description "ikev2-rsa"
May 28 09:32:15.297941: added connection description "l2tp-psk"
May 28 09:32:15.298137: added connection description "v6neighbor-hole-in"
May 28 09:32:15.298312: added connection description "v6neighbor-hole-out"
May 28 09:32:15.302422: added connection description "xauth-rsa"
May 28 09:32:15.302846: listening for IKE messages
May 28 09:32:15.303259: adding interface eth3/eth3 144.132.45.114:500
May 28 09:32:15.303409: adding interface eth3/eth3 144.132.45.114:4500
May 28 09:32:15.303506: adding interface eth1/eth1 172.21.1.1:500
May 28 09:32:15.303596: adding interface eth1/eth1 172.21.1.1:4500
May 28 09:32:15.303736: adding interface eth4/eth4 172.21.0.2:500
May 28 09:32:15.303832: adding interface eth4/eth4 172.21.0.2:4500
May 28 09:32:15.303926: adding interface lo/lo 127.0.0.1:500
May 28 09:32:15.304016: adding interface lo/lo 127.0.0.1:4500
May 28 09:32:15.304336: adding interface lo/lo ::1:500
May 28 09:32:15.304411: | setup callback for interface lo:500 fd 25
May 28 09:32:15.304448: | setup callback for interface lo:4500 fd 24
May 28 09:32:15.304483: | setup callback for interface lo:500 fd 23
May 28 09:32:15.304517: | setup callback for interface eth4:4500 fd 22
May 28 09:32:15.304552: | setup callback for interface eth4:500 fd 21
May 28 09:32:15.304587: | setup callback for interface eth1:4500 fd 20
May 28 09:32:15.304642: | setup callback for interface eth1:500 fd 19
May 28 09:32:15.304681: | setup callback for interface eth3:4500 fd 18
May 28 09:32:15.304716: | setup callback for interface eth3:500 fd 17
May 28 09:32:15.304745: forgetting secrets
May 28 09:32:15.304846: loading secrets from "/etc/ipsec.secrets"
May 28 09:32:15.305020: loading secrets from "/etc/ipsec.d/hostkey.secrets"
May 28 09:32:15.305235: loaded private key for keyid: PKK_RSA:AQOxBlhBg



Log with successful ikev1 connection:

ikev1 test
May 28 09:32:28.749427: "xauth-rsa"[1] 1.152.246.98 #1: responding to Main
Mode from
unknown peer 1.152.246.98 on port 500
May 28 09:32:28.749651: "xauth-rsa"[1] 1.152.246.98 #1: STATE_MAIN_R1:
sent MR1,
expecting MI2
May 28 09:32:28.845447: "xauth-rsa"[1] 1.152.246.98 #1: STATE_MAIN_R2:
sent MR2,
expecting MI3
May 28 09:32:28.959164: "xauth-rsa"[1] 1.152.246.98 #1: ignoring
informational
payload IPSEC_INITIAL_CONTACT, msgid=00000000, length=28
May 28 09:32:28.959220: | ISAKMP Notification Payload
May 28 09:32:28.959244: |   00 00 00 1c  00 00 00 01  01 10 60 02
May 28 09:32:28.959287: "xauth-rsa"[1] 1.152.246.98 #1: Peer ID is
ID_DER_ASN1_DN:
'C=AU, ST=Victoria, L=Surrey Hills, O=OOB, CN=ian at oob.id.au, E=ian at oob.id.au'
May 28 09:32:28.980670: "xauth-rsa"[1] 1.152.246.98 #1: certificate
verified OK:
E=ian at oob.id.au,CN=ian at oob.id.au,O=OOB,L=Surrey Hills,ST=Victoria,C=AU
May 28 09:32:28.984273: "xauth-rsa"[1] 1.152.246.98 #1: certificate does
not contain
ID_IP subjectAltName=1.152.246.98
May 28 09:32:28.984322: "xauth-rsa"[1] 1.152.246.98 #1: Peer public key
SubjectAltName does not match peer ID for this connection
May 28 09:32:28.984354: "xauth-rsa"[1] 1.152.246.98 #1: X509: CERT payload
does not
match connection ID
May 28 09:32:28.986728: "xauth-rsa"[1] 1.152.246.98 #1: switched from
"xauth-rsa"[1]
1.152.246.98 to "xauth-rsa"
May 28 09:32:28.986801: "xauth-rsa"[2] 1.152.246.98 #1: deleting connection
"xauth-rsa"[1] 1.152.246.98 instance with peer 1.152.246.98
{isakmp=#0/ipsec=#0}
May 28 09:32:28.986864: "xauth-rsa"[2] 1.152.246.98 #1: Peer ID is
ID_DER_ASN1_DN:
'C=AU, ST=Victoria, L=Surrey Hills, O=OOB, CN=ian at oob.id.au, E=ian at oob.id.au'
May 28 09:32:29.003350: "xauth-rsa"[2] 1.152.246.98 #1: certificate
verified OK:
E=ian at oob.id.au,CN=ian at oob.id.au,O=OOB,L=Surrey Hills,ST=Victoria,C=AU
May 28 09:32:29.006511: "xauth-rsa"[2] 1.152.246.98 #1: I am sending my cert
May 28 09:32:29.015442: "xauth-rsa"[2] 1.152.246.98 #1: STATE_MAIN_R3:
sent MR3,
ISAKMP SA established {auth=RSA_SIG cipher=aes_256 integ=sha2_256
group=MODP2048}
May 28 09:32:29.095671: "xauth-rsa"[2] 1.152.246.98 #1: XAUTH: Sending
Username/Password request (MAIN_R3->XAUTH_R0)
May 28 09:32:29.596575: "xauth-rsa"[2] 1.152.246.98 #1: STATE_XAUTH_R0:
retransmission; will wait 0.5 seconds for response
May 28 09:32:29.676973: "xauth-rsa"[2] 1.152.246.98 #1: XAUTH: Sending
Username/Password request (XAUTH_R0->XAUTH_R0)
May 28 09:32:30.097773: "xauth-rsa"[2] 1.152.246.98 #1: STATE_XAUTH_R0:
retransmission; will wait 1 seconds for response
May 28 09:32:30.178119: "xauth-rsa"[2] 1.152.246.98 #1: XAUTH: Sending
Username/Password request (XAUTH_R0->XAUTH_R0)
May 28 09:32:31.099404: "xauth-rsa"[2] 1.152.246.98 #1: STATE_XAUTH_R0:
retransmission; will wait 2 seconds for response
May 28 09:32:31.179687: "xauth-rsa"[2] 1.152.246.98 #1: XAUTH: Sending
Username/Password request (XAUTH_R0->XAUTH_R0)
May 28 09:32:33.102328: "xauth-rsa"[2] 1.152.246.98 #1: STATE_XAUTH_R0:
retransmission; will wait 4 seconds for response
May 28 09:32:33.183061: "xauth-rsa"[2] 1.152.246.98 #1: XAUTH: Sending
Username/Password request (XAUTH_R0->XAUTH_R0)
May 28 09:32:37.106032: "xauth-rsa"[2] 1.152.246.98 #1: STATE_XAUTH_R0:
retransmission; will wait 8 seconds for response
May 28 09:32:37.186377: "xauth-rsa"[2] 1.152.246.98 #1: XAUTH: Sending
Username/Password request (XAUTH_R0->XAUTH_R0)
May 28 09:32:38.478684: "xauth-rsa"[2] 1.152.246.98 #1: XAUTH: password file
authentication method requested to authenticate user 'iand'
May 28 09:32:38.478779: "xauth-rsa"[2] 1.152.246.98 #1: XAUTH: password file
(/etc/ipsec.d/passwd) open.
May 28 09:32:38.496882: "xauth-rsa"[2] 1.152.246.98 #1: XAUTH: success
user(iand:xauth-rsa)
May 28 09:32:38.496987: "xauth-rsa"[2] 1.152.246.98 #1: XAUTH: #1:
completed for
user 'iand' with status SUCCESSS
May 28 09:32:38.497020: "xauth-rsa"[2] 1.152.246.98 #1: XAUTH: User iand:
Authentication Successful
May 28 09:32:38.538694: "xauth-rsa"[2] 1.152.246.98 #1: XAUTH:
xauth_inR1(STF_OK)
May 28 09:32:38.538782: "xauth-rsa"[2] 1.152.246.98 #1: STATE_MAIN_R3:
sent MR3,
ISAKMP SA established {auth=RSA_SIG cipher=aes_256 integ=sha2_256
group=MODP2048}
May 28 09:32:38.539097: "xauth-rsa"[2] 1.152.246.98 #1: modecfg_inR0(STF_OK)
May 28 09:32:38.539207: "xauth-rsa"[2] 1.152.246.98 #1: STATE_MODE_CFG_R1:
ModeCfg
Set sent, expecting Ack {auth=RSA_SIG cipher=aes_256 integ=sha2_256
group=MODP2048}
May 28 09:32:38.619774: "xauth-rsa"[2] 1.152.246.98 #1: the peer proposed:
0.0.0.0/0:0/0 -> 172.21.1.201/32:0/0
May 28 09:32:38.620555: "xauth-rsa"[2] 1.152.246.98 #2: responding to
Quick Mode
proposal {msgid:281f9195}
May 28 09:32:38.620630: "xauth-rsa"[2] 1.152.246.98 #2:     us:
0.0.0.0/0===144.132.45.114<144.132.45.114>[C=AU, ST=Victoria, L=Surrey
Hills, O=OOB,
CN=vpn.oob.id.au,MS+XS+S=C]
May 28 09:32:38.620683: "xauth-rsa"[2] 1.152.246.98 #2:   them:
1.152.246.98[C=AU,
ST=Victoria, L=Surrey Hills, O=OOB, CN=ian at oob.id.au,
E=ian at oob.id.au,+MC+XC+S=C]===172.21.1.201/32
May 28 09:32:38.621817: "xauth-rsa"[2] 1.152.246.98 #2: STATE_QUICK_R1:
sent QR1,
inbound IPsec SA installed, expecting QI2 tunnel mode {ESP/NAT=>0x05e0abb6
<0xaa013f9e xfrm=AES_CBC_256-HMAC_SHA1_96 NATOA=none NATD=1.152.246.98:4500
DPD=active username=iand}
May 28 09:32:38.826579: "xauth-rsa"[2] 1.152.246.98 #2: STATE_QUICK_R2:
IPsec SA
established tunnel mode {ESP/NAT=>0x05e0abb6 <0xaa013f9e
xfrm=AES_CBC_256-HMAC_SHA1_96 NATOA=none NATD=1.152.246.98:4500 DPD=active
username=iand}
May 28 09:32:57.709046: "xauth-rsa"[2] 1.152.246.98 #1: received Delete
SA(0x05e0abb6) payload: deleting IPSEC State #2
May 28 09:32:57.709113: "xauth-rsa"[2] 1.152.246.98 #2: deleting other
state #2
(STATE_QUICK_R2) and sending notification
May 28 09:32:57.709219: "xauth-rsa"[2] 1.152.246.98 #2: ESP traffic
information:
in=2KB out=292B XAUTHuser=iand
May 28 09:32:57.840868: "xauth-rsa" #1: deleting state (STATE_MODE_CFG_R1)
and
sending notification
May 28 09:32:57.841737: "xauth-rsa"[2] 1.152.246.98: deleting connection
"xauth-rsa"[2] 1.152.246.98 instance with peer 1.152.246.98
{isakmp=#0/ipsec=#0}
May 28 09:32:57.841828: packet from 1.152.246.98:4500: received and
ignored empty
informational notification payload


And nothing at all is being output when I try an ikev2 connection. Do I
need to change a parameter to increase the level of logging?


Ian



More information about the Swan mailing list