I've got a weird problem that TAC hasn't been able solve.
Cisco VPN Client 4.0.2.A and 4.0.3.C both fail on phase 2 rekey against a VPN3K 3015 running 4.0.1.C. The initial connection works fine -- everything negotiates as it should.
This only seems to happen across cable modem connections -- not reproducible over a dialup connection and the TAC engineer says that he can't repro it.
Any ideas?
Server log:
43357 11/17/2003 07:59:32.560 SEV=5 IKEDBG/64 RPT=1683 <external ip address>
IKE Peer included IKE fragmentation capability flags:
Main Mode: True
Aggressive Mode: False
43359 11/17/2003 07:59:40.060 SEV=4 IKE/52 RPT=1394 <external ip address>
Group [Test-Group] User [username]
User (username) authenticated.
43360 11/17/2003 07:59:40.090 SEV=5 IKE/184 RPT=1392 <external ip address>
Group [Test-Group] User [username]
Client OS: WinNT
Client Application Version: 4.0.2 (A)
43362 11/17/2003 07:59:40.150 SEV=4 AUTH/22 RPT=1767
User [username], Group [Test-Group] connected
43363 11/17/2003 07:59:40.150 SEV=4 IKE/119 RPT=1775 <external ip address>
Group [Test-Group] User [username]
PHASE 1 COMPLETED
43364 11/17/2003 07:59:40.160 SEV=5 IKE/25 RPT=1487 <external ip address>
Group [Test-Group] User [username]
Received remote Proxy Host data in ID Payload:
Address <client assigned IP address>, Protocol 0, Port 0
43367 11/17/2003 07:59:40.160 SEV=5 IKE/34 RPT=13150 <external ip address>
Group [Test-Group] User [username]
Received local IP Proxy Subnet data in ID Payload:
Address 0.0.0.0, Mask 0.0.0.0, Protocol 0, Port 0
43370 11/17/2003 07:59:40.160 SEV=5 IKE/66 RPT=14809 <external ip address>
Group [Test-Group] User [username]
IKE Remote Peer configured for SA: CVC-Test-AES256-SHA-DH2-90lifetime
43372 11/17/2003 07:59:40.300 SEV=5 IKE/75 RPT=1483 <external ip address>
Group [Test-Group] User [username]
Overriding Initiator's IPSec rekeying duration from 2147483 to 90 seconds
43374 11/17/2003 07:59:40.340 SEV=4 IKE/49 RPT=15729 <external ip address>
Group [Test-Group] User [username]
Security negotiation complete for User (username)
Responder, Inbound SPI = 0x475b80df, Outbound SPI = 0xfec43b25
43377 11/17/2003 07:59:40.340 SEV=4 IKE/120 RPT=3140 <external ip address>
Group [Test-Group] User [username]
PHASE 2 COMPLETED (msgid=67642acd)
- Connected at this point
43378 11/17/2003 08:01:05.840 SEV=4 IKE/41 RPT=2079
IKE Initiator: Rekeying Phase 2, Intf 2, IKE Peer <external ip address>
local Proxy Address 0.0.0.0, remote Proxy Address <client assigned IP address>,
SA (CVC-Test-AES256-SHA-DH2-90lifetime)
- Goes into rekeying
43381 11/17/2003 08:01:37.910 SEV=4 IKEDBG/0 RPT=24
QM FSM error (P2 struct &0x755c5ac, mess id 0x83639001)!
- Rekey fails
43382 11/17/2003 08:01:37.910 SEV=5 IKE/194 RPT=1412 <external ip address>
Group [Test-Group] User [username]
Sending IKE Delete With Reason message: No Reason Provided.
43384 11/17/2003 08:01:37.910 SEV=4 AUTH/28 RPT=1385 <external ip address>
User [username], Group [Test-Group] disconnected:
Duration: 0:01:57
Bytes xmt: 131472
Bytes rcv: 76304
Reason: Unknown
Excerpt from client log:
68 07:59:57.900 11/17/03 Sev=Info/4 CM/0x63100038
Address watch added for <client assigned ip address>. Current address(es): <client assigned ip address>, <client real ip address>, 192.168.0.1, 192.168.237.1.
69 07:59:58.371 11/17/03 Sev=Info/4 IPSEC/0x63700010
Created a new key structure
70 07:59:58.561 11/17/03 Sev=Info/4 IPSEC/0x6370000F
Added key with SPI=0xdf805b47 into key list
71 07:59:58.561 11/17/03 Sev=Info/4 IPSEC/0x63700010
Created a new key structure
72 07:59:58.561 11/17/03 Sev=Info/4 IPSEC/0x6370000F
Added key with SPI=0x253bc4fe into key list
73 07:59:58.561 11/17/03 Sev=Info/4 IPSEC/0x6370002E
Assigned VA private interface addr <client assigned ip address>
74 08:00:00.364 11/17/03 Sev=Info/4 IPSEC/0x63700019
Activate outbound key with SPI=0xdf805b47 for inbound key with SPI=0x253bc4fe
84 08:00:53.454 11/17/03 Sev=Info/4 IPSEC/0x6370000E
Key with outbound SPI=0xdf805b47 is about to expire, requesting a new one
86 08:01:11.511 11/17/03 Sev=Info/4 IPSEC/0x63700011
Key Expired SPI=0x253bc4fe
87 08:01:11.511 11/17/03 Sev=Info/4 IPSEC/0x63700013
Delete internal key with SPI=0x253bc4fe
88 08:01:11.511 11/17/03 Sev=Info/4 IPSEC/0x63700011
Key Expired SPI=0xdf805b47
89 08:01:11.511 11/17/03 Sev=Info/4 IPSEC/0x63700013
Delete internal key with SPI=0xdf805b47
90 08:01:11.511 11/17/03 Sev=Info/4 IPSEC/0x63700010
Created a new key structure
91 08:01:31.552 11/17/03 Sev=Info/4 IPSEC/0x63700011
Key Expired SPI=0x00000000
92 08:01:31.552 11/17/03 Sev=Info/4 IPSEC/0x63700013
Delete internal key with SPI=0x00000000
93 08:01:31.552 11/17/03 Sev=Info/4 IPSEC/0x63700010
Created a new key structure
95 08:01:52.595 11/17/03 Sev=Info/4 IPSEC/0x63700011
Key Expired SPI=0x00000000
96 08:01:52.595 11/17/03 Sev=Info/4 IPSEC/0x63700013
Delete internal key with SPI=0x00000000
97 08:01:52.595 11/17/03 Sev=Info/4 IPSEC/0x63700010
Created a new key structure
99 08:02:10.632 11/17/03 Sev=Info/4 IKE/0x63000013
SENDING >>> ISAKMP OAK INFO *(HASH, DEL) to <VPN3K external address>
100 08:02:10.632 11/17/03 Sev=Info/5 IKE/0x63000018
Deleting IPsec SA: (OUTBOUND SPI = 475B80DF INBOUND SPI = FEC43B25)
101 08:02:10.632 11/17/03 Sev=Info/4 IKE/0x63000048
Discarding IPsec SA negotiation, MsgID=67642ACD
102 08:02:12.636 11/17/03 Sev=Info/4 IPSEC/0x63700011
Key Expired SPI=0x00000000
103 08:02:12.636 11/17/03 Sev=Info/4 IPSEC/0x63700013
Delete internal key with SPI=0x00000000
104 08:02:12.636 11/17/03 Sev=Info/4 IPSEC/0x63700010
Created a new key structure
105 08:02:34.180 11/17/03 Sev=Info/4 IPSEC/0x63700011
Key Expired SPI=0x00000000
106 08:02:34.180 11/17/03 Sev=Info/4 IPSEC/0x63700013
Delete internal key with SPI=0x00000000
107 08:02:34.180 11/17/03 Sev=Info/4 IPSEC/0x63700010
Created a new key structure
108 08:02:55.222 11/17/03 Sev=Info/4 IPSEC/0x63700011
Key Expired SPI=0x00000000
109 08:02:55.222 11/17/03 Sev=Info/4 IPSEC/0x63700013
Delete internal key with SPI=0x00000000
110 08:02:55.222 11/17/03 Sev=Info/4 IPSEC/0x63700010
Created a new key structure
111 08:03:19.271 11/17/03 Sev=Info/4 IPSEC/0x63700011
Key Expired SPI=0x00000000
112 08:03:19.271 11/17/03 Sev=Info/4 IPSEC/0x63700013
Delete internal key with SPI=0x00000000
113 08:03:19.271 11/17/03 Sev=Info/4 IPSEC/0x63700010
Created a new key structure
114 08:03:42.318 11/17/03 Sev=Info/4 IPSEC/0x63700011
Key Expired SPI=0x00000000
115 08:03:42.318 11/17/03 Sev=Info/4 IPSEC/0x63700013
Delete internal key with SPI=0x00000000
116 08:03:42.318 11/17/03 Sev=Info/4 IPSEC/0x63700010
Created a new key structure
118 08:03:52.339 11/17/03 Sev=Info/4 CM/0x6310000A
Secure connections terminated
119 08:03:52.339 11/17/03 Sev=Info/4 IKE/0x63000001
IKE received signal to terminate VPN connection
120 08:03:52.339 11/17/03 Sev=Info/4 IKE/0x63000017
Marking IKE SA for deletion (I_Cookie=894EC82823B4BA7F R_Cookie=E5E768A8AF516A7E) reason = DEL_REASON_RESET_SADB
