I have managed to take different (i.e. older) version of Forticlient (5 vs 6) which actually allows to turn debug mode on. So, I have managed to check two things:
1) Client side logs and problem with xauth
2) Switching to aggressive mode
Ad.1
As I have mentioned, I have checked logs and client side.
3/6/2019 9:20:24 AM Debug VPN HASH computed:
3/6/2019 9:20:24 AM Debug VPN 9f7200e3 3d31a872 14aecea9 05733cc1 55d5eda7
3/6/2019 9:20:24 AM Debug VPN HASH for PSK validated.
3/6/2019 9:20:24 AM Debug VPN peer's ID:
3/6/2019 9:20:24 AM Debug VPN 01110000 b2ff2a0e
3/6/2019 9:20:24 AM Debug VPN ===
3/6/2019 9:20:24 AM Debug VPN ISAKMP-SA established clientAddr[500]-routerAddr[500]
spi:8243bc412c8b6033:62a4b23f51445745
3/6/2019 9:20:24 AM Debug VPN ===
3/6/2019 9:20:26 AM Debug VPN peer has not completed Xauth exchange
3/6/2019 9:20:26 AM Debug VPN CHKPH1THERE: no established ph1 handler found
3/6/2019 9:20:27 AM Debug VPN peer has not completed Xauth exchange
3/6/2019 9:20:27 AM Debug VPN CHKPH1THERE: no established ph1 handler found
It seems that there are problems with xauth - however I cannot find what exact problem it is - disabling xauth explictly in ASA configuration does not change anything. I have disabled it by:
tunnel-group DefaultRAGroup ipsec-attributes
ikev1 user-authentication none
However, it breaks native Windows VPN client so I reverted this change back to defaults i.e:
ikev1 user-authentication xauth
Due to lack of ideas, I decided to try
Ad. 2) Aggresive mode.
Here I am mislead by non acceptable proposals. Dunno why it gives such error.
I have defined two policies:
crypto ikev1 policy 10
authentication pre-share
encryption 3des
hash sha
group 2
lifetime 86400
crypto ikev1 policy 20
authentication pre-share
encryption aes
hash sha
group 2
lifetime 86400
Connection debug seems to confirm it:
RECV PACKET from clientAddr
ISAKMP Header
Initiator COOKIE: a6 29 1e d2 82 38 d0 35
Responder COOKIE: 00 00 00 00 00 00 00 00
Next Payload: Security Association
Version: 1.0
Exchange Type: Aggressive Mode
Flags: (none)
MessageID: 00000000
Length: 450
Payload Security Association
Next Payload: Key Exchange
Reserved: 00
Payload Length: 96
DOI: IPsec
Situation:(SIT_IDENTITY_ONLY)
Payload Proposal
Next Payload: None
Reserved: 00
Payload Length: 84
Proposal #: 1
Protocol-Id: PROTO_ISAKMP
SPI Size: 0
# of transforms: 2
Payload Transform
Next Payload: Transform
Reserved: 00
Payload Length: 36
Transform #: 1
Transform-Id: KEY_IKE
Reserved2: 0000
Life Type: seconds
Life Duration (Hex): 00 01 51 80
Encryption Algorithm: 3DES-CBC
Authentication Method: Preshared key
Hash Algorithm: SHA1
Group Description: Group 2
Payload Transform
Next Payload: None
Reserved: 00
Payload Length: 40
Transform #: 2
Transform-Id: KEY_IKE
Reserved2: 0000
Life Type: seconds
Life Duration (Hex): 00 01 51 80
Encryption Algorithm: AES-CBC
Key Length: 128
Authentication Method: Preshared key
Hash Algorithm: SHA1
Group Description: Group 2
Payload Key Exchange
Next Payload: Nonce
Reserved: 00
Payload Length: 132
Data:
(...)
but in the end it tells that:
Mar 06 18:12:20 [IKEv1]IP = clientAddr, IKE_DECODE RECEIVED Message (msgid=0) with payloads : HDR + SA (1)
+ KE (4) + NONCE (10) + ID (5) + VENDOR (13) + VENDOR (13) + VENDOR (13) + VENDOR (13) + VENDOR (13) + VENDOR
(13) + VENDOR (13) + VENDOR (13) + NONE (0) total length : 450
Mar 06 18:12:20 [IKEv1 DEBUG]IP = clientAddr, processing SA payload
Mar 06 18:12:20 [IKEv1 DEBUG]IP = clientAddr, processing ke payload
Mar 06 18:12:20 [IKEv1 DEBUG]IP = clientAddr, processing ISA_KE payload
Mar 06 18:12:20 [IKEv1 DEBUG]IP = clientAddr, processing nonce payload
Mar 06 18:12:20 [IKEv1 DEBUG]IP = clientAddr, processing ID payload
Mar 06 18:12:20 [IKEv1 DECODE]IP = clientAddr, ID_FQDN ID received, len 14
0000: 44656661 756C7452 4147726F 7570 DefaultRAGroup
Mar 06 18:12:20 [IKEv1 DEBUG]IP = clientAddr, processing VID payload
Mar 06 18:12:20 [IKEv1 DEBUG]IP = clientAddr, Received Cisco Unity client VID
Mar 06 18:12:20 [IKEv1 DEBUG]IP = clientAddr, processing VID payload
Mar 06 18:12:20 [IKEv1 DEBUG]IP = clientAddr, Received NAT-Traversal RFC VID
Mar 06 18:12:20 [IKEv1 DEBUG]IP = clientAddr, processing VID payload
Mar 06 18:12:20 [IKEv1 DEBUG]IP = clientAddr, processing VID payload
Mar 06 18:12:20 [IKEv1 DEBUG]IP = clientAddr, Received NAT-Traversal ver 02 VID
Mar 06 18:12:20 [IKEv1 DEBUG]IP = clientAddr, processing VID payload
Mar 06 18:12:20 [IKEv1 DEBUG]IP = clientAddr, Received xauth V6 VID
Mar 06 18:12:20 [IKEv1 DEBUG]IP = clientAddr, processing VID payload
Mar 06 18:12:20 [IKEv1 DEBUG]IP = clientAddr, Received DPD VID
Mar 06 18:12:20 [IKEv1 DEBUG]IP = clientAddr, processing VID payload
Mar 06 18:12:20 [IKEv1 DEBUG]IP = clientAddr, processing VID payload
Mar 06 18:12:20 [IKEv1]IP = clientAddr, Connection landed on tunnel_group DefaultRAGroup
Mar 06 18:12:20 [IKEv1 DEBUG]Group = DefaultRAGroup, IP = clientAddr, processing IKE SA payload
Mar 06 18:12:20 [IKEv1]IP = clientAddr, IKE_DECODE SENDING Message (msgid=0) with payloads : HDR + NOTIFY
(11) + NONE (0) total length : 136
Mar 06 18:12:20 [IKEv1 DEBUG]Group = DefaultRAGroup, IP = clientAddr, All SA proposals found unacceptable
Mar 06 18:12:20 [IKEv1]IP = clientAddr, All IKE SA proposals found unacceptable!
Mar 06 18:12:20 [IKEv1 DEBUG]Group = DefaultRAGroup, IP = clientAddr, IKE AM Responder FSM error history
(struct &0xc868ac48) <state>, <event>: AM_DONE, EV_ERROR-->AM_BLD_MSG2, EV_PROCESS_SA-->AM_BLD_MSG2,
EV_GROUP_LOOKUP-->AM_BLD_MSG2, EV_PROCESS_MSG-->AM_BLD_MSG2, EV_CREATE_TMR-->AM_START, EV_RCV_MSG-->AM_START,
EV_START_AM-->AM_START, EV_START_AM
Mar 06 18:12:20 [IKEv1 DEBUG]Group = DefaultRAGroup, IP = clientAddr, IKE SA AM:84212e9b terminating:
flags 0x0100c001, refcnt 0, tuncnt 0
Mar 06 18:12:20 [IKEv1 DEBUG]Group = DefaultRAGroup, IP = clientAddr, sending delete/delete with reason message
Client side logs, it just seems to break when ASA does not find any acceptable proposals:
3/6/2019 9:36:33 AM Debug VPN begin Aggressive mode.
3/6/2019 9:36:33 AM Debug VPN new cookie: 6f312b96f65ab7ae
3/6/2019 9:36:33 AM Debug VPN use ID type of IPv4_address
3/6/2019 9:36:33 AM Debug VPN compute DH's private.
3/6/2019 9:36:33 AM Debug VPN (some encoded data)
3/6/2019 9:36:33 AM Debug VPN compute DH's public.
3/6/2019 9:36:33 AM Debug VPN (some encoded data)
3/6/2019 9:36:33 AM Debug VPN authmethod is pre-shared key
3/6/2019 9:36:33 AM Debug VPN add payload of len 92, next type 4
3/6/2019 9:36:33 AM Debug VPN add payload of len 128, next type 10
3/6/2019 9:36:33 AM Debug VPN add payload of len 16, next type 5
3/6/2019 9:36:33 AM Debug VPN add payload of len 8, next type 13
3/6/2019 9:36:33 AM Debug VPN add payload of len 16, next type 13
3/6/2019 9:36:32 AM Debug VPN (repeated 3 times in last 0 sec) add payload of len 16, next type 13
3/6/2019 9:36:33 AM Debug VPN add payload of len 8, next type 13
3/6/2019 9:36:33 AM Debug VPN add payload of len 16, next type 13
3/6/2019 9:36:32 AM Debug VPN (repeated 1 times in last 0 sec) add payload of len 16, next type 13
3/6/2019 9:36:33 AM Debug VPN add payload of len 16, next type 0
3/6/2019 9:36:33 AM Debug VPN 440 bytes from clientAddr[500] to routerAddr[500]
3/6/2019 9:36:33 AM Debug VPN sockname 0.0.0.0[500]
3/6/2019 9:36:33 AM Debug VPN send packet from clientAddr[500]
3/6/2019 9:36:33 AM Debug VPN send packet to routerAddr[500]
3/6/2019 9:36:33 AM Debug VPN 1 times of 440 bytes message will be sent to routerAddr[500]
3/6/2019 9:36:33 AM Debug VPN (some encoded data)
3/6/2019 9:36:33 AM Debug VPN resend phase1 packet 6f312b96f65ab7ae:0000000000000000
3/6/2019 9:36:33 AM Information VPN id=96566 msg="negotiation information, loc_ip=clientAddr loc_port=500 rem_ip=routerAddr rem_port=500 out_if=0 vpn_tunnel=test action=negotiate init=local mode=aggressive stage=1 dir=outbound status=success Initiator: sent routerAddr aggressive mode message #1
(OK)" vpntunnel=test vpntype=ipsec
3/6/2019 9:36:33 AM Debug VPN ===
3/6/2019 9:36:33 AM Debug VPN 136 bytes message received from routerAddr[500] to clientAddr[500]
3/6/2019 9:36:33 AM Debug VPN (some encoded data)
3/6/2019 9:36:33 AM Debug VPN receive Information.
3/6/2019 9:36:33 AM Debug VPN reject the packet, received unexpecting payload type 0.
3/6/2019 9:36:34 AM Debug VPN CHKPH1THERE: no established ph1 handler found3/6/2019 9:36:34 AM Debug VPN (repeated 1 times in last 1 sec) CHKPH1THERE: no established ph1 handler found
That's all I have managed to check so far.
