asked on

PIX 501, VPN Client v5.0.3 dropping connections

This client has a PIX 501 in their central office. All users are connecting using the latest Cisco VPN Client on Windows XP. For some users, the client drops the connection after 3-15 minutes, citing "remote peer not responding." Here's the log from the client's perspective (trouble begins on line 65):

Cisco Systems VPN Client Version 5.0.03.0530
Copyright (C) 1998-2007 Cisco Systems, Inc. All Rights Reserved.
Client Type(s): Windows, WinNT
Running on: 5.1.2600 Service Pack 2
Config file directory: C:\Program Files\Cisco Systems\VPN Client\

1 16:37:32.468 10/14/08 Sev=Info/4      CM/0x63100002
Begin connection process

2 16:37:32.483 10/14/08 Sev=Info/4      CM/0x63100004
Establish secure connection

3 16:37:32.483 10/14/08 Sev=Info/4      CM/0x63100024
Attempt connection with server "66.195.200.66"

4 16:37:32.483 10/14/08 Sev=Info/6      IKE/0x6300003B
Attempting to establish a connection with 66.195.200.66.

5 16:37:32.499 10/14/08 Sev=Info/4      IKE/0x63000013
SENDING >>> ISAKMP OAK AG (SA, KE, NON, ID, VID(Xauth), VID(dpd), VID(Frag), VID(Nat-T), VID(Unity)) to 66.195.200.66

6 16:37:32.561 10/14/08 Sev=Info/4      IPSEC/0x63700008
IPSec driver successfully started

7 16:37:32.561 10/14/08 Sev=Info/4      IPSEC/0x63700014
Deleted all keys

8 16:37:32.561 10/14/08 Sev=Info/6      IPSEC/0x6370002C
Sent 6 packets, 0 were fragmented.

9 16:37:33.718 10/14/08 Sev=Info/5      IKE/0x6300002F
Received ISAKMP packet: peer = 66.195.200.66

10 16:37:33.718 10/14/08 Sev=Info/4      IKE/0x63000014
RECEIVING <<< ISAKMP OAK AG (SA, VID(Xauth), VID(dpd), VID(Unity), VID(?), KE, ID, NON, HASH) from 66.195.200.66

11 16:37:33.718 10/14/08 Sev=Info/5      IKE/0x63000001
Peer supports XAUTH

12 16:37:33.718 10/14/08 Sev=Info/5      IKE/0x63000001
Peer supports DPD

13 16:37:33.718 10/14/08 Sev=Info/5      IKE/0x63000001
Peer is a Cisco-Unity compliant peer

14 16:37:33.718 10/14/08 Sev=Info/5      IKE/0x63000082
Received IOS Vendor ID with unknown capabilities flag 0x00000025

15 16:37:33.733 10/14/08 Sev=Info/6      IKE/0x63000001
IOS Vendor ID Contruction successful

16 16:37:33.733 10/14/08 Sev=Info/4      IKE/0x63000013
SENDING >>> ISAKMP OAK AG *(HASH, NOTIFY:STATUS_INITIAL_CONTACT, VID(?), VID(Unity)) to 66.195.200.66

17 16:37:33.733 10/14/08 Sev=Info/4      IKE/0x63000083
IKE Port in use - Local Port = 0x0582, Remote Port = 0x01F4

18 16:37:33.733 10/14/08 Sev=Info/4      CM/0x6310000E
Established Phase 1 SA. 1 Crypto Active IKE SA, 0 User Authenticated IKE SA in the system

19 16:37:33.733 10/14/08 Sev=Info/4      CM/0x6310000E
Established Phase 1 SA. 1 Crypto Active IKE SA, 1 User Authenticated IKE SA in the system

20 16:37:33.749 10/14/08 Sev=Info/5      IKE/0x6300005E
Client sending a firewall request to concentrator

21 16:37:33.749 10/14/08 Sev=Info/5      IKE/0x6300005D
Firewall Policy: Product=Cisco Systems Integrated Client Firewall, Capability= (Centralized Protection Policy).

22 16:37:33.749 10/14/08 Sev=Info/4      IKE/0x63000013
SENDING >>> ISAKMP OAK TRANS *(HASH, ATTR) to 66.195.200.66

23 16:37:33.796 10/14/08 Sev=Info/5      IKE/0x6300002F
Received ISAKMP packet: peer = 66.195.200.66

24 16:37:33.796 10/14/08 Sev=Info/4      IKE/0x63000014
RECEIVING <<< ISAKMP OAK INFO *(HASH, NOTIFY:STATUS_RESP_LIFETIME) from 66.195.200.66

25 16:37:33.796 10/14/08 Sev=Info/5      IKE/0x63000045
RESPONDER-LIFETIME notify has value of 86400 seconds

26 16:37:33.796 10/14/08 Sev=Info/5      IKE/0x63000047
This SA has already been alive for 1 seconds, setting expiry to 86399 seconds from now

27 16:37:33.827 10/14/08 Sev=Info/5      IKE/0x6300002F
Received ISAKMP packet: peer = 66.195.200.66

28 16:37:33.827 10/14/08 Sev=Info/4      IKE/0x63000014
RECEIVING <<< ISAKMP OAK TRANS *(HASH, ATTR) from 66.195.200.66

29 16:37:33.827 10/14/08 Sev=Info/5      IKE/0x63000010
MODE_CFG_REPLY: Attribute = INTERNAL_IPV4_ADDRESS: , value = 192.168.1.25

30 16:37:33.827 10/14/08 Sev=Info/5      IKE/0x63000010
MODE_CFG_REPLY: Attribute = INTERNAL_IPV4_DNS(1): , value = 10.1.1.2

31 16:37:33.827 10/14/08 Sev=Info/5      IKE/0x63000010
MODE_CFG_REPLY: Attribute = INTERNAL_IPV4_NBNS(1) (a.k.a. WINS) : , value = 10.1.1.2

32 16:37:33.827 10/14/08 Sev=Info/5      IKE/0x6300000E
MODE_CFG_REPLY: Attribute = MODECFG_UNITY_DEFDOMAIN: , value = kontek.local

33 16:37:33.827 10/14/08 Sev=Info/5      IKE/0x6300000D
MODE_CFG_REPLY: Attribute = MODECFG_UNITY_SPLIT_INCLUDE (# of split_nets), value = 0x00000001

34 16:37:33.827 10/14/08 Sev=Info/5      IKE/0x6300000F
SPLIT_NET #1
      subnet = 10.1.1.0
      mask = 255.255.255.0
      protocol = 0
      src port = 0
      dest port=0

35 16:37:33.827 10/14/08 Sev=Info/5      IKE/0x6300000D
MODE_CFG_REPLY: Attribute = MODECFG_UNITY_PFS: , value = 0x00000000

36 16:37:33.827 10/14/08 Sev=Info/4      CM/0x63100019
Mode Config data received

37 16:37:33.843 10/14/08 Sev=Info/4      IKE/0x63000056
Received a key request from Driver: Local IP = 192.168.1.25, GW IP = 66.195.200.66, Remote IP = 0.0.0.0

38 16:37:33.843 10/14/08 Sev=Info/4      IKE/0x63000013
SENDING >>> ISAKMP OAK QM *(HASH, SA, NON, ID, ID) to 66.195.200.66

39 16:37:33.936 10/14/08 Sev=Info/5      IKE/0x6300002F
Received ISAKMP packet: peer = 66.195.200.66

40 16:37:33.936 10/14/08 Sev=Info/4      IKE/0x63000014
RECEIVING <<< ISAKMP OAK QM *(HASH, SA, NON, ID, ID, NOTIFY:STATUS_RESP_LIFETIME) from 66.195.200.66

41 16:37:33.936 10/14/08 Sev=Info/5      IKE/0x63000045
RESPONDER-LIFETIME notify has value of 28800 seconds

42 16:37:33.936 10/14/08 Sev=Info/5      IKE/0x63000046
RESPONDER-LIFETIME notify has value of 4608000 kb

43 16:37:33.936 10/14/08 Sev=Info/4      IKE/0x63000013
SENDING >>> ISAKMP OAK QM *(HASH) to 66.195.200.66

44 16:37:33.936 10/14/08 Sev=Info/5      IKE/0x63000059
Loading IPsec SA (MsgID=C4BF8A9C OUTBOUND SPI = 0xA363802B INBOUND SPI = 0xC041495B)

45 16:37:33.936 10/14/08 Sev=Info/5      IKE/0x63000025
Loaded OUTBOUND ESP SPI: 0xA363802B

46 16:37:33.936 10/14/08 Sev=Info/5      IKE/0x63000026
Loaded INBOUND ESP SPI: 0xC041495B

47 16:37:33.999 10/14/08 Sev=Info/5      CVPND/0x63400013
Destination Netmask Gateway Interface Metric
0.0.0.0 0.0.0.0 192.168.2.1 192.168.2.105 20
127.0.0.0 255.0.0.0 127.0.0.1 127.0.0.1 1
192.168.2.0 255.255.255.0 192.168.2.105 192.168.2.105 20
192.168.2.105 255.255.255.255 127.0.0.1 127.0.0.1 20
192.168.2.255 255.255.255.255 192.168.2.105 192.168.2.105 20
224.0.0.0 240.0.0.0 192.168.2.105 192.168.2.105 20
255.255.255.255 255.255.255.255 192.168.2.105 192.168.2.105 1
255.255.255.255 255.255.255.255 192.168.2.105 0.0.0.0 1

48 16:37:35.467 10/14/08 Sev=Info/4      CM/0x63100034
The Virtual Adapter was enabled:
      IP=192.168.1.25/255.255.255.0
      DNS=10.1.1.2,0.0.0.0
      WINS=10.1.1.2,0.0.0.0
      Domain=kontek.local
      Split DNS Names=

49 16:37:35.467 10/14/08 Sev=Info/5      CVPND/0x63400013
Destination Netmask Gateway Interface Metric
0.0.0.0 0.0.0.0 192.168.2.1 192.168.2.105 20
127.0.0.0 255.0.0.0 127.0.0.1 127.0.0.1 1
192.168.1.0 255.255.255.0 192.168.1.25 192.168.1.25 20
192.168.1.25 255.255.255.255 127.0.0.1 127.0.0.1 20
192.168.1.255 255.255.255.255 192.168.1.25 192.168.1.25 20
192.168.2.0 255.255.255.0 192.168.2.105 192.168.2.105 20
192.168.2.105 255.255.255.255 127.0.0.1 127.0.0.1 20
192.168.2.255 255.255.255.255 192.168.2.105 192.168.2.105 20
224.0.0.0 240.0.0.0 192.168.1.25 192.168.1.25 20
224.0.0.0 240.0.0.0 192.168.2.105 192.168.2.105 20
255.255.255.255 255.255.255.255 192.168.1.25 0.0.0.0 1
255.255.255.255 255.255.255.255 192.168.1.25 192.168.1.25 1
255.255.255.255 255.255.255.255 192.168.2.105 192.168.2.105 1

50 16:37:35.483 10/14/08 Sev=Info/4      CM/0x63100038
Successfully saved route changes to file.

51 16:37:35.483 10/14/08 Sev=Info/5      CVPND/0x63400013
Destination Netmask Gateway Interface Metric
0.0.0.0 0.0.0.0 192.168.2.1 192.168.2.105 20
10.1.1.0 255.255.255.0 192.168.1.25 192.168.1.25 1
66.195.200.66 255.255.255.255 192.168.2.1 192.168.2.105 1
127.0.0.0 255.0.0.0 127.0.0.1 127.0.0.1 1
192.168.1.0 255.255.255.0 192.168.1.25 192.168.1.25 20
192.168.1.25 255.255.255.255 127.0.0.1 127.0.0.1 20
192.168.1.255 255.255.255.255 192.168.1.25 192.168.1.25 20
192.168.2.0 255.255.255.0 192.168.2.105 192.168.2.105 20
192.168.2.42 255.255.255.255 192.168.2.105 192.168.2.105 1
192.168.2.105 255.255.255.255 127.0.0.1 127.0.0.1 20
192.168.2.255 255.255.255.255 192.168.2.105 192.168.2.105 20
224.0.0.0 240.0.0.0 192.168.1.25 192.168.1.25 20
224.0.0.0 240.0.0.0 192.168.2.105 192.168.2.105 20
255.255.255.255 255.255.255.255 192.168.1.25 0.0.0.0 1
255.255.255.255 255.255.255.255 192.168.1.25 192.168.1.25 1
255.255.255.255 255.255.255.255 192.168.2.105 192.168.2.105 1

52 16:37:35.483 10/14/08 Sev=Info/6      CM/0x63100036
The routing table was updated for the Virtual Adapter

53 16:37:35.545 10/14/08 Sev=Info/4      CM/0x6310001A
One secure connection established

54 16:37:35.967 10/14/08 Sev=Info/4      CM/0x6310003B
Address watch added for 192.168.2.105. Current hostname: NFI-Common-01, Current address(es): 192.168.1.25, 192.168.2.105.

55 16:37:35.967 10/14/08 Sev=Info/4      CM/0x6310003B
Address watch added for 192.168.1.25. Current hostname: NFI-Common-01, Current address(es): 192.168.1.25, 192.168.2.105.

56 16:37:35.967 10/14/08 Sev=Info/4      IPSEC/0x63700014
Deleted all keys

57 16:37:35.967 10/14/08 Sev=Info/4      IPSEC/0x63700010
Created a new key structure

58 16:37:35.967 10/14/08 Sev=Info/4      IPSEC/0x6370000F
Added key with SPI=0x2b8063a3 into key list

59 16:37:35.967 10/14/08 Sev=Info/4      IPSEC/0x63700010
Created a new key structure

60 16:37:35.967 10/14/08 Sev=Info/4      IPSEC/0x6370000F
Added key with SPI=0x5b4941c0 into key list

61 16:37:35.967 10/14/08 Sev=Info/4      IPSEC/0x6370002F
Assigned VA private interface addr 192.168.1.25

62 16:37:35.967 10/14/08 Sev=Info/4      IPSEC/0x63700037
Configure public interface: 192.168.2.105. SG: 66.195.200.66

63 16:37:35.967 10/14/08 Sev=Info/6      CM/0x63100046
Set tunnel established flag in registry to 1.

64 16:37:37.561 10/14/08 Sev=Info/4      IPSEC/0x63700019
Activate outbound key with SPI=0x2b8063a3 for inbound key with SPI=0x5b4941c0

65 16:38:09.062 10/14/08 Sev=Info/4      IKE/0x63000013
SENDING >>> ISAKMP OAK INFO *(HASH, NOTIFY:DPD_REQUEST) to 66.195.200.66

66 16:38:09.062 10/14/08 Sev=Info/6      IKE/0x6300003D
Sending DPD request to 66.195.200.66, our seq# = 1793365825

67 16:38:09.124 10/14/08 Sev=Info/5      IKE/0x6300002F
Received ISAKMP packet: peer = 66.195.200.66

68 16:38:09.124 10/14/08 Sev=Info/4      IKE/0x63000014
RECEIVING <<< ISAKMP OAK INFO *(HASH, NOTIFY:DPD_ACK) from 66.195.200.66

69 16:38:09.124 10/14/08 Sev=Info/5      IKE/0x63000040
Received DPD ACK from 66.195.200.66, seq# received = 1793365825, seq# expected = 1793365825

70 16:39:24.565 10/14/08 Sev=Info/4      IKE/0x63000013
SENDING >>> ISAKMP OAK INFO *(HASH, NOTIFY:DPD_REQUEST) to 66.195.200.66

71 16:39:24.565 10/14/08 Sev=Info/6      IKE/0x6300003D
Sending DPD request to 66.195.200.66, our seq# = 1793365826

72 16:39:29.565 10/14/08 Sev=Info/4      IKE/0x63000013
SENDING >>> ISAKMP OAK INFO *(HASH, NOTIFY:DPD_REQUEST) to 66.195.200.66

73 16:39:29.565 10/14/08 Sev=Info/6      IKE/0x6300003D
Sending DPD request to 66.195.200.66, our seq# = 1793365827

74 16:39:34.565 10/14/08 Sev=Info/4      IKE/0x63000013
SENDING >>> ISAKMP OAK INFO *(HASH, NOTIFY:DPD_REQUEST) to 66.195.200.66

75 16:39:34.565 10/14/08 Sev=Info/6      IKE/0x6300003D
Sending DPD request to 66.195.200.66, our seq# = 1793365828

76 16:39:39.565 10/14/08 Sev=Info/4      IKE/0x63000013
SENDING >>> ISAKMP OAK INFO *(HASH, NOTIFY:DPD_REQUEST) to 66.195.200.66

77 16:39:39.565 10/14/08 Sev=Info/6      IKE/0x6300003D
Sending DPD request to 66.195.200.66, our seq# = 1793365829

78 16:39:44.565 10/14/08 Sev=Info/4      IKE/0x63000013
SENDING >>> ISAKMP OAK INFO *(HASH, NOTIFY:DPD_REQUEST) to 66.195.200.66

79 16:39:44.565 10/14/08 Sev=Info/6      IKE/0x6300003D
Sending DPD request to 66.195.200.66, our seq# = 1793365830

80 16:39:49.566 10/14/08 Sev=Info/4      IKE/0x63000013
SENDING >>> ISAKMP OAK INFO *(HASH, NOTIFY:DPD_REQUEST) to 66.195.200.66

81 16:39:49.566 10/14/08 Sev=Info/6      IKE/0x6300003D
Sending DPD request to 66.195.200.66, our seq# = 1793365831

82 16:39:54.566 10/14/08 Sev=Info/4      IKE/0x63000013
SENDING >>> ISAKMP OAK INFO *(HASH, NOTIFY:DPD_REQUEST) to 66.195.200.66

83 16:39:54.566 10/14/08 Sev=Info/6      IKE/0x6300003D
Sending DPD request to 66.195.200.66, our seq# = 1793365832

84 16:39:59.566 10/14/08 Sev=Info/4      IKE/0x63000013
SENDING >>> ISAKMP OAK INFO *(HASH, NOTIFY:DPD_REQUEST) to 66.195.200.66

85 16:39:59.566 10/14/08 Sev=Info/6      IKE/0x6300003D
Sending DPD request to 66.195.200.66, our seq# = 1793365833

86 16:40:04.566 10/14/08 Sev=Info/4      IKE/0x63000013
SENDING >>> ISAKMP OAK INFO *(HASH, NOTIFY:DPD_REQUEST) to 66.195.200.66

87 16:40:04.566 10/14/08 Sev=Info/6      IKE/0x6300003D
Sending DPD request to 66.195.200.66, our seq# = 1793365834

88 16:40:09.566 10/14/08 Sev=Info/4      IKE/0x63000013
SENDING >>> ISAKMP OAK INFO *(HASH, NOTIFY:DPD_REQUEST) to 66.195.200.66

89 16:40:09.566 10/14/08 Sev=Info/6      IKE/0x6300003D
Sending DPD request to 66.195.200.66, our seq# = 1793365835

90 16:40:14.567 10/14/08 Sev=Info/4      IKE/0x63000013
SENDING >>> ISAKMP OAK INFO *(HASH, NOTIFY:DPD_REQUEST) to 66.195.200.66

91 16:40:14.567 10/14/08 Sev=Info/6      IKE/0x6300003D
Sending DPD request to 66.195.200.66, our seq# = 1793365836

92 16:40:19.567 10/14/08 Sev=Info/4      IKE/0x63000013
SENDING >>> ISAKMP OAK INFO *(HASH, NOTIFY:DPD_REQUEST) to 66.195.200.66

93 16:40:19.567 10/14/08 Sev=Info/6      IKE/0x6300003D
Sending DPD request to 66.195.200.66, our seq# = 1793365837

94 16:40:24.567 10/14/08 Sev=Info/4      IKE/0x63000013
SENDING >>> ISAKMP OAK INFO *(HASH, NOTIFY:DPD_REQUEST) to 66.195.200.66

95 16:40:24.567 10/14/08 Sev=Info/6      IKE/0x6300003D
Sending DPD request to 66.195.200.66, our seq# = 1793365838

96 16:40:29.567 10/14/08 Sev=Info/4      IKE/0x63000013
SENDING >>> ISAKMP OAK INFO *(HASH, NOTIFY:DPD_REQUEST) to 66.195.200.66

97 16:40:29.567 10/14/08 Sev=Info/6      IKE/0x6300003D
Sending DPD request to 66.195.200.66, our seq# = 1793365839

98 16:40:34.567 10/14/08 Sev=Info/4      IKE/0x63000013
SENDING >>> ISAKMP OAK INFO *(HASH, NOTIFY:DPD_REQUEST) to 66.195.200.66

99 16:40:34.567 10/14/08 Sev=Info/6      IKE/0x6300003D
Sending DPD request to 66.195.200.66, our seq# = 1793365840

100 16:40:39.567 10/14/08 Sev=Info/4      IKE/0x63000013
SENDING >>> ISAKMP OAK INFO *(HASH, NOTIFY:DPD_REQUEST) to 66.195.200.66

101 16:40:39.567 10/14/08 Sev=Info/6      IKE/0x6300003D
Sending DPD request to 66.195.200.66, our seq# = 1793365841

102 16:40:44.568 10/14/08 Sev=Info/4      IKE/0x63000013
SENDING >>> ISAKMP OAK INFO *(HASH, NOTIFY:DPD_REQUEST) to 66.195.200.66

103 16:40:44.568 10/14/08 Sev=Info/6      IKE/0x6300003D
Sending DPD request to 66.195.200.66, our seq# = 1793365842

104 16:40:49.568 10/14/08 Sev=Info/4      IKE/0x63000013
SENDING >>> ISAKMP OAK INFO *(HASH, NOTIFY:DPD_REQUEST) to 66.195.200.66

105 16:40:49.568 10/14/08 Sev=Info/6      IKE/0x6300003D
Sending DPD request to 66.195.200.66, our seq# = 1793365843

106 16:40:54.568 10/14/08 Sev=Info/4      IKE/0x63000013
SENDING >>> ISAKMP OAK INFO *(HASH, DEL) to 66.195.200.66

107 16:40:54.568 10/14/08 Sev=Info/5      IKE/0x63000018
Deleting IPsec SA: (OUTBOUND SPI = A363802B INBOUND SPI = C041495B)

108 16:40:54.568 10/14/08 Sev=Info/4      IKE/0x63000049
Discarding IPsec SA negotiation, MsgID=C4BF8A9C

109 16:40:54.568 10/14/08 Sev=Info/4      IKE/0x63000017
Marking IKE SA for deletion (I_Cookie=02B3EE6D57D262B2 R_Cookie=0B637AE9F04A14E7) reason = DEL_REASON_PEER_NOT_RESPONDING

110 16:40:54.568 10/14/08 Sev=Info/4      IKE/0x63000013
SENDING >>> ISAKMP OAK INFO *(HASH, DEL) to 66.195.200.66

111 16:40:54.568 10/14/08 Sev=Info/4      IPSEC/0x63700013
Delete internal key with SPI=0x5b4941c0

112 16:40:54.568 10/14/08 Sev=Info/4      IPSEC/0x6370000C
Key deleted by SPI 0x5b4941c0

113 16:40:54.568 10/14/08 Sev=Info/4      IPSEC/0x63700013
Delete internal key with SPI=0x2b8063a3

114 16:40:54.568 10/14/08 Sev=Info/4      IPSEC/0x6370000C
Key deleted by SPI 0x2b8063a3

115 16:40:55.115 10/14/08 Sev=Warning/2      CVPND/0xA3400018
Output size mismatch. Actual: 4, Expected: 225. (DRVIFACE:1868)

116 16:40:55.115 10/14/08 Sev=Info/4      IKE/0x6300004B
Discarding IKE SA negotiation (I_Cookie=02B3EE6D57D262B2 R_Cookie=0B637AE9F04A14E7) reason = DEL_REASON_PEER_NOT_RESPONDING

117 16:40:55.115 10/14/08 Sev=Info/4      CM/0x63100013
Phase 1 SA deleted cause by DEL_REASON_PEER_NOT_RESPONDING. 0 Crypto Active IKE SA, 0 User Authenticated IKE SA in the system

118 16:40:55.115 10/14/08 Sev=Info/5      CM/0x63100025
Initializing CVPNDrv

119 16:40:55.115 10/14/08 Sev=Info/6      CM/0x63100031
Tunnel to headend device 66.195.200.66 disconnected: duration: 0 days 0:3:20

120 16:40:55.162 10/14/08 Sev=Info/6      CM/0x63100046
Set tunnel established flag in registry to 0.

121 16:40:55.162 10/14/08 Sev=Info/4      IKE/0x63000001
IKE received signal to terminate VPN connection

122 16:40:55.271 10/14/08 Sev=Info/5      CVPND/0x63400013
Destination Netmask Gateway Interface Metric
0.0.0.0 0.0.0.0 192.168.2.1 192.168.2.105 20
10.1.1.0 255.255.255.0 192.168.1.25 192.168.1.25 1
66.195.200.66 255.255.255.255 192.168.2.1 192.168.2.105 1
127.0.0.0 255.0.0.0 127.0.0.1 127.0.0.1 1
192.168.1.0 255.255.255.0 192.168.1.25 192.168.1.25 20
192.168.1.25 255.255.255.255 127.0.0.1 127.0.0.1 20
192.168.1.255 255.255.255.255 192.168.1.25 192.168.1.25 20
192.168.2.0 255.255.255.0 192.168.2.105 192.168.2.105 20
192.168.2.42 255.255.255.255 192.168.2.105 192.168.2.105 1
192.168.2.105 255.255.255.255 127.0.0.1 127.0.0.1 20
192.168.2.255 255.255.255.255 192.168.2.105 192.168.2.105 20
224.0.0.0 240.0.0.0 192.168.1.25 192.168.1.25 20
224.0.0.0 240.0.0.0 192.168.2.105 192.168.2.105 20
255.255.255.255 255.255.255.255 192.168.1.25 0.0.0.0 1
255.255.255.255 255.255.255.255 192.168.1.25 192.168.1.25 1
255.255.255.255 255.255.255.255 192.168.2.105 192.168.2.105 1

123 16:40:55.365 10/14/08 Sev=Info/6      CM/0x63100037
The routing table was returned to original state prior to Virtual Adapter

124 16:40:57.318 10/14/08 Sev=Info/5      CVPND/0x63400013
Destination Netmask Gateway Interface Metric
0.0.0.0 0.0.0.0 192.168.2.1 192.168.2.105 20
127.0.0.0 255.0.0.0 127.0.0.1 127.0.0.1 1
192.168.2.0 255.255.255.0 192.168.2.105 192.168.2.105 20
192.168.2.105 255.255.255.255 127.0.0.1 127.0.0.1 20
192.168.2.255 255.255.255.255 192.168.2.105 192.168.2.105 20
224.0.0.0 240.0.0.0 192.168.2.105 192.168.2.105 20
255.255.255.255 255.255.255.255 192.168.2.105 192.168.2.105 1
255.255.255.255 255.255.255.255 192.168.2.105 0.0.0.0 1

125 16:40:57.318 10/14/08 Sev=Info/4      CM/0x63100035
The Virtual Adapter was disabled

126 16:40:57.318 10/14/08 Sev=Info/4      IPSEC/0x63700014
Deleted all keys

127 16:40:57.318 10/14/08 Sev=Info/4      IPSEC/0x63700014
Deleted all keys

128 16:40:57.318 10/14/08 Sev=Info/4      IPSEC/0x63700014
Deleted all keys

129 16:40:57.318 10/14/08 Sev=Info/4      IPSEC/0x6370000A
IPSec driver successfully stopped

And here's the log from the PIX's perspective (this is a different instance of the same problem, and I only caught the end of the connection):

crypto_isakmp_process_block:src:66.93.241.11, dest:66.195.200.66 spt:53628 dpt:500
ISAKMP (0): processing NOTIFY payload 36136 protocol 1
      spi 0, message ID = 2576814910
ISAMKP (0): received DPD_R_U_THERE from peer 66.93.241.11
ISAKMP (0): sending NOTIFY message 36137 protocol 1
return status is IKMP_NO_ERR_NO_TRANS
crypto_isakmp_process_block:src:66.93.241.11, dest:66.195.200.66 spt:53628 dpt:500
ISAKMP (0): processing NOTIFY payload 36136 protocol 1
      spi 0, message ID = 1570061309
ISAMKP (0): received DPD_R_U_THERE from peer 66.93.241.11
ISAKMP (0): sending NOTIFY message 36137 protocol 1
return status is IKMP_NO_ERR_NO_TRANS
hollandstreet#
crypto_isakmp_process_block:src:66.93.241.11, dest:66.195.200.66 spt:53628 dpt:500
ISAKMP (0): processing NOTIFY payload 36136 protocol 1
      spi 0, message ID = 1414104139
ISAMKP (0): received DPD_R_U_THERE from peer 66.93.241.11
ISAKMP (0): sending NOTIFY message 36137 protocol 1
return status is IKMP_NO_ERR_NO_TRANS
crypto_isakmp_process_block:src:66.93.241.11, dest:66.195.200.66 spt:53628 dpt:500
ISAKMP (0): processing NOTIFY payload 36136 protocol 1
      spi 0, message ID = 1787384261
ISAMKP (0): received DPD_R_U_THERE from peer 66.93.241.11
ISAKMP (0): sending NOTIFY message 36137 protocol 1
return status is IKMP_NO_ERR_NO_TRANS
crypto_isakmp_process_block:src:66.93.241.11, dest:66.195.200.66 spt:53628 dpt:500
ISAKMP (0): processing NOTIFY payload 36136 protocol 1
      spi 0, message ID = 730669538
ISAMKP (0): received DPD_R_U_THERE from peer 66.93.241.11
ISAKMP (0): sending NOTIFY message 36137 protocol 1
return status is IKMP_NO_ERR_NO_TRANS
crypto_isakmp_process_block:src:66.93.241.11, dest:66.195.200.66 spt:53628 dpt:500
ISAKMP (0): processing NOTIFY payload 36136 protocol 1
      spi 0, message ID = 2223670166
ISAMKP (0): received DPD_R_U_THERE from peer 66.93.241.11
ISAKMP (0): sending NOTIFY message 36137 protocol 1
return status is IKMP_NO_ERR_NO_TRANS
crypto_isakmp_process_block:src:66.93.241.11, dest:66.195.200.66 spt:53628 dpt:500
ISAKMP (0): processing NOTIFY payload 36136 protocol 1
      spi 0, message ID = 227972650
ISAMKP (0): received DPD_R_U_THERE from peer 66.93.241.11
ISAKMP (0): sending NOTIFY message 36137 protocol 1
return status is IKMP_NO_ERR_NO_TRANS
crypto_isakmp_process_block:src:66.93.241.11, dest:66.195.200.66 spt:53628 dpt:500
ISAKMP (0): processing NOTIFY payload 36136 protocol 1
      spi 0, message ID = 4247477680
ISAMKP (0): received DPD_R_U_THERE from peer 66.93.241.11
ISAKMP (0): sending NOTIFY message 36137 protocol 1
return status is IKMP_NO_ERR_NO_TRANS
crypto_isakmp_process_block:src:66.93.241.11, dest:66.195.200.66 spt:53628 dpt:500
ISAKMP (0): processing NOTIFY payload 36136 protocol 1
      spi 0, message ID = 2434263619
ISAMKP (0): received DPD_R_U_THERE from peer 66.93.241.11
ISAKMP (0): sending NOTIFY message 36137 protocol 1
return status is IKMP_NO_ERR_NO_TRANS
crypto_isakmp_process_block:src:66.93.241.11, dest:66.195.200.66 spt:53628 dpt:500
ISAKMP (0): processing NOTIFY payload 36136 protocol 1
      spi 0, message ID = 993690832
ISAMKP (0): received DPD_R_U_THERE from peer 66.93.241.11
ISAKMP (0): sending NOTIFY message 36137 protocol 1
return status is IKMP_NO_ERR_NO_TRANS
crypto_isakmp_process_block:src:66.93.241.11, dest:66.195.200.66 spt:53628 dpt:500
ISAKMP (0): processing NOTIFY payload 36136 protocol 1
      spi 0, message ID = 3033282711
ISAMKP (0): received DPD_R_U_THERE from peer 66.93.241.11
ISAKMP (0): sending NOTIFY message 36137 protocol 1
return status is IKMP_NO_ERR_NO_TRANS
crypto_isakmp_process_block:src:66.93.241.11, dest:66.195.200.66 spt:53628 dpt:500
ISAKMP (0): processing NOTIFY payload 36136 protocol 1
      spi 0, message ID = 4204971994
ISAMKP (0): received DPD_R_U_THERE from peer 66.93.241.11
ISAKMP (0): sending NOTIFY message 36137 protocol 1
return status is IKMP_NO_ERR_NO_TRANS
crypto_isakmp_process_block:src:66.93.241.11, dest:66.195.200.66 spt:53628 dpt:500
ISAKMP (0): processing NOTIFY payload 36136 protocol 1
      spi 0, message ID = 2541937388
ISAMKP (0): received DPD_R_U_THERE from peer 66.93.241.11
ISAKMP (0): sending NOTIFY message 36137 protocol 1
return status is IKMP_NO_ERR_NO_TRANS
crypto_isakmp_process_block:src:66.93.241.11, dest:66.195.200.66 spt:53628 dpt:500
ISAKMP (0): processing NOTIFY payload 36136 protocol 1
      spi 0, message ID = 1142087174
ISAMKP (0): received DPD_R_U_THERE from peer 66.93.241.11
ISAKMP (0): sending NOTIFY message 36137 protocol 1
return status is IKMP_NO_ERR_NO_TRANS
crypto_isakmp_process_block:src:66.93.241.11, dest:66.195.200.66 spt:53628 dpt:500
ISAKMP (0): processing NOTIFY payload 36136 protocol 1
      spi 0, message ID = 455293355
ISAMKP (0): received DPD_R_U_THERE from peer 66.93.241.11
ISAKMP (0): sending NOTIFY message 36137 protocol 1
return status is IKMP_NO_ERR_NO_TRANS
crypto_isakmp_process_block:src:66.93.241.11, dest:66.195.200.66 spt:53628 dpt:500
ISAKMP (0): processing NOTIFY payload 36136 protocol 1
      spi 0, message ID = 3088244210
ISAMKP (0): received DPD_R_U_THERE from peer 66.93.241.11
ISAKMP (0): sending NOTIFY message 36137 protocol 1
return status is IKMP_NO_ERR_NO_TRANS
crypto_isakmp_process_block:src:66.93.241.11, dest:66.195.200.66 spt:53628 dpt:500
ISAKMP (0): processing NOTIFY payload 36136 protocol 1
      spi 0, message ID = 3703493587
ISAMKP (0): received DPD_R_U_THERE from peer 66.93.241.11
ISAKMP (0): sending NOTIFY message 36137 protocol 1
return status is IKMP_NO_ERR_NO_TRANS
crypto_isakmp_process_block:src:66.93.241.11, dest:66.195.200.66 spt:53628 dpt:500
ISAKMP (0): processing NOTIFY payload 36136 protocol 1
      spi 0, message ID = 3052295325
ISAMKP (0): received DPD_R_U_THERE from peer 66.93.241.11
ISAKMP (0): sending NOTIFY message 36137 protocol 1
return status is IKMP_NO_ERR_NO_TRANS
crypto_isakmp_process_block:src:66.93.241.11, dest:66.195.200.66 spt:53628 dpt:500
ISAKMP (0): processing DELETE payload. message ID = 2006724249, spi size = 4IPSEC(key_engine): got a queue event...
IPSEC(key_engine_delete_sas): rec'd delete notify from ISAKMP
map_free_entry: freeing entry 3
CRYPTO(epa_release_conn): released conn 3

VPN Peer: IPSEC: Peer ip:66.93.241.11/53488 Decrementing Ref cnt to:2 Total VPN Peers:1map_free_entry: freeing entry 4
CRYPTO(epa_release_conn): released conn 4

VPN Peer: IPSEC: Peer ip:66.93.241.11/53488 Decrementing Ref cnt to:1 Total VPN Peers:1IPSEC(key_engine): got a queue event...
IPSEC(key_engine_delete_sas): rec'd delete notify from ISAKMP

return status is IKMP_NO_ERR_NO_TRANS
crypto_isakmp_process_block:src:66.93.241.11, dest:66.195.200.66 spt:53628 dpt:500
ISAKMP (0): processing DELETE payload. message ID = 4168862270, spi size = 16
ISAKMP (0): deleting SA: src 66.93.241.11, dst 66.195.200.66
return status is IKMP_NO_ERR_NO_TRANS
ISADB: reaper checking SA 0xacd93c, conn_id = 0
ISADB: reaper checking SA 0xb6f0d4, conn_id = 0 DELETE IT!

VPN Peer: ISAKMP: Peer ip:66.93.241.11/53488 Ref cnt decremented to:0 Total VPN Peers:1
VPN Peer: ISAKMP: Deleted peer: ip:66.93.241.11/53488 Total VPN peers:0IPSEC(key_engine): got a queue event...
IPSEC(key_engine_delete_sas): rec'd delete notify from ISAKMP
IPSEC(key_engine_delete_sas): delete all SAs shared with 66.93.241.11

Does anyone know why the DPD_R_U_THERE signal would be ignored/not received by the client?

Jay_Gridley

I've had this same problem myself with a client, but for me it was fixed by upgrading to a newer VPN Client version... (would be difficult for you, offcourse..)

I've been looking around for this and found that people had several ways to fix this issue.
- Upgrading to a newer version
- Opening an command prompt and have a ping -t work as a keep alive
- Setting a longer time out on the VPN connections.

You might want to try downgrading in your case, as you obviously already have the latest client.

I also read about a user who connected his laptop directly to his modem (bypassing his firewall) for testing purposes. He found that he didn't have the disconnect problem in that situation, You could try a similar test to see if the problem is with some provider(s), the software or a type of router / firewall.

Just some pointers to get you started...

JG

ASKER CERTIFIED SOLUTION

netfriendsinc

membership

This solution is only available to members.

To access this solution, you must be a member of Experts Exchange.

Start Free Trial