cancel
Showing results for 
Search instead for 
Did you mean: 
cancel
373
Views
0
Helpful
2
Replies

Problem with VPN client 3.5.1

rshanmugam
Level 1
Level 1

Hi:

We have a VPN solution based on the securID with ACE server seems to be not working with Cisco client 3.5.1 and Cisco 2621 .The actual problem is with the authentication phase. Please find the log and debug files for the same as attached and somebody do advise me if anyone faced and solved the same problem as ours.

Thnx

Raj

VPN client log

1 22:06:08.187 04/08/02 Sev=Info/6 DIALER/0x63300006

Disconnecting connection.

2 22:06:08.203 04/08/02 Sev=Info/4 CM/0x6310000A

Secure connections terminated

3 22:06:08.203 04/08/02 Sev=Info/5 IKE/0x63000018

Deleting IPsec SA: (OUTBOUND SPI = 28A5CE19 INBOUND SPI = CB7E3DF1)

4 22:06:08.203 04/08/02 Sev=Info/4 IKE/0x63000013

SENDING >>> ISAKMP OAK INFO *(HASH, DEL) to 203.199.202.73

5 22:06:08.203 04/08/02 Sev=Info/5 IKE/0x63000018

Deleting IPsec SA: (OUTBOUND SPI = CC9F7C93 INBOUND SPI = 44C27972)

6 22:06:08.203 04/08/02 Sev=Info/4 IKE/0x63000013

SENDING >>> ISAKMP OAK INFO *(HASH, DEL) to 203.199.202.73

7 22:06:08.203 04/08/02 Sev=Info/5 IKE/0x63000017

Marking IKE SA for deletion (COOKIES = 924C7FA1CAEF88CB 54C4ACECFFF2ECAE) reason = DEL_REASON_RESET_SADB

8 22:06:08.203 04/08/02 Sev=Info/4 IKE/0x63000013

SENDING >>> ISAKMP OAK INFO *(HASH, DEL) to 203.199.202.73

9 22:06:08.203 04/08/02 Sev=Info/4 CM/0x63100013

Phase 1 SA deleted cause by DEL_REASON_RESET_SADB. 0 Phase 1 SA currently in the system

10 22:06:08.203 04/08/02 Sev=Info/5 CM/0x63100029

Initializing CVPNDrv

11 22:06:08.203 04/08/02 Sev=Info/6 CM/0x63100035

Tunnel to headend device 203.199.202.73 disconnected: duration: 0 days 0:4:7

12 22:06:08.203 04/08/02 Sev=Info/5 CM/0x63100029

Initializing CVPNDrv

13 22:06:08.671 04/08/02 Sev=Info/6 DIALER/0x63300007

Disconnected.

14 22:06:08.671 04/08/02 Sev=Info/6 DIALER/0x63300008

MAPI32 Information - Outlook not default mail client

15 22:06:08.687 04/08/02 Sev=Info/4 IPSEC/0x63700013

Delete internal key with SPI=0xf13d7ecb

16 22:06:08.687 04/08/02 Sev=Info/4 IPSEC/0x63700013

Delete internal key with SPI=0x7279c244

17 22:06:08.687 04/08/02 Sev=Info/4 IPSEC/0x63700013

Delete internal key with SPI=0x937c9fcc

18 22:06:08.687 04/08/02 Sev=Info/4 IPSEC/0x63700013

Delete internal key with SPI=0x19cea528

19 22:06:08.687 04/08/02 Sev=Info/4 IPSEC/0x63700014

Deleted all keys

20 22:06:08.687 04/08/02 Sev=Info/4 IPSEC/0x63700014

Deleted all keys

21 22:06:08.687 04/08/02 Sev=Info/4 IPSEC/0x63700014

Deleted all keys

22 22:06:08.687 04/08/02 Sev=Info/4 IPSEC/0x63700014

Deleted all keys

23 22:06:17.984 04/08/02 Sev=Info/6 DIALER/0x63300002

Initiating connection.

24 22:06:17.984 04/08/02 Sev=Info/4 CM/0x63100002

Begin connection process

25 22:06:17.984 04/08/02 Sev=Info/4 CM/0x63100004

Establish secure connection using Ethernet

26 22:06:17.984 04/08/02 Sev=Info/4 CM/0x63100026

Attempt connection with server "203.199.202.73"

27 22:06:17.984 04/08/02 Sev=Info/6 IKE/0x6300003B

Attempting to establish a connection with 203.199.202.73.

28 22:06:17.984 04/08/02 Sev=Info/4 IKE/0x63000013

SENDING >>> ISAKMP OAK AG (SA, KE, NON, ID, VID, VID, VID) to 203.199.202.73

29 22:06:18.546 04/08/02 Sev=Info/4 IPSEC/0x63700014

Deleted all keys

30 22:06:18.562 04/08/02 Sev=Info/5 IKE/0x6300002F

Received ISAKMP packet: peer = 203.199.202.73

31 22:06:18.562 04/08/02 Sev=Info/4 IKE/0x63000014

RECEIVING <<< ISAKMP OAK AG (SA, VID, VID, VID, VID, KE, ID, NON, HASH) from 203.199.202.73

32 22:06:18.562 04/08/02 Sev=Info/5 IKE/0x63000059

Vendor ID payload = 12F5F28C457168A9702D9FE274CC0100

33 22:06:18.562 04/08/02 Sev=Info/5 IKE/0x63000001

Peer is a Cisco-Unity compliant peer

34 22:06:18.562 04/08/02 Sev=Info/5 IKE/0x63000059

Vendor ID payload = AFCAD71368A1F1C96B8696FC77570100

35 22:06:18.562 04/08/02 Sev=Info/5 IKE/0x63000001

Peer supports DPD

36 22:06:18.562 04/08/02 Sev=Info/5 IKE/0x63000059

Vendor ID payload = A1030BF1FFE8EAECDA734DEBAE1DDF2C

37 22:06:18.562 04/08/02 Sev=Info/5 IKE/0x63000059

Vendor ID payload = 09002689DFD6B712

38 22:06:18.562 04/08/02 Sev=Info/4 IKE/0x63000013

SENDING >>> ISAKMP OAK AG *(HASH, NOTIFY:STATUS_INITIAL_CONTACT) to 203.199.202.73

39 22:06:18.843 04/08/02 Sev=Info/5 IKE/0x6300002F

Received ISAKMP packet: peer = 203.199.202.73

40 22:06:18.843 04/08/02 Sev=Info/4 IKE/0x63000014

RECEIVING <<< ISAKMP OAK INFO *(HASH, NOTIFY:STATUS_RESP_LIFETIME) from 203.199.202.73

41 22:06:18.843 04/08/02 Sev=Info/5 IKE/0x63000044

RESPONDER-LIFETIME notify has value of 86400 seconds

42 22:06:18.843 04/08/02 Sev=Info/5 IKE/0x63000046

This SA has already been alive for 1 seconds, setting expiry to 86399 seconds from now

43 22:06:18.875 04/08/02 Sev=Info/5 IKE/0x6300002F

Received ISAKMP packet: peer = 203.199.202.73

44 22:06:18.875 04/08/02 Sev=Info/4 IKE/0x63000014

RECEIVING <<< ISAKMP OAK TRANS *(HASH, ATTR) from 203.199.202.73

45 22:06:18.875 04/08/02 Sev=Info/4 CM/0x63100015

Launch xAuth application

46 22:06:23.859 04/08/02 Sev=Info/5 IKE/0x6300002F

Received ISAKMP packet: peer = 203.199.202.73

47 22:06:23.859 04/08/02 Sev=Info/4 IKE/0x63000014

RECEIVING <<< ISAKMP OAK TRANS *(Retransmission) from 203.199.202.73

48 22:06:28.859 04/08/02 Sev=Info/5 IKE/0x6300002F

Received ISAKMP packet: peer = 203.199.202.73

49 22:06:28.859 04/08/02 Sev=Info/4 IKE/0x63000014

RECEIVING <<< ISAKMP OAK TRANS *(Retransmission) from 203.199.202.73

50 22:06:33.859 04/08/02 Sev=Info/5 IKE/0x6300002F

Received ISAKMP packet: peer = 203.199.202.73

51 22:06:33.859 04/08/02 Sev=Info/4 IKE/0x63000014

RECEIVING <<< ISAKMP OAK TRANS *(Retransmission) from 203.199.202.73

52 22:07:09.000 04/08/02 Sev=Info/4 CM/0x63100017

xAuth application returned

53 22:07:09.000 04/08/02 Sev=Info/4 IKE/0x63000013

SENDING >>> ISAKMP OAK TRANS *(HASH, ATTR) to 203.199.202.73

54 22:07:14.046 04/08/02 Sev=Info/4 IKE/0x63000056

Phase 2 exchange timed out (message id = 0xB5106BE6). Retry count: 1

55 22:07:14.046 04/08/02 Sev=Info/4 IKE/0x63000013

SENDING >>> ISAKMP OAK TRANS *(Retransmission) to 203.199.202.73

56 22:07:19.046 04/08/02 Sev=Info/4 IKE/0x63000056

Phase 2 exchange timed out (message id = 0xB5106BE6). Retry count: 2

57 22:07:19.046 04/08/02 Sev=Info/4 IKE/0x63000013

SENDING >>> ISAKMP OAK TRANS *(Retransmission) to 203.199.202.73

58 22:07:24.046 04/08/02 Sev=Info/4 IKE/0x63000056

Phase 2 exchange timed out (message id = 0xB5106BE6). Retry count: 3

59 22:07:24.046 04/08/02 Sev=Info/4 IKE/0x63000013

SENDING >>> ISAKMP OAK TRANS *(Retransmission) to 203.199.202.73

60 22:07:29.046 04/08/02 Sev=Info/4 IKE/0x63000053

Phase-2 retransmission count exceeded, message id = 0x00000003

61 22:07:29.046 04/08/02 Sev=Info/6 IKE/0x6300003D

Sending DPD request to 203.199.202.73, seq# = 2264229020

62 22:07:29.046 04/08/02 Sev=Info/4 IKE/0x63000013

SENDING >>> ISAKMP OAK INFO *(HASH, NOTIFY:DPD_REQUEST) to 203.199.202.73

63 22:07:34.046 04/08/02 Sev=Info/6 IKE/0x6300003D

Sending DPD request to 203.199.202.73, seq# = 2264229021

64 22:07:34.046 04/08/02 Sev=Info/4 IKE/0x63000013

SENDING >>> ISAKMP OAK INFO *(HASH, NOTIFY:DPD_REQUEST) to 203.199.202.73

65 22:07:39.046 04/08/02 Sev=Info/6 IKE/0x6300003D

Sending DPD request to 203.199.202.73, seq# = 2264229022

66 22:07:39.046 04/08/02 Sev=Info/4 IKE/0x63000013

SENDING >>> ISAKMP OAK INFO *(HASH, NOTIFY:DPD_REQUEST) to 203.199.202.73

67 22:07:44.046 04/08/02 Sev=Info/6 IKE/0x6300003D

Sending DPD request to 203.199.202.73, seq# = 2264229023

68 22:07:44.046 04/08/02 Sev=Info/4 IKE/0x63000013

SENDING >>> ISAKMP OAK INFO *(HASH, NOTIFY:DPD_REQUEST) to 203.199.202.73

69 22:07:49.046 04/08/02 Sev=Info/6 IKE/0x6300003D

Sending DPD request to 203.199.202.73, seq# = 2264229024

70 22:07:49.046 04/08/02 Sev=Info/4 IKE/0x63000013

SENDING >>> ISAKMP OAK INFO *(HASH, NOTIFY:DPD_REQUEST) to 203.199.202.73

71 22:07:54.046 04/08/02 Sev=Info/6 IKE/0x6300003D

Sending DPD request to 203.199.202.73, seq# = 2264229025

72 22:07:54.046 04/08/02 Sev=Info/4 IKE/0x63000013

SENDING >>> ISAKMP OAK INFO *(HASH, NOTIFY:DPD_REQUEST) to 203.199.202.73

73 22:07:59.046 04/08/02 Sev=Info/6 IKE/0x6300003D

Sending DPD request to 203.199.202.73, seq# = 2264229026

74 22:07:59.046 04/08/02 Sev=Info/4 IKE/0x63000013

SENDING >>> ISAKMP OAK INFO *(HASH, NOTIFY:DPD_REQUEST) to 203.199.202.73

75 22:08:04.046 04/08/02 Sev=Info/6 IKE/0x6300003D

Sending DPD request to 203.199.202.73, seq# = 2264229027

76 22:08:04.046 04/08/02 Sev=Info/4 IKE/0x63000013

SENDING >>> ISAKMP OAK INFO *(HASH, NOTIFY:DPD_REQUEST) to 203.199.202.73

77 22:08:09.046 04/08/02 Sev=Info/6 IKE/0x6300003D

Sending DPD request to 203.199.202.73, seq# = 2264229028

78 22:08:09.046 04/08/02 Sev=Info/4 IKE/0x63000013

SENDING >>> ISAKMP OAK INFO *(HASH, NOTIFY:DPD_REQUEST) to 203.199.202.73

79 22:08:14.046 04/08/02 Sev=Info/6 IKE/0x6300003D

Sending DPD request to 203.199.202.73, seq# = 2264229029

80 22:08:14.046 04/08/02 Sev=Info/4 IKE/0x63000013

SENDING >>> ISAKMP OAK INFO *(HASH, NOTIFY:DPD_REQUEST) to 203.199.202.73

81 22:08:18.921 04/08/02 Sev=Info/6 DIALER/0x63300004

Canceling connection.

82 22:08:18.921 04/08/02 Sev=Info/4 CM/0x63100006

Abort connection attempt before Phase 1 SA up

83 22:08:18.921 04/08/02 Sev=Info/5 IKE/0x63000017

Marking IKE SA for deletion (COOKIES = 81B8645543FCCD80 54C4ACECFFE9EAEC) reason = DEL_REASON_RESET_SADB

84 22:08:18.921 04/08/02 Sev=Info/4 IKE/0x63000013

SENDING >>> ISAKMP OAK INFO *(HASH, DEL) to 203.199.202.73

85 22:08:18.937 04/08/02 Sev=Info/5 CM/0x63100029

Initializing CVPNDrv

86 22:08:18.984 04/08/02 Sev=Info/6 DIALER/0x63300005

Connection canceled.

87 22:08:19.937 04/08/02 Sev=Info/4 IPSEC/0x63700014

Deleted all keys

88 22:08:19.937 04/08/02 Sev=Info/4 IPSEC/0x63700014

Deleted all keys

89 22:08:19.937 04/08/02 Sev=Info/4 IPSEC/0x63700014

Deleted all keys

90 22:08:25.062 04/08/02 Sev=Info/6 DIALER/0x63300002

Initiating connection.

91 22:08:25.062 04/08/02 Sev=Info/4 CM/0x63100002

Begin connection process

92 22:08:25.062 04/08/02 Sev=Info/4 CM/0x63100004

Establish secure connection using Ethernet

93 22:08:25.062 04/08/02 Sev=Info/4 CM/0x63100026

Attempt connection with server "203.199.202.73"

94 22:08:25.062 04/08/02 Sev=Info/6 IKE/0x6300003B

Attempting to establish a connection with 203.199.202.73.

95 22:08:25.078 04/08/02 Sev=Info/4 IKE/0x63000013

SENDING >>> ISAKMP OAK AG (SA, KE, NON, ID, VID, VID, VID) to 203.199.202.73

96 22:08:25.609 04/08/02 Sev=Info/5 IKE/0x6300002F

Received ISAKMP packet: peer = 203.199.202.73

97 22:08:25.609 04/08/02 Sev=Info/4 IKE/0x63000014

RECEIVING <<< ISAKMP OAK AG (SA, VID, VID, VID, VID, KE, ID, NON, HASH) from 203.199.202.73

98 22:08:25.609 04/08/02 Sev=Info/5 IKE/0x63000059

Vendor ID payload = 12F5F28C457168A9702D9FE274CC0100

99 22:08:25.625 04/08/02 Sev=Info/5 IKE/0x63000001

Peer is a Cisco-Unity compliant peer

100 22:08:25.625 04/08/02 Sev=Info/5 IKE/0x63000059

Vendor ID payload = AFCAD71368A1F1C96B8696FC77570100

101 22:08:25.625 04/08/02 Sev=Info/5 IKE/0x63000001

Peer supports DPD

102 22:08:25.625 04/08/02 Sev=Info/5 IKE/0x63000059

Vendor ID payload = A1030BF12EBCCD41495FCC8B6F7E7306

103 22:08:25.625 04/08/02 Sev=Info/5 IKE/0x63000059

Vendor ID payload = 09002689DFD6B712

Router Debug output:

May 20 12:52:21 UTC: %CRYPTO-4-IKMP_BAD_MESSAGE: IKE message from 63.82.81.166

failed its sanity check or is malformed

May 20 12:52:27 UTC: TAC+: Opening TCP/IP to 172.23.86.105/49 timeout=5

May 20 12:52:27 UTC: TAC+: Opened TCP/IP handle 0x832E00C8 to 172.23.86.105/49

May 20 12:52:27 UTC: TAC+: periodic timer started

May 20 12:52:27 UTC: TAC+: 172.23.86.105 req=8313C8E0 Qd id=3512101476 ver=192 h

andle=0x832E00C8 (ESTAB) expire=5 AUTHEN/START/LOGIN/ASCII queued

May 20 12:52:27 UTC: TAC+: 172.23.86.105 ESTAB id=3512101476 wrote 49 of 49 byte

s

May 20 12:52:27 UTC: TAC+: 172.23.86.105 req=8313C8E0 Qd id=3512101476 ver=192 h

andle=0x832E00C8 (ESTAB) expire=4 AUTHEN/START/LOGIN/ASCII sent

May 20 12:52:27 UTC: TAC+: 172.23.86.105 ESTAB read=12 wanted=12 alloc=12 got=12

May 20 12:52:27 UTC: TAC+: 172.23.86.105 ESTAB read=34 wanted=34 alloc=34 got=22

May 20 12:52:27 UTC: TAC+: 172.23.86.105 received 34 byte reply for 8313C8E0

May 20 12:52:27 UTC: TAC+: req=8313C8E0 Tx id=3512101476 ver=192 handle=0x832E00

C8 (ESTAB) expire=4 AUTHEN/START/LOGIN/ASCII processed

May 20 12:52:27 UTC: TAC+: periodic timer stopped (queue empty)

May 20 12:52:27 UTC: TAC+: periodic timer started

May 20 12:52:27 UTC: TAC+: 172.23.86.105 req=8313C8E0 Qd id=3512101476 ver=192 h

andle=0x832E00C8 (ESTAB) expire=5 AUTHEN/CONT queued

May 20 12:52:27 UTC: TAC+: 172.23.86.105 ESTAB id=3512101476 wrote 23 of 23 byte

s

May 20 12:52:27 UTC: TAC+: 172.23.86.105 req=8313C8E0 Qd id=3512101476 ver=192 h

andle=0x832E00C8 (ESTAB) expire=4 AUTHEN/CONT sent

May 20 12:52:29 UTC: TAC+: 172.23.86.105 ESTAB read=12 wanted=12 alloc=12 got=12

May 20 12:52:29 UTC: TAC+: 172.23.86.105 ESTAB read=66 wanted=66 alloc=66 got=54

May 20 12:52:29 UTC: TAC+: 172.23.86.105 received 66 byte reply for 8313C8E0

May 20 12:52:29 UTC: TAC+: req=8313C8E0 Tx id=3512101476 ver=192 handle=0x832E00

C8 (ESTAB) expire=3 AUTHEN/CONT processed

May 20 12:52:29 UTC: TAC+: periodic timer stopped (queue empty)

May 20 12:52:29 UTC: TAC+: Closing TCP/IP 0x832E00C8 connection to 172.23.86.105

/49

May 20 12:53:26 UTC: %CRYPTO-4-IKMP_BAD_MESSAGE: IKE message from 63.82.81.166

failed its sanity check or is malformed

May 20 12:53:32 UTC: %CRYPTO-4-IKMP_NO_SA: IKE message from 203.199.231.187 has

no SA and is not an initialization offer

May 20 12:54:04 UTC: TAC+: Opening TCP/IP to 172.23.86.105/49 timeout=5

May 20 12:54:04 UTC: TAC+: Opened TCP/IP handle 0x8317B804 to 172.23.86.105/49

May 20 12:54:04 UTC: TAC+: periodic timer started

May 20 12:54:04 UTC: TAC+: 172.23.86.105 req=8313C7F0 Qd id=553051766 ver=192 ha

ndle=0x8317B804 (ESTAB) expire=5 AUTHEN/START/LOGIN/ASCII queued

May 20 12:54:04 UTC: TAC+: 172.23.86.105 ESTAB id=553051766 wrote 49 of 49 bytes

May 20 12:54:04 UTC: TAC+: 172.23.86.105 req=8313C7F0 Qd id=553051766 ver=192 ha

ndle=0x8317B804 (ESTAB) expire=4 AUTHEN/START/LOGIN/ASCII sent

May 20 12:54:05 UTC: TAC+: 172.23.86.105 ESTAB read=12 wanted=12 alloc=12 got=12

May 20 12:54:05 UTC: TAC+: 172.23.86.105 ESTAB read=34 wanted=34 alloc=34 got=22

May 20 12:54:05 UTC: TAC+: 172.23.86.105 received 34 byte reply for 8313C7F0

May 20 12:54:05 UTC: TAC+: req=8313C7F0 Tx id=553051766 ver=192 handle=0x8317B80

4 (ESTAB) expire=4 AUTHEN/START/LOGIN/ASCII processed

May 20 12:54:05 UTC: TAC+: periodic timer stopped (queue empty)

May 20 12:54:05 UTC: TAC+: periodic timer started

May 20 12:54:05 UTC: TAC+: 172.23.86.105 req=83167E3C Qd id=553051766 ver=192 ha

ndle=0x8317B804 (ESTAB) expire=5 AUTHEN/CONT queued

May 20 12:54:05 UTC: TAC+: 172.23.86.105 ESTAB id=553051766 wrote 21 of 21 bytes

May 20 12:54:05 UTC: TAC+: 172.23.86.105 req=83167E3C Qd id=553051766 ver=192 ha

ndle=0x8317B804 (ESTAB) expire=4 AUTHEN/CONT sent

May 20 12:54:06 UTC: TAC+: 172.23.86.105 ESTAB read=12 wanted=12 alloc=12 got=12

May 20 12:54:06 UTC: TAC+: 172.23.86.105 ESTAB read=18 wanted=18 alloc=18 got=6

May 20 12:54:06 UTC: TAC+: 172.23.86.105 received 18 byte reply for 83167E3C

May 20 12:54:06 UTC: TAC+: req=83167E3C Tx id=553051766 ver=192 handle=0x8317B80

4 (ESTAB) expire=3 AUTHEN/CONT processed

May 20 12:54:06 UTC: TAC+: periodic timer stopped (queue empty)

May 20 12:54:06 UTC: TAC+: Closing TCP/IP 0x8317B804 connection to 172.23.86.105

/49

2 Replies 2

david_prakken
Level 1
Level 1

Hi,

Are you using D-H group 2 in your isakmp settings? Also, I assume that if you are talking directly to the ACE server from the router, it is with RADIUS. Is the ACE/Server log showing any attempts for xauth from the router?

Dave

Dave:

We are using D-H group 2 and we do use TACACS to talk to ACE server. The ACE server log shows the attempt for xauth and it seems to be that it prompted user to set his PIN, which it doesn’t.

Raj

Getting Started

Find answers to your questions by entering keywords or phrases in the Search bar above. New here? Use these resources to familiarize yourself with the community: