An example of a line from a system log file:
May 13 11:50:03 intra charon: 12[IKE1] <C1|3> authentication of
'CN=intra.net.lan' with RSA_EMSA_PKCS1_NULL successful
|
|
Date and time of the event |
|
|
Hostname of the Intra2net System |
|
|
IPSec service identifier (strongSwan version 6) |
|
|
Thread ID, module name, and log level of the message |
|
|
Connection identifier (prefixed with "C") and internal ID of the IKE session. If no connection ID has been explicitly assigned yet, only the IKE-SA ID is displayed. Connection IDs can be mapped to connection names via the "" menu. |
|
|
Message |
Errors in phase 1 usually mean an incorrect authentication configuration (e.g. incorrectly configured certificates or a different IPSec ID used) or incorrectly configured encryption algorithms.
At the beginning of each connection, the peers typically exchange information about their capabilities and recognize whether the connection is passing through NAT:
received packet: from 192.168.1.200[500] to 192.168.1.254[500] (416 bytes) parsed ID_PROT request 0 [ SA V V V V V ] received XAuth vendor ID received DPD vendor ID received FRAGMENTATION vendor ID received NAT-T (RFC 3947) vendor ID
Next is the actual function of the packet:
192.168.1.200 is initiating a Main Mode IKE_SA
Now the appropriate encryption profile is being selected. If successful, it will look something like this:
selected proposal: IKE:AES_CBC_192/HMAC_SHA2_256_128/PRF_HMAC_SHA2_256/MODP_1536
If the encryption profile requested by the other party does not match the locally configured one, this is logged in detail:
received proposals: IKE:CAMELLIA_CBC_256/HMAC_SHA1_96/PRF_HMAC_SHA1/MODP_1024 configured proposals: IKE:AES_CBC_192/HMAC_SHA2_256_128/PRF_HMAC_SHA2_256... no proposal found generating INFORMATIONAL_V1 request 3626487893 [ N(NO_PROP) ]
The shorthand "N(NO_PROP)" stands for the message NO_PROPOSAL_CHOSEN.
The Intra2net system then prompts the remote peer to send its certificate:
sending cert request for "CN=vpntest.net.lan"
The remote peer responds with its certificate and requests the Intra2net system's certificate:
parsed ID_PROT request 0 [ ID CERT SIG CERTREQ N(INITIAL_CONTACT) ] received cert request for 'CN=intra.net.lan' received end entity cert "CN=vpntest.net.lan"
Now the connection can be clearly assigned to a configured VPN:
looking for RSA signature peer configs matching 192.168.1.254... 192.168.1.200[CN=vpntest.net.lan(ID_DER_ASN1_DN)] selected peer config "C1"
We now have all the necessary information to successfully complete Phase 1:
using trusted certificate "CN=vpntest.net.lan" authentication of 'CN=vpntest.net.lan' with RSA_EMSA_PKCS1_NULL successful authentication of 'CN=intra.net.lan' (myself) successful IKE_SA C1[1] established between 192.168.1.254[CN=intra.net.lan]... 192.168.1.200[CN=vpntest.net.lan]
If, on the other hand, the wrong certificate is configured on the other end, the connection cannot be matched:
received cert request for 'CN=intra.net.lan' received end entity cert "CN=wrongcert.net.lan" looking for RSA signature peer configs matching 192.168.1.254... 192.168.1.200[CN=wrongcert.net.lan(ID_DER_ASN1_DN)] no peer config found generating INFORMATIONAL_V1 request 2748090117 [ HASH N(AUTH_FAILED) ]
If the other peer has the correct certificate but expects a different one from the Intra2net system, the connection is established first on the Intra2net system's side. However, the other peer terminates the connection immediately afterward:
parsed INFORMATIONAL_V1 request 1539580505 [ HASH D ] received DELETE for IKE_SA C1[1] deleting IKE_SA C1[1] between 192.168.1.254[CN=intra.net.lan]... 192.168.1.200[CN=vpntest.net.lan]
If the peer is completely unreachable or rejects all connection attempts without responding, the following pattern will appear in the log:
vici initiate CHILD_SA 'C1' initiating Main Mode IKE_SA C1[2] to 192.168.1.200 generating ID_PROT request 0 [ SA V V V V V ] sending packet: from 192.168.1.254[500] to 192.168.1.200[500] (416 bytes) sending retransmit 1 of request message ID 0, seq 1 sending retransmit 2 of request message ID 0, seq 1 giving up after 2 retransmits peer not responding, trying again (2/3) peer not responding, trying again (3/3) establishing IKE_SA failed, peer not responding
The connection attempt is repeated several times at the various levels and is given up after about 40 seconds. If the connection is configured to always be established, a new attempt begins shortly afterwards.
In phase 2, the data for the IP tunnels is negotiated. If an error occurs here, it is mostly due to incorrect IP addresses for the tunnel. However, there may not be suitable encryption algorithms here either.
A successful completion of Phase 2 might look like this:
parsed QUICK_MODE request 3970744905 [ HASH ]
CHILD_SA C1{12} established with SPIs cbf076da_i c112327b_o and TS 192.168.101.0/24
=== 192.168.100.0/24
The message shows the net of the local side on the left and the net of the remote side on the right.
If the data configured for the tunnel on the other end does not match, an error occurs:
no matching CHILD_SA config found for 192.168.100.0/24 === 192.168.103.0/24 generating INFORMATIONAL_V1 request 4234879466 [ HASH N(INVAL_ID) ]
If the other peer does not agree with your tunnel configuration, this is logged as follows:
received INVALID_ID_INFORMATION error notify
If the wrong encryption profile is configured on the other peer, the symptoms are very similar to those in Phase 1:
received proposals: ESP:CAMELLIA_CBC_256/HMAC_SHA1_96/MODP_1536/NO_EXT_SEQ configured proposals: ESP:AES_CBC_192/HMAC_SHA2_256_128/MODP_1536/NO_EXT_SEQ,... no matching proposal found, sending NO_PROPOSAL_CHOSEN generating INFORMATIONAL_V1 request 1561624858 [ HASH N(NO_PROP) ]
If the remote peer does not agree with your encryption profile, this is logged as follows:
received NO_PROPOSAL_CHOSEN error notify
If the VPN connection is successfully established and the offline detection feature is enabled, offline detection (Dead Peer Detection (DPD)) is performed and logged on a regular basis:
sending DPD request generating INFORMATIONAL_V1 request 2386962670 [ HASH N(DPD) ] sending packet: from 192.168.1.254[500] to 192.168.1.200[500] (108 bytes) received packet: from 192.168.1.200[500] to 192.168.1.254[500] (108 bytes) parsed INFORMATIONAL_V1 request 2215444627 [ HASH N(DPD) ] generating INFORMATIONAL_V1 request 4233730633 [ HASH N(DPD_ACK) ] sending packet: from 192.168.1.254[500] to 192.168.1.200[500] (108 bytes) received packet: from 192.168.1.200[500] to 192.168.1.254[500] (108 bytes) parsed INFORMATIONAL_V1 request 2351292760 [ HASH N(DPD_ACK) ]