[c-nsp] iPad IPSEC to 1841 router - communication failed - FSM error
Marc Haber
mh+cisco-nsp at zugschlus.de
Sun Apr 8 04:52:59 EDT 2012
Hi,
In my lab, I have an 1841 router running IOS 12.4(24)T1. The router is
serving as an IPSEC endpoint for a quite small number of Windows
clients running the Cisco IPSEC client 5.0.04.0300. I do not have a
clue whether these versions are only blatantly or dangerously
outdated. Router configuration is quoted below, hopefully successfully
sanitized.
I am currently trying to have an iPad connect to the router via IPSEC.
Unfortunately, this does not get past the XAUTH phase of the login
process. After entering the password, 15 to 20 seconds pass before the
iPad complains with a quite generic error message "VPN-Verbindung,
Kommunikation mit VPN-Server fehlgeschlagen". Since the iPad is
unfortunately configured for German language, here is my translation:
"VPN-Connection, Communicating with VPN Server failed". Debug output
of the router suggests that there is a 15 second timeout passing.
The router's debug output ("debug crypto isakmp", "debug crypto
ipsec") is attached as well. If I should repeat the process with more
debugging options set, please say so. The debug output contains
"ISAKMP:FSM error - Message from AAA grp/user." right before the 15
seconds timeout.
I can connect using the same account from a Windows IPSEC client.
Debug output from the 1841 for the successfully connecting Windows
client is also quoted below. This contains the "ISAKMP:FSM error"
message as well.
What can I do to make the iPad work? The iPad VPN Client doesn't have
too many configuration options. I can only choose IPSEC as a protocol,
Server IP address, account, password, group name
("InternClient200910") and the shared secret. "Use Certificate" is set
to Zero, and when I deliberately enter a wrong shared secret, I do not
get to the Username/Password prompt. I am therefore reasonably sure
that the shared secret is entered in the iPad correctly. Is there any
way to have the iPad share more debug info or maybe even a log?
If anybody has a simliar setup working and would like to share a
working configuration, I am always open to try it. The 1841 is a test
box and I can freely change its configuration. The only "requirement"
is that it should be possible to connect with the Windows client to
the newly configured router as well after the operation.
Any hints will be appreciated. Thanks in advance and happy easter.
Greetings
Marc
Router data:
Cisco IOS Software, 1841 Software (C1841-ADVIPSERVICESK9-M), Version 12.4(24)T1, RELEASE SOFTWARE (fc3)
Technical Support: http://www.cisco.com/techsupport
Copyright (c) 1986-2009 by Cisco Systems, Inc.
Compiled Fri 19-Jun-09 13:56 by prod_rel_team
ROM: System Bootstrap, Version 12.4(13r)T, RELEASE SOFTWARE (fc1)
r00606 uptime is 1 year, 17 weeks, 1 day, 19 hours, 59 minutes
System returned to ROM by power-on
System restarted at 13:12:26 UTC Thu Dec 9 2010
System image file is "flash:c1841-advipservicesk9-mz.124-24.T1.bin"
Cisco 1841 (revision 7.0) with 238592K/23552K bytes of memory.
Processor board ID FCZ1224723C
2 FastEthernet interfaces
2 Virtual Private Network (VPN) Modules
DRAM configuration is 64 bits wide with parity disabled.
191K bytes of NVRAM.
62720K bytes of ATA CompactFlash (Read/Write)
Configuration register is 0x2102
The relevant parts of router configuration:
version 12.4
service timestamps debug datetime msec
service timestamps log datetime msec
no service password-encryption
!
hostname r00606
!
boot-start-marker
boot-end-marker
!
logging message-counter syslog
logging buffered 51200 warnings
!
aaa new-model
!
!
aaa authentication login default local
aaa authentication login userauthen local
aaa authentication login localauth local
aaa authorization exec default local
aaa authorization network groupauthor local
!
!
aaa session-id common
!
crypto pki trustpoint TP-self-signed-1872590029
enrollment selfsigned
subject-name cn=IOS-Self-Signed-Certificate-1872590029
revocation-check none
rsakeypair TP-self-signed-1872590029
crypto pki certificate chain TP-self-signed-1872590029
certificate self-signed 01
<snip>
quit
dot11 syslog
ip source-route
ip cef
no ip domain lookup
ip domain name example.com
ip name-server 192.168.248.45
no ipv6 cef
ntp server 192.168.248.14
!
multilink bundle-name authenticated
!
username marc.haber privilege 15 secret 5 <snip>
!
crypto isakmp policy 3
encr aes 256
authentication pre-share
group 2
!
crypto isakmp client configuration group InternClient200910
key <snip>
dns 10.1.2.11 10.1.2.45
domain internal.example
pool ippool
acl DefaultrouteTunnel
crypto ipsec transform-set InternTransformSet esp-aes 256 esp-sha-hmac
!
crypto dynamic-map InternDynmap 10
set transform-set InternTransformSet
reverse-route
!
!
crypto map InternClientMap client authentication list userauthen
crypto map InternClientMap isakmp authorization list groupauthor
crypto map InternClientMap client configuration address respond
crypto map InternClientMap 10 ipsec-isakmp dynamic InternDynmap
!
archive
log config
hidekeys
!
!
ip scp server enable
!
!
!
interface FastEthernet0/0
description $ETH-LAN$$ETH-SW-LAUNCH$$INTF-INFO-FE 0$
ip address 192.168.248.11 255.255.255.248
duplex auto
speed auto
crypto map InternClientMap
!
interface FastEthernet0/1
no ip address
shutdown
duplex auto
speed auto
!
ip local pool ippool 10.2.60.1 10.2.60.30
ip default-gateway 192.168.248.14
ip forward-protocol nd
ip route 0.0.0.0 0.0.0.0 192.168.248.14
ip route 10.2.60.0 255.255.255.0 Null0
no ip http server
ip http access-class 23
ip http authentication local
no ip http secure-server
ip http timeout-policy idle 60 life 86400 requests 10000
!
!
!
ip access-list extended DefaultrouteTunnel
permit ip any any
!
access-list 23 permit 86.214.131.164
access-list 23 permit 85.214.68.41
access-list 23 permit 10.1.108.0 0.0.1.255
access-list 23 permit 10.1.2.0 0.0.0.255
no cdp run
!
!
!
!
!
snmp-server community <snip> RO 23
!
control-plane
!
!
banner login ^Cla
*****************************************************
* authorized access only *
*****************************************************
^C
!
line con 0
exec-timeout 30 0
password <snip>
line aux 0
password <snip>
line vty 0 4
access-class 23 in
exec-timeout 30 0
privilege level 15
transport input ssh
line vty 5 15
access-class 23 in
exec-timeout 30 0
privilege level 15
transport input ssh
!
scheduler allocate 20000 1000
end
output of debug crypto isakamp, debug crypto ipsec:
Apr 8 08:09:49.004: ISAKMP (0): received packet from 91.10.64.182 dport 500 sport 500 Global (N) NEW SA
Apr 8 08:09:49.004: ISAKMP: Created a peer struct for 91.10.64.182, peer port 500
Apr 8 08:09:49.004: ISAKMP: New peer created peer = 0x659E57C8 peer_handle = 0x80000038
Apr 8 08:09:49.004: ISAKMP: Locking peer struct 0x659E57C8, refcount 1 for crypto_isakmp_process_block
Apr 8 08:09:49.004: ISAKMP:(0):Setting client config settings 668D0A54
Apr 8 08:09:49.004: ISAKMP:(0):(Re)Setting client xauth list and state
Apr 8 08:09:49.004: ISAKMP/xauth: initializing AAA request
Apr 8 08:09:49.004: ISAKMP: local port 500, remote port 500
Apr 8 08:09:49.004: ISAKMP:(0):insert sa successfully sa = 666FA960
Apr 8 08:09:49.004: ISAKMP:(0): processing SA payload. message ID = 0
Apr 8 08:09:49.004: ISAKMP:(0): processing ID payload. message ID = 0
Apr 8 08:09:49.004: ISAKMP (0): ID payload
next-payload : 13
type : 11
group id : InternClient200910
protocol : 0
port : 0
length : 29
Apr 8 08:09:49.004: ISAKMP:(0):: peer matches *none* of the profiles
Apr 8 08:09:49.004: ISAKMP:(0): processing vendor id payload
Apr 8 08:09:49.004: ISAKMP:(0): vendor ID seems Unity/DPD but major 69 mismatch
Apr 8 08:09:49.004: ISAKMP (0): vendor ID is NAT-T RFC 3947
Apr 8 08:09:49.004: ISAKMP:(0): processing vendor id payload
Apr 8 08:09:49.004: ISAKMP:(0): vendor ID seems Unity/DPD but major 198 mismatch
Apr 8 08:09:49.008: ISAKMP:(0): processing vendor id payload
Apr 8 08:09:49.008: ISAKMP:(0): vendor ID seems Unity/DPD but major 29 mismatch
Apr 8 08:09:49.008: ISAKMP:(0): processing vendor id payload
Apr 8 08:09:49.008: ISAKMP:(0): vendor ID seems Unity/DPD but major 245 mismatch
Apr 8 08:09:49.008: ISAKMP (0): vendor ID is NAT-T v7
Apr 8 08:09:49.008: ISAKMP:(0): processing vendor id payload
Apr 8 08:09:49.008: ISAKMP:(0): vendor ID seems Unity/DPD but major 114 mismatch
Apr 8 08:09:49.008: ISAKMP:(0): processing vendor id payload
Apr 8 08:09:49.008: ISAKMP:(0): vendor ID seems Unity/DPD but major 227 mismatch
Apr 8 08:09:49.008: ISAKMP:(0): processing vendor id payload
Apr 8 08:09:49.008: ISAKMP:(0): vendor ID seems Unity/DPD but major 250 mismatch
Apr 8 08:09:49.008: ISAKMP:(0): processing vendor id payload
Apr 8 08:09:49.008: ISAKMP:(0): vendor ID seems Unity/DPD but major 157 mismatch
Apr 8 08:09:49.008: ISAKMP:(0): vendor ID is NAT-T v3
Apr 8 08:09:49.008: ISAKMP:(0): processing vendor id payload
Apr 8 08:09:49.008: ISAKMP:(0): vendor ID seems Unity/DPD but major 164 mismatch
Apr 8 08:09:49.008: ISAKMP:(0): processing vendor id payload
Apr 8 08:09:49.008: ISAKMP:(0): vendor ID seems Unity/DPD but major 123 mismatch
Apr 8 08:09:49.008: ISAKMP:(0): vendor ID is NAT-T v2
Apr 8 08:09:49.008: ISAKMP:(0): processing vendor id payload
Apr 8 08:09:49.008: ISAKMP:(0): vendor ID seems Unity/DPD but major 242 mismatch
Apr 8 08:09:49.008: ISAKMP:(0): vendor ID is XAUTH
Apr 8 08:09:49.008: ISAKMP:(0): processing vendor id payload
Apr 8 08:09:49.008: ISAKMP:(0): vendor ID is Unity
Apr 8 08:09:49.008: ISAKMP:(0): processing vendor id payload
Apr 8 08:09:49.008: ISAKMP:(0): vendor ID is DPD
Apr 8 08:09:49.008: ISAKMP:(0): Authentication by xauth preshared
Apr 8 08:09:49.008: ISAKMP:(0):Checking ISAKMP transform 1 against priority 3 policy
Apr 8 08:09:49.012: ISAKMP: life type in seconds
Apr 8 08:09:49.012: ISAKMP: life duration (basic) of 3600
Apr 8 08:09:49.012: ISAKMP: encryption AES-CBC
Apr 8 08:09:49.012: ISAKMP: keylength of 256
Apr 8 08:09:49.012: ISAKMP: auth XAUTHInitPreShared
Apr 8 08:09:49.012: ISAKMP: hash SHA
Apr 8 08:09:49.012: ISAKMP: default group 2
Apr 8 08:09:49.012: ISAKMP:(0):atts are acceptable. Next payload is 3
Apr 8 08:09:49.012: ISAKMP:(0):Acceptable atts:actual life: 86400
Apr 8 08:09:49.012: ISAKMP:(0):Acceptable atts:life: 0
Apr 8 08:09:49.012: ISAKMP:(0):Basic life_in_seconds:3600
Apr 8 08:09:49.012: ISAKMP:(0):Returning Actual lifetime: 3600
Apr 8 08:09:49.012: ISAKMP:(0)::Started lifetime timer: 3600.
Apr 8 08:09:49.012: ISAKMP:(0): processing KE payload. message ID = 0
Apr 8 08:09:49.016: ISAKMP:(0): processing NONCE payload. message ID = 0
Apr 8 08:09:49.016: ISAKMP (0): vendor ID is NAT-T RFC 3947
Apr 8 08:09:49.016: ISAKMP (0): vendor ID is NAT-T v7
Apr 8 08:09:49.016: ISAKMP:(0): vendor ID is NAT-T v3
Apr 8 08:09:49.016: ISAKMP:(0): vendor ID is NAT-T v2
Apr 8 08:09:49.016: ISAKMP:(0):Input = IKE_MESG_FROM_PEER, IKE_AM_EXCH
Apr 8 08:09:49.016: ISAKMP:(0):Old State = IKE_READY New State = IKE_R_AM_AAA_AWAIT
Apr 8 08:09:49.024: ISAKMP:(2052): constructed NAT-T vendor-rfc3947 ID
Apr 8 08:09:49.024: ISAKMP:(2052):SA is doing pre-shared key authentication plus XAUTH using id type ID_IPV4_ADDR
Apr 8 08:09:49.024: ISAKMP (2052): ID payload
next-payload : 10
type : 1
address : 192.168.248.11
protocol : 0
port : 0
length : 12
Apr 8 08:09:49.024: ISAKMP:(2052):Total payload length: 12
Apr 8 08:09:49.024: ISAKMP:(2052): sending packet to 91.10.64.182 my_port 500 peer_port 500 (R) AG_INIT_EXCH
Apr 8 08:09:49.024: ISAKMP:(2052):Sending an IKE IPv4 Packet.
Apr 8 08:09:49.024: ISAKMP:(2052):Input = IKE_MESG_FROM_AAA, PRESHARED_KEY_REPLY
Apr 8 08:09:49.024: ISAKMP:(2052):Old State = IKE_R_AM_AAA_AWAIT New State = IKE_R_AM2
Apr 8 08:09:49.640: ISAKMP (2052): received packet from 91.10.64.182 dport 4500 sport 4500 Global (R) AG_INIT_EXCH
Apr 8 08:09:49.640: ISAKMP:(2052): processing HASH payload. message ID = 0
Apr 8 08:09:49.644: ISAKMP:received payload type 20
Apr 8 08:09:49.644: ISAKMP (2052): His hash no match - this node outside NAT
Apr 8 08:09:49.644: ISAKMP:received payload type 20
Apr 8 08:09:49.644: ISAKMP (2052): His hash no match - this node outside NAT
Apr 8 08:09:49.644: ISAKMP:(2052): processing NOTIFY INITIAL_CONTACT protocol 1
spi 0, message ID = 0, sa = 666FA960
Apr 8 08:09:49.644: ISAKMP:(2052):SA authentication status:
authenticated
Apr 8 08:09:49.644: ISAKMP:(2052):SA has been authenticated with 91.10.64.182
Apr 8 08:09:49.644: ISAKMP:(2052):Detected port,floating to port = 4500
Apr 8 08:09:49.644: ISAKMP: Trying to find existing peer 192.168.248.11/91.10.64.182/4500/
Apr 8 08:09:49.644: ISAKMP:(2052):SA authentication status:
authenticated
Apr 8 08:09:49.644: ISAKMP:(2052): Process initial contact,
bring down existing phase 1 and 2 SA's with local 192.168.248.11 remote 91.10.64.182 remote port 4500
Apr 8 08:09:49.644: ISAKMP:(2052):returning IP addr to the address pool
Apr 8 08:09:49.644: ISAKMP: Trying to insert a peer 192.168.248.11/91.10.64.182/4500/, and inserted successfully 659E57C8.
Apr 8 08:09:49.644: ISAKMP:(2052):Returning Actual lifetime: 3600
Apr 8 08:09:49.644: ISAKMP: set new node 573350674 to CONF_XAUTH
Apr 8 08:09:49.648: IPSEC(key_engine): got a queue event with 1 KMI message(s)
Apr 8 08:09:49.648: ISAKMP:(2052):Sending NOTIFY RESPONDER_LIFETIME protocol 1
spi 1711191280, message ID = 573350674
Apr 8 08:09:49.648: ISAKMP:(2052): sending packet to 91.10.64.182 my_port 4500 peer_port 4500 (R) QM_IDLE
Apr 8 08:09:49.648: ISAKMP:(2052):Sending an IKE IPv4 Packet.
Apr 8 08:09:49.652: ISAKMP:(2052):purging node 573350674
Apr 8 08:09:49.652: ISAKMP: Sending phase 1 responder lifetime 3600
Apr 8 08:09:49.652: ISAKMP:(2052):Input = IKE_MESG_FROM_PEER, IKE_AM_EXCH
Apr 8 08:09:49.652: ISAKMP:(2052):Old State = IKE_R_AM2 New State = IKE_P1_COMPLETE
Apr 8 08:09:49.652: ISAKMP:(2052):Need XAUTH
Apr 8 08:09:49.652: ISAKMP: set new node -404346201 to CONF_XAUTH
Apr 8 08:09:49.652: ISAKMP/xauth: request attribute XAUTH_USER_NAME_V2
Apr 8 08:09:49.652: ISAKMP/xauth: request attribute XAUTH_USER_PASSWORD_V2
Apr 8 08:09:49.652: ISAKMP:(2052): initiating peer config to 91.10.64.182. ID = -404346201
Apr 8 08:09:49.652: ISAKMP:(2052): sending packet to 91.10.64.182 my_port 4500 peer_port 4500 (R) CONF_XAUTH
Apr 8 08:09:49.652: ISAKMP:(2052):Sending an IKE IPv4 Packet.
Apr 8 08:09:49.656: ISAKMP:(2052):Input = IKE_MESG_INTERNAL, IKE_PHASE1_COMPLETE
Apr 8 08:09:49.656: ISAKMP:(2052):Old State = IKE_P1_COMPLETE New State = IKE_XAUTH_REQ_SENT
(ipad asks for user password. I enter the wrong one)
Apr 8 08:10:04.655: ISAKMP:(2052): retransmitting phase 2 CONF_XAUTH -404346201 ...
Apr 8 08:10:04.655: ISAKMP (2052): incrementing error counter on node, attempt 1 of 5: retransmit phase 2
Apr 8 08:10:04.655: ISAKMP (2052): incrementing error counter on sa, attempt 1 of 5: retransmit phase 2
Apr 8 08:10:04.655: ISAKMP:(2052): retransmitting phase 2 -404346201 CONF_XAUTH
Apr 8 08:10:04.655: ISAKMP:(2052): sending packet to 91.10.64.182 my_port 4500 peer_port 4500 (R) CONF_XAUTH
Apr 8 08:10:04.655: ISAKMP:(2052):Sending an IKE IPv4 Packet.
(I have finished entering the password and click OK)
Apr 8 08:10:19.553: ISAKMP (2052): received packet from 91.10.64.182 dport 4500 sport 4500 Global (R) CONF_XAUTH
Apr 8 08:10:19.553: ISAKMP:(2052):processing transaction payload from 91.10.64.182. message ID = -404346201
Apr 8 08:10:19.557: ISAKMP: Config payload REPLY
Apr 8 08:10:19.557: ISAKMP/xauth: reply attribute XAUTH_USER_NAME_V2
Apr 8 08:10:19.557: ISAKMP/xauth: reply attribute XAUTH_USER_PASSWORD_V2
Apr 8 08:10:19.557: ISAKMP:(2052):deleting node -404346201 error FALSE reason "Done with xauth request/reply exchange"
Apr 8 08:10:19.557: ISAKMP:(2052):Input = IKE_MESG_FROM_PEER, IKE_CFG_REPLY
Apr 8 08:10:19.557: ISAKMP:(2052):Old State = IKE_XAUTH_REQ_SENT New State = IKE_XAUTH_AAA_CONT_LOGIN_AWAIT
Apr 8 08:10:19.573: ISAKMP: set new node 1095519141 to CONF_XAUTH
Apr 8 08:10:19.573: ISAKMP/xauth: request attribute XAUTH_USER_NAME_V2
Apr 8 08:10:19.573: ISAKMP/xauth: request attribute XAUTH_USER_PASSWORD_V2
Apr 8 08:10:19.573: ISAKMP:(2052): initiating peer config to 91.10.64.182. ID = 1095519141
Apr 8 08:10:19.573: ISAKMP:(2052): sending packet to 91.10.64.182 my_port 4500 peer_port 4500 (R) CONF_XAUTH
Apr 8 08:10:19.573: ISAKMP:(2052):Sending an IKE IPv4 Packet.
Apr 8 08:10:19.573: ISAKMP:(2052):Input = IKE_MESG_FROM_AAA, IKE_AAA_START_LOGIN
Apr 8 08:10:19.573: ISAKMP:(2052):Old State = IKE_XAUTH_AAA_CONT_LOGIN_AWAIT New State = IKE_XAUTH_REQ_SENT
(iPad asks for password again. I enter the right one this time)
Apr 8 08:10:34.572: ISAKMP:(2052): retransmitting phase 2 CONF_XAUTH 1095519141 ...
Apr 8 08:10:34.572: ISAKMP (2052): incrementing error counter on node, attempt 1 of 5: retransmit phase 2
Apr 8 08:10:34.572: ISAKMP (2052): incrementing error counter on sa, attempt 1 of 5: retransmit phase 2
Apr 8 08:10:34.572: ISAKMP:(2052): retransmitting phase 2 1095519141 CONF_XAUTH
Apr 8 08:10:34.572: ISAKMP:(2052): sending packet to 91.10.64.182 my_port 4500 peer_port 4500 (R) CONF_XAUTH
Apr 8 08:10:34.572: ISAKMP:(2052):Sending an IKE IPv4 Packet.
(I have finished entered the password and click OK)
Apr 8 08:10:43.403: ISAKMP (2052): received packet from 91.10.64.182 dport 4500 sport 4500 Global (R) CONF_XAUTH
Apr 8 08:10:43.403: ISAKMP:(2052):processing transaction payload from 91.10.64.182. message ID = 1095519141
Apr 8 08:10:43.407: ISAKMP: Config payload REPLY
Apr 8 08:10:43.407: ISAKMP/xauth: reply attribute XAUTH_USER_NAME_V2
Apr 8 08:10:43.407: ISAKMP/xauth: reply attribute XAUTH_USER_PASSWORD_V2
Apr 8 08:10:43.407: ISAKMP:(2052):deleting node 1095519141 error FALSE reason "Done with xauth request/reply exchange"
Apr 8 08:10:43.407: ISAKMP:(2052):Input = IKE_MESG_FROM_PEER, IKE_CFG_REPLY
Apr 8 08:10:43.407: ISAKMP:(2052):Old State = IKE_XAUTH_REQ_SENT New State = IKE_XAUTH_AAA_CONT_LOGIN_AWAIT
Apr 8 08:10:43.423: ISAKMP: set new node 276028305 to CONF_XAUTH
Apr 8 08:10:43.423: ISAKMP:(2052): initiating peer config to 91.10.64.182. ID = 276028305
Apr 8 08:10:43.423: ISAKMP:(2052): sending packet to 91.10.64.182 my_port 4500 peer_port 4500 (R) CONF_XAUTH
Apr 8 08:10:43.423: ISAKMP:(2052):Sending an IKE IPv4 Packet.
Apr 8 08:10:43.423: ISAKMP:(2052):Input = IKE_MESG_FROM_AAA, IKE_AAA_CONT_LOGIN
Apr 8 08:10:43.423: ISAKMP:(2052):Old State = IKE_XAUTH_AAA_CONT_LOGIN_AWAIT New State = IKE_XAUTH_SET_SENT
Apr 8 08:10:43.451: ISAKMP (2052): received packet from 91.10.64.182 dport 4500 sport 4500 Global (R) CONF_XAUTH
Apr 8 08:10:43.455: ISAKMP:(2052):processing transaction payload from 91.10.64.182. message ID = 276028305
Apr 8 08:10:43.455: ISAKMP: Config payload ACK
Apr 8 08:10:43.455: ISAKMP:(2052): XAUTH ACK Processed
Apr 8 08:10:43.455: ISAKMP:(2052):deleting node 276028305 error FALSE reason "Transaction mode done"
Apr 8 08:10:43.455: ISAKMP:(2052):Talking to a Unity Client
Apr 8 08:10:43.455: ISAKMP:(2052):Input = IKE_MESG_FROM_PEER, IKE_CFG_ACK
Apr 8 08:10:43.455: ISAKMP:(2052):Old State = IKE_XAUTH_SET_SENT New State = IKE_P1_COMPLETE
Apr 8 08:10:43.455: ISAKMP (2052): received packet from 91.10.64.182 dport 4500 sport 4500 Global (R) QM_IDLE
Apr 8 08:10:43.455: ISAKMP: set new node 316331675 to QM_IDLE
Apr 8 08:10:43.459: ISAKMP:(2052):processing transaction payload from 91.10.64.182. message ID = 316331675
Apr 8 08:10:43.459: ISAKMP: Config payload REQUEST
Apr 8 08:10:43.459: ISAKMP:(2052):checking request:
Apr 8 08:10:43.459: ISAKMP: IP4_ADDRESS
Apr 8 08:10:43.459: ISAKMP: IP4_NETMASK
Apr 8 08:10:43.459: ISAKMP: IP4_DNS
Apr 8 08:10:43.459: ISAKMP: IP4_NBNS
Apr 8 08:10:43.459: ISAKMP: ADDRESS_EXPIRY
Apr 8 08:10:43.459: ISAKMP: APPLICATION_VERSION
Apr 8 08:10:43.459: ISAKMP: MODECFG_BANNER
Apr 8 08:10:43.459: ISAKMP: DEFAULT_DOMAIN
Apr 8 08:10:43.459: ISAKMP: SPLIT_DNS
Apr 8 08:10:43.459: ISAKMP: SPLIT_INCLUDE
Apr 8 08:10:43.459: ISAKMP: INCLUDE_LOCAL_LAN
Apr 8 08:10:43.459: ISAKMP: PFS
Apr 8 08:10:43.459: ISAKMP: MODECFG_SAVEPWD
Apr 8 08:10:43.459: ISAKMP: FW_RECORD
Apr 8 08:10:43.459: ISAKMP: BACKUP_SERVER
Apr 8 08:10:43.459: ISAKMP: MODECFG_BROWSER_PROXY
Apr 8 08:10:43.463: ISAKMP/author: Author request for group InternClient200910successfully sent to AAA
Apr 8 08:10:43.463: ISAKMP:(2052):Input = IKE_MESG_FROM_PEER, IKE_CFG_REQUEST
Apr 8 08:10:43.463: ISAKMP:(2052):Old State = IKE_P1_COMPLETE New State = IKE_CONFIG_AUTHOR_AAA_AWAIT
Apr 8 08:10:43.463: ISAKMP:(2052):Input = IKE_MESG_INTERNAL, IKE_PHASE1_COMPLETE
Apr 8 08:10:43.463: ISAKMP:(2052):Old State = IKE_CONFIG_AUTHOR_AAA_AWAIT New State = IKE_CONFIG_AUTHOR_AAA_AWAIT
Apr 8 08:10:43.463: ISAKMP:(2052):attributes sent in message:
Apr 8 08:10:43.463: Address: 0.2.0.0
Apr 8 08:10:43.467: ISAKMP:(2052):allocating address 10.2.60.11
Apr 8 08:10:43.467: ISAKMP: Sending private address: 10.2.60.11
Apr 8 08:10:43.467: ISAKMP: Sending IP4_DNS server address: 10.1.2.11
Apr 8 08:10:43.467: ISAKMP: Sending IP4_DNS server address: 10.1.2.45
Apr 8 08:10:43.467: ISAKMP: Sending ADDRESS_EXPIRY seconds left to use the address: 3545
Apr 8 08:10:43.467: ISAKMP: Sending APPLICATION_VERSION string: Cisco IOS Software, 1841 Software (C1841-ADVIPSERVICESK9-M), Version 12.4(24)T1, RELEASE SOFTWARE (fc3)
Technical Support: http://www.cisco.com/techsupport
Copyright (c) 1986-2009 by Cisco Systems, Inc.
Compiled Fri 19-Jun-09 13:56 by prod_rel_team
Apr 8 08:10:43.467: ISAKMP: Sending DEFAULT_DOMAIN default domain name: internal.example
Apr 8 08:10:43.467: ISAKMP: Sending split include name DefaultrouteTunnel network 0.0.0.0 mask 0.0.0.0 protocol 0, src port 0, dst port 0
Apr 8 08:10:43.467: ISAKMP: Sending save password reply value 0
Apr 8 08:10:43.467: ISAKMP:(2052): responding to peer config from 91.10.64.182. ID = 316331675
Apr 8 08:10:43.467: ISAKMP: Marking node 316331675 for late deletion
Apr 8 08:10:43.467: ISAKMP:(2052): sending packet to 91.10.64.182 my_port 4500 peer_port 4500 (R) CONF_ADDR
Apr 8 08:10:43.471: ISAKMP:(2052):Sending an IKE IPv4 Packet.
Apr 8 08:10:43.471: ISAKMP:(2052):Talking to a Unity Client
Apr 8 08:10:43.471: ISAKMP:(2052):Input = IKE_MESG_FROM_AAA, IKE_AAA_GROUP_ATTR
Apr 8 08:10:43.471: ISAKMP:(2052):Old State = IKE_CONFIG_AUTHOR_AAA_AWAIT New State = IKE_P1_COMPLETE
Apr 8 08:10:43.471: ISAKMP:FSM error - Message from AAA grp/user.
Apr 8 08:10:43.471: ISAKMP:(2052):Input = IKE_MESG_INTERNAL, IKE_PHASE1_COMPLETE
Apr 8 08:10:43.471: ISAKMP:(2052):Old State = IKE_P1_COMPLETE New State = IKE_P1_COMPLETE
(Debug output stops for a while. 15 seconds timeout?)
Apr 8 08:10:58.470: ISAKMP:(2052): retransmitting phase 2 QM_IDLE 316331675 ...
Apr 8 08:10:58.470: ISAKMP (2052): incrementing error counter on node, attempt 1 of 5: retransmit phase 2
Apr 8 08:10:58.470: ISAKMP (2052): incrementing error counter on sa, attempt 1 of 5: retransmit phase 2
Apr 8 08:10:58.470: ISAKMP:(2052): retransmitting phase 2 316331675 QM_IDLE
Apr 8 08:10:58.470: ISAKMP:(2052): sending packet to 91.10.64.182 my_port 4500 peer_port 4500 (R) QM_IDLE
Apr 8 08:10:58.470: ISAKMP:(2052):Sending an IKE IPv4 Packet.
Apr 8 08:10:59.638: ISAKMP (2052): received packet from 91.10.64.182 dport 4500 sport 4500 Global (R) QM_IDLE
Apr 8 08:10:59.638: ISAKMP: set new node 889057329 to QM_IDLE
Apr 8 08:10:59.642: ISAKMP:(2052): processing HASH payload. message ID = 889057329
Apr 8 08:10:59.642: ISAKMP:(2052): processing DELETE payload. message ID = 889057329
Apr 8 08:10:59.642: ISAKMP:(2052):peer does not do paranoid keepalives.
Apr 8 08:10:59.642: ISAKMP:(2052):peer does not do paranoid keepalives.
Apr 8 08:10:59.642: ISAKMP:(2052):deleting SA reason "No reason" state (R) QM_IDLE (peer 91.10.64.182)
Apr 8 08:10:59.642: ISAKMP:(2052):deleting node 889057329 error FALSE reason "Informational (in) state 1"
Apr 8 08:10:59.642: IPSEC(key_engine): got a queue event with 1 KMI message(s)
Apr 8 08:10:59.642: IPSEC(key_engine_delete_sas): rec'd delete notify from ISAKMP
Apr 8 08:10:59.642: IPSEC(key_engine_delete_sas): delete all SAs shared with peer 91.10.64.182
Apr 8 08:10:59.646: ISAKMP: set new node -2141766346 to QM_IDLE
Apr 8 08:10:59.646: ISAKMP:(2052): sending packet to 91.10.64.182 my_port 4500 peer_port 4500 (R) QM_IDLE
Apr 8 08:10:59.646: ISAKMP:(2052):Sending an IKE IPv4 Packet.
Apr 8 08:10:59.646: ISAKMP:(2052):purging node -2141766346
Apr 8 08:10:59.646: ISAKMP:(2052):Input = IKE_MESG_INTERNAL, IKE_PHASE1_DEL
Apr 8 08:10:59.646: ISAKMP:(2052):Old State = IKE_P1_COMPLETE New State = IKE_DEST_SA
Apr 8 08:10:59.650: ISAKMP:(2052):deleting SA reason "No reason" state (R) QM_IDLE (peer 91.10.64.182)
Apr 8 08:10:59.650: ISAKMP:(0):Can't decrement IKE Call Admission Control stat incoming_active since it's already 0.
Apr 8 08:10:59.650: ISAKMP (2052): returning address 10.2.60.11 to pool
Apr 8 08:10:59.650: ISAKMP: Unlocking peer struct 0x659E57C8 for isadb_mark_sa_deleted(), count 0
Apr 8 08:10:59.650: ISAKMP: returning address 10.2.60.11 to pool
Apr 8 08:10:59.650: ISAKMP: Deleting peer node by peer_reap for 91.10.64.182: 659E57C8
Apr 8 08:10:59.650: ISAKMP: returning address 10.2.60.11 to pool
Apr 8 08:10:59.654: IPSEC(key_engine): got a queue event with 1 KMI message(s)
Apr 8 08:10:59.654: ISAKMP:(2052):Input = IKE_MESG_FROM_PEER, IKE_MM_EXCH
Apr 8 08:10:59.654: ISAKMP:(2052):Old State = IKE_DEST_SA New State = IKE_DEST_SA
(iPad gives error message "VPN-Verbindung, Kommunikation mit
VPN-Server fehlgeschlagen". My translation "VPN-Connection,
Communicating with VPN Server failed")
Apr 8 08:11:08.469: ISAKMP:(2052): retransmitting phase 2 MM_NO_STATE 316331675 ...
Apr 8 08:11:08.469: ISAKMP (2052): incrementing error counter on node, attempt 2 of 5: retransmit phase 2
Apr 8 08:11:08.469: ISAKMP (2052): incrementing error counter on sa, attempt 2 of 5: retransmit phase 2
Apr 8 08:11:08.469: ISAKMP:(2052): retransmitting phase 2 316331675 MM_NO_STATE
Apr 8 08:11:08.469: ISAKMP:(2052): sending packet to 91.10.64.182 my_port 4500 peer_port 4500 (R) MM_NO_STATE
Apr 8 08:11:08.469: ISAKMP:(2052):Sending an IKE IPv4 Packet.pn-serverf
Apr 8 08:11:09.553: ISAKMP:(2052):purging node -404346201
Apr 8 08:11:18.469: ISAKMP:(2052): retransmitting phase 2 MM_NO_STATE 316331675 ...
Apr 8 08:11:18.469: ISAKMP (2052): incrementing error counter on node, attempt 3 of 5: retransmit phase 2
Apr 8 08:11:18.469: ISAKMP (2052): incrementing error counter on sa, attempt 3 of 5: retransmit phase 2
Apr 8 08:11:18.469: ISAKMP:(2052): retransmitting phase 2 316331675 MM_NO_STATE
Apr 8 08:11:18.469: ISAKMP:(2052): sending packet to 91.10.64.182 my_port 4500 peer_port 4500 (R) MM_NO_STATE
Apr 8 08:11:18.469: ISAKMP:(2052):Sending an IKE IPv4 Packet.
Apr 8 08:11:28.468: ISAKMP:(2052): retransmitting phase 2 MM_NO_STATE 316331675 ...
Apr 8 08:11:28.468: ISAKMP (2052): incrementing error counter on node, attempt 4 of 5: retransmit phase 2
Apr 8 08:11:28.468: ISAKMP (2052): incrementing error counter on sa, attempt 4 of 5: retransmit phase 2
Apr 8 08:11:28.468: ISAKMP:(2052): retransmitting phase 2 316331675 MM_NO_STATE
Apr 8 08:11:28.468: ISAKMP:(2052): sending packet to 91.10.64.182 my_port 4500 peer_port 4500 (R) MM_NO_STATE
Apr 8 08:11:28.468: ISAKMP:(2052):Sending an IKE IPv4 Packet.
Apr 8 08:11:33.404: ISAKMP:(2052):purging node 1095519141
Apr 8 08:11:33.452: ISAKMP:(2052):purging node 276028305
Apr 8 08:11:38.467: ISAKMP:(2052): retransmitting phase 2 MM_NO_STATE 316331675 ...
Apr 8 08:11:38.467: ISAKMP (2052): incrementing error counter on node, attempt 5 of 5: retransmit phase 2
Apr 8 08:11:38.467: ISAKMP (2052): incrementing error counter on sa, attempt 5 of 5: retransmit phase 2
Apr 8 08:11:38.467: ISAKMP:(2052): retransmitting phase 2 316331675 MM_NO_STATE
Apr 8 08:11:38.467: ISAKMP:(2052): sending packet to 91.10.64.182 my_port 4500 peer_port 4500 (R) MM_NO_STATE
Apr 8 08:11:38.467: ISAKMP:(2052):Sending an IKE IPv4 Packet.
Here is a packet trace from the router in front of the Cisco box:
0.041101 91.10.64.182 -> 192.168.248.11 ISAKMP Transaction (Config Mode)
0.051362 192.168.248.11 -> 91.10.64.182 ISAKMP Transaction (Config Mode)
1.514137 192.168.248.11 -> 91.10.64.182 ISAKMP Transaction (Config Mode)
11.513302 192.168.248.11 -> 91.10.64.182 ISAKMP Transaction (Config Mode)
15.049015 192.168.248.11 -> 91.10.64.182 ISAKMP Transaction (Config Mode)
16.280696 91.10.64.182 -> 192.168.248.11 ISAKMP Informational
16.286915 192.168.248.11 -> 91.10.64.182 ISAKMP Informational
16.306841 91.10.64.182 -> 192.168.248.11 ICMP Destination unreachable (Port unreachable)
21.512495 192.168.248.11 -> 91.10.64.182 ISAKMP Transaction (Config Mode)
21.611905 91.10.64.182 -> 192.168.248.11 ICMP Destination unreachable (Port unreachable)
This looks to me as if the iPad doesn't like why my router says.
To compare things, here is the same debug output from a Windows client
connecting successfully, starting with the FSM error line:
Apr 8 08:32:08.013: ISAKMP:FSM error - Message from AAA grp/user.
Apr 8 08:32:08.013: ISAKMP:(2053):Input = IKE_MESG_INTERNAL, IKE_PHASE1_COMPLETE
Apr 8 08:32:08.013: ISAKMP:(2053):Old State = IKE_P1_COMPLETE New State = IKE_P1_COMPLETE
Apr 8 08:32:08.069: ISAKMP (2053): received packet from 91.10.64.182 dport 4500 sport 1306 Global (R) QM_IDLE
Apr 8 08:32:08.069: ISAKMP: set new node -76171706 to QM_IDLE
Apr 8 08:32:08.073: ISAKMP:(2053): processing HASH payload. message ID = -76171706
Apr 8 08:32:08.073: ISAKMP:(2053): processing SA payload. message ID = -76171706
Apr 8 08:32:08.073: ISAKMP:(2053):Checking IPSec proposal 1
Apr 8 08:32:08.073: ISAKMP: transform 1, ESP_AES
Apr 8 08:32:08.073: ISAKMP: attributes in transform:
Apr 8 08:32:08.073: ISAKMP: authenticator is HMAC-MD5
Apr 8 08:32:08.073: ISAKMP: key length is 256
Apr 8 08:32:08.073: ISAKMP: encaps is 61443 (Tunnel-UDP)
Apr 8 08:32:08.073: ISAKMP: SA life type in seconds
Apr 8 08:32:08.073: ISAKMP: SA life duration (VPI) of 0x0 0x20 0xC4 0x9B
Apr 8 08:32:08.073: ISAKMP:(2053):atts are acceptable.
Apr 8 08:32:08.073: ISAKMP:(2053):Checking IPSec proposal 1
Apr 8 08:32:08.073: ISAKMP:(2053):transform 1, IPPCP LZS
Apr 8 08:32:08.073: ISAKMP: attributes in transform:
Apr 8 08:32:08.073: ISAKMP: encaps is 61443 (Tunnel-UDP)
Apr 8 08:32:08.073: ISAKMP: SA life type in seconds
Apr 8 08:32:08.073: ISAKMP: SA life duration (VPI) of 0x0 0x20 0xC4 0x9B
Apr 8 08:32:08.073: ISAKMP:(2053):atts are acceptable.
Apr 8 08:32:08.073: IPSEC(validate_proposal_request): proposal part #1
Apr 8 08:32:08.073: IPSEC(validate_proposal_request): proposal part #1,
(key eng. msg.) INBOUND local= 192.168.248.11, remote= 91.10.64.182,
local_proxy= 0.0.0.0/0.0.0.0/0/0 (type=4),
remote_proxy= 10.2.60.12/255.255.255.255/0/0 (type=1),
protocol= ESP, transform= NONE (Tunnel-UDP),
lifedur= 0s and 0kb,
spi= 0x0(0), conn_id= 0, keysize= 256, flags= 0x0
Apr 8 08:32:08.073: IPSEC(validate_proposal_request): proposal part #2
Apr 8 08:32:08.073: IPSEC(validate_proposal_request): proposal part #2,
(key eng. msg.) INBOUND local= 192.168.248.11, remote= 91.10.64.182,
local_proxy= 0.0.0.0/0.0.0.0/0/0 (type=4),
remote_proxy= 10.2.60.12/255.255.255.255/0/0 (type=1),
protocol= PCP, transform= NONE (Tunnel-UDP),
lifedur= 0s and 0kb,
spi= 0x0(0), conn_id= 0, keysize= 0, flags= 0x0
Apr 8 08:32:08.077: IPSEC(ipsec_process_proposal): transform proposal not supported for identity:
{esp-aes 256 esp-md5-hmac comp-lzs }
Apr 8 08:32:08.077: ISAKMP:(2053): IPSec policy invalidated proposal with error 256
Apr 8 08:32:08.077: ISAKMP:(2053):Checking IPSec proposal 2
Apr 8 08:32:08.077: ISAKMP: transform 1, ESP_AES
Apr 8 08:32:08.077: ISAKMP: attributes in transform:
Apr 8 08:32:08.077: ISAKMP: authenticator is HMAC-SHA
Apr 8 08:32:08.077: ISAKMP: key length is 256
Apr 8 08:32:08.077: ISAKMP: encaps is 61443 (Tunnel-UDP)
Apr 8 08:32:08.077: ISAKMP: SA life type in seconds
Apr 8 08:32:08.077: ISAKMP: SA life duration (VPI) of 0x0 0x20 0xC4 0x9B
Apr 8 08:32:08.077: ISAKMP:(2053):atts are acceptable.
Apr 8 08:32:08.077: ISAKMP:(2053):Checking IPSec proposal 2
Apr 8 08:32:08.077: ISAKMP:(2053):transform 1, IPPCP LZS
Apr 8 08:32:08.077: ISAKMP: attributes in transform:
Apr 8 08:32:08.077: ISAKMP: encaps is 61443 (Tunnel-UDP)
Apr 8 08:32:08.077: ISAKMP: SA life type in seconds
Apr 8 08:32:08.077: ISAKMP: SA life duration (VPI) of 0x0 0x20 0xC4 0x9B
Apr 8 08:32:08.077: ISAKMP:(2053):atts are acceptable.
Apr 8 08:32:08.077: IPSEC(validate_proposal_request): proposal part #1
Apr 8 08:32:08.077: IPSEC(validate_proposal_request): proposal part #1,
(key eng. msg.) INBOUND local= 192.168.248.11, remote= 91.10.64.182,
local_proxy= 0.0.0.0/0.0.0.0/0/0 (type=4),
remote_proxy= 10.2.60.12/255.255.255.255/0/0 (type=1),
protocol= ESP, transform= NONE (Tunnel-UDP),
lifedur= 0s and 0kb,
--
-----------------------------------------------------------------------------
Marc Haber | "I don't trust Computers. They | Mailadresse im Header
Mannheim, Germany | lose things." Winona Ryder | Fon: *49 621 31958061
Nordisch by Nature | How to make an American Quilt | Fax: *49 621 31958062
More information about the cisco-nsp
mailing list