Cisco IOS VPN connection with SonicWall FW issue

abu.banafa · ‎08-21-2013

Hi, I need your kind support .. I have 3 routers configured to connect to SonicWall FW. Two of these routers are establishing VPN with FW but the third is not and I got a strange debug output that I could not find similar on the net. The debug of the IOS is as follows:

**********************************************************************************************************************

sho cryp ipe sec sa

interface: Dialer0

Crypto map tag: SDM_CMAP_1, local addr 12.yyy.yyy.99

protected vrf: (none)

local ident (addr/mask/prot/port): (10.0.19.0/255.255.255.0/0/0)

remote ident (addr/mask/prot/port): (10.0.0.0/255.255.240.0/0/0)

current_peer 20.xxx.xxx.116 port 500

PERMIT, flags={origin_is_acl,ipsec_sa_request_sent}

#pkts encaps: 0, #pkts encrypt: 0, #pkts digest: 0

#pkts decaps: 0, #pkts decrypt: 0, #pkts verify: 0

#pkts compressed: 0, #pkts decompressed: 0

#pkts not compressed: 0, #pkts compr. failed: 0

#pkts not decompressed: 0, #pkts decompress failed: 0

#send errors 54, #recv errors 0

local crypto endpt.: 12.yyy.yyy.99, remote crypto endpt.: 20.xxx.xxx.116

path mtu 1500, ip mtu 1500, ip mtu idb Dialer0

current outbound spi: 0x0(0)

PFS (Y/N): N, DH group: none

inbound esp sas:

inbound ah sas:

--More--

Aug 20 22:59:14.783: %CRYPTO-6-IKMP_BAD_DOI_NOTIFY: DOI of 0 in notify message from 20.xxx.xxx.116

Aug 20 22:59:28.031: %CRYPTO-6-IKMP_NOT_ENCRYPTED: IKE packet from 20.xxx.xxx.116 was not encrypted and it should've been.

inbound pcp sas:

--More--

outbound esp sas:

--More--

Router#\ deb i cryp ipse

Crypto IPSEC debugging is on

Router#

Aug 20 23:00:14.951: %CRYPTO-6-IKMP_BAD_DOI_NOTIFY: DOI of 0 in notify message from 20.xxx.xxx.116

Router#debu

Aug 20 23:00:21.779: IPSEC(key_engine): request timer fired: count = 1,

(identity) local= 12.yyy.yyy.99:0, remote= 20.xxx.xxx.1160,

local_proxy= 10.0.19.0/255.255.255.0/0/0 (type=4),

remote_proxy= 10.208.0.0/255.255.240.0/0/0 (type=4)

Aug 20 23:00:21.779: IPSEC(sa_request): ,

(key eng. msg.) OUTBOUND local= 12.yyy.yyy.99:500, remote= 20.xxx.xxx.116500,

local_proxy= 10.0.19.0/255.255.255.0/0/0 (type=4),

remote_proxy= 10.208.0.0/255.255.240.0/0/0 (type=4),

protocol= crypESP, transform= esp-3des esp-md5-hmac (Tunnel),

lifedur= 3600s and 4608000kb,

spi= 0x0(0), conn_id= 0, keysize= 0, flags= 0x0 isa

Crypto ISAKMP debugging is on

Router#

Aug 20 23:00:31.291: ISAKMP:(1019):purging SA., sa=293C81C8, delme=293C81C8

Aug 20 23:00:31.295: ISAKMP:(1020):purging SA., sa=293C8BE4, delme=293C8BE4

Aug 20 23:00:31.911: ISAKMP:(1026): retransmitting phase 1 MM_KEY_EXCH...

Aug 20 23:00:31.911: ISAKMP (1026): incrementing error counter on sa, attempt 1 of 5: retransmit phase 1

Aug 20 23:00:31.911: ISAKMP:(1026): retransmitting phase 1 MM_KEY_EXCH

Aug 20 23:00:31.911: ISAKMP:(1026): sending packet to 20.xxx.xxx.116 my_port 500 peer_port 500 (I) MM_KEY_EXCH

Aug 20 23:00:31.911: ISAKMP:(1026):Sending an IKE IPv4 Packet.

Aug 20 23:00:31.999: ISAKMP (1026): received packet from 20.xxx.xxx.116 dport 500 sport 500 Global (I) MM_KEY_EXCH

Aug 20 23:00:31.999: %CRYPTO-6-IKMP_NOT_ENCRYPTED: IKE packet from 20.xxx.xxx.116 was not encrypted and it should've been.

Aug 20 23:00:32.827: ISAKMP:(1021):purging node 446349765

Aug 20 23:00:34.791: ISAKMP (0): received packet from 20.xxx.xxx.116 dport 500 sport 500 Global (N) NEW SA

Aug 20 23:00:34.791: ISAKMP: Created a peer struct for 20.xxx.xxx.116, peer port 500

Aug 20 23:00:34.791: ISAKMP: New peer created peer = 0x317EF178 peer_handle = 0x8000001D

Aug 20 23:00:34.791: ISAKMP: Locking peer struct 0x317EF178, refcount 1 for crypto_isakmp_process_block

Aug 20 23:00:34.791: ISAKMP: local port 500, remote port 500

Aug 20 23:00:34.791: ISAKMP: Find a dup sa in the avl tree during calling isadb_insert sa = 293BAC84

Aug 20 23:00:34.791: ISAKMP:(0):Input = IKE_MESG_FROM_PEER, IKE_MM_EXCH

Aug 20 23:00:34.791: ISAKMP:(0):Old State = IKE_READY New State = IKE_R_MM1

Aug 20 23:00:34.791: ISAKMP:(0): processing SA payload. message ID = 0

Aug 20 23:00:34.791: ISAKMP:(0): processing vendor id payload

Aug 20 23:00:34.791: ISAKMP:(0): vendor ID seems Unity/DPD but major 28 mismatch

Aug 20 23:00:34.791: ISAKMP:(0): processing vendor id payload

Aug 20 23:00:34.791: ISAKMP:(0): vendor ID seems Unity/DPD but major 69 mismatch

Aug 20 23:00:34.791: ISAKMP (0): vendor ID is NAT-T RFC 3947

Aug 20 23:00:34.791: ISAKMP:(0): processing vendor id payload

Aug 20 23:00:34.791: ISAKMP:(0): vendor ID seems Unity/DPD but major 157 mismatch

Aug 20 23:00:34.791: ISAKMP:(0): vendor ID is NAT-T v3

Aug 20 23:00:34.791: ISAKMP:(0): processing vendor id payload

Aug 20 23:00:34.791: ISAKMP:(0): vendor ID seems Unity/DPD but major 221 mismatch

Aug 20 23:00:34.791: ISAKMP:(0):found peer pre-shared key matching 20.xxx.xxx.116

Aug 20 23:00:34.791: ISAKMP:(0): local preshared key found

Aug 20 23:00:34.791: ISAKMP : Scanning profiles for xauth ...

Aug 20 23:00:34.791: ISAKMP:(0):Checking ISAKMP transform 1 against priority 1 policy

Aug 20 23:00:34.791: ISAKMP: encryption 3DES-CBC

Aug 20 23:00:34.791: ISAKMP: hash MD5

Aug 20 23:00:34.791: ISAKMP: default group 1

Aug 20 23:00:34.791: ISAKMP: auth pre-share

Aug 20 23:00:34.791: ISAKMP: life type in seconds

Aug 20 23:00:34.791: ISAKMP: life duration (basic) of 28800

Aug 20 23:00:34.791: ISAKMP:(0):atts are acceptable. Next payload is 0

Aug 20 23:00:34.791: ISAKMP:(0):Acceptable atts:actual life: 0

Aug 20 23:00:34.791: ISAKMP:(0):Acceptable atts:life: 0

Aug 20 23:00:34.791: ISAKMP:(0):Basic life_in_seconds:28800

Aug 20 23:00:34.791: ISAKMP:(0):Returning Actual lifetime: 28800

Aug 20 23:00:34.791: ISAKMP:(0)::Started lifetime timer: 28800.

Aug 20 23:00:34.791: ISAKMP:(0): processing vendor id payload

Aug 20 23:00:34.791: ISAKMP:(0): vendor ID seems Unity/DPD but major 28 mismatch

Aug 20 23:00:34.791: ISAKMP:(0): processing vendor id payload

Aug 20 23:00:34.791: ISAKMP:(0): vendor ID seems Unity/DPD but major 69 mismatch

Aug 20 23:00:34.791: ISAKMP (0): vendor ID is NAT-T RFC 3947

Aug 20 23:00:34.791: ISAKMP:(0): processing vendor id payload

Aug 20 23:00:34.791: ISAKMP:(0): vendor ID seems Unity/DPD but major 157 mismatch

Aug 20 23:00:34.791: ISAKMP:(0): vendor ID is NAT-T v3

Aug 20 23:00:34.791: ISAKMP:(0): processing vendor id payload

Aug 20 23:00:34.791: ISAKMP:(0): vendor ID seems Unity/DPD but major 221 mismatch

Aug 20 23:00:34.791: ISAKMP:(0):Input = IKE_MESG_INTERNAL, IKE_PROCESS_MAIN_MODE

Aug 20 23:00:34.791: ISAKMP:(0):Old State = IKE_R_MM1 New State = IKE_R_MM1

Aug 20 23:00:34.795: ISAKMP:(0): constructed NAT-T vendor-rfc3947 ID

Aug 20 23:00:34.795: ISAKMP:(0): sending packet to 20.xxx.xxx.116 my_port 500 peer_port 500 (R) MM_SA_SETUP

Aug 20 23:00:34.795: ISAKMP:(0):Sending an IKE IPv4 Packet.

Aug 20 23:00:34.795: ISAKMP:(0):Input = IKE_MESG_INTERNAL, IKE_PROCESS_COMPLETE

Aug 20 23:00:34.795: ISAKMP:(0):Old State = IKE_R_MM1 New State = IKE_R_MM2

Aug 20 23:00:34.851: ISAKMP (0): received packet from 20.xxx.xxx.116 dport 500 sport 500 Global (R) MM_SA_SETUP

Aug 20 23:00:34.851: ISAKMP:(0):Input = IKE_MESG_FROM_PEER, IKE_MM_EXCH

Aug 20 23:00:34.851: ISAKMP:(0):Old State = IKE_R_MM2 New State = IKE_R_MM3

Aug 20 23:00:34.851: ISAKMP:(0): processing KE payload. message ID = 0

Aug 20 23:00:34.867: ISAKMP:received payload type 20

Aug 20 23:00:34.867: ISAKMP (0): His hash no match - this node outside NAT

Aug 20 23:00:34.867: ISAKMP:received payload type 20

Aug 20 23:00:34.867: ISAKMP (0): No NAT Found for self or peer

Aug 20 23:00:34.867: ISAKMP:(0): processing NONCE payload. message ID = 0

Aug 20 23:00:34.867: ISAKMP:(0):found peer pre-shared key matching 20.xxx.xxx.116

Aug 20 23:00:34.867: ISAKMP:(1027): processing vendor id payload

Aug 20 23:00:34.867: ISAKMP:(1027): vendor ID seems Unity/DPD but major 38 mismatch

Aug 20 23:00:34.867: ISAKMP:(1027): processing vendor id payload

Aug 20 23:00:34.867: ISAKMP:(1027): vendor ID seems Unity/DPD but major 147 mismatch

Aug 20 23:00:34.867: ISAKMP:(1027): vendor ID is XAUTH

Aug 20 23:00:34.867: ISAKMP:(1027): processing vendor id payload

Aug 20 23:00:34.867: ISAKMP:(1027): vendor ID seems Unity/DPD but major 215 mismatch

Aug 20 23:00:34.867: ISAKMP:(1027): processing vendor id payload

Aug 20 23:00:34.867: ISAKMP:(1027): vendor ID is DPD

Aug 20 23:00:34.867: ISAKMP:(1027):Input = IKE_MESG_INTERNAL, IKE_PROCESS_MAIN_MODE

Aug 20 23:00:34.867: ISAKMP:(1027):Old State = IKE_R_MM3 New State = IKE_R_MM3

Aug 20 23:00:34.867: ISAKMP:(1027): sending packet to 20.xxx.xxx.116 my_port 500 peer_port 500 (R) MM_KEY_EXCH

Aug 20 23:00:34.867: ISAKMP:(1027):Sending an IKE IPv4 Packet.

Aug 20 23:00:34.867: ISAKMP:(1027):Input = IKE_MESG_INTERNAL, IKE_PROCESS_COMPLETE

Aug 20 23:00:34.867: ISAKMP:(1027):Old State = IKE_R_MM3 New State = IKE_R_MM4

Aug 20 23:00:34.891: ISAKMP (1027): received packet from 20.xxx.xxx.116 dport 500 sport 500 Global (R) MM_KEY_EXCH

Aug 20 23:00:34.891: ISAKMP:(1027):Input = IKE_MESG_FROM_PEER, IKE_MM_EXCH

Aug 20 23:00:34.891: ISAKMP:(1027):Old State = IKE_R_MM4 New State = IKE_R_MM5

Aug 20 23:00:34.891: ISAKMP:(1027): processing ID payload. message ID = 0

Aug 20 23:00:34.891: ISAKMP (1027): ID payload

next-payload : 8

type : 1

address : 20.xxx.xxx.116

protocol : 0

port : 0

length : 12

Aug 20 23:00:34.891: ISAKMP:(0):: peer matches *none* of the profiles

Aug 20 23:00:34.891: ISAKMP:(1027): processing HASH payload. message ID = 0

Aug 20 23:00:34.891: ISAKMP:(1027): processing NOTIFY INITIAL_CONTACT protocol 1

spi 0, message ID = 0, sa = 0x293BAC84

Aug 20 23:00:34.891: ISAKMP:(1027):SA authentication status:

authenticated

Aug 20 23:00:34.891: ISAKMP:(1027):SA has been authenticated with 20.xxx.xxx.116

Aug 20 23:00:34.891: ISAKMP:(1027):SA authentication status:

authenticated

Aug 20 23:00:34.891: ISAKMP:(1027): Process initial contact,

bring down existing phase 1 and 2 SA's with local 12.yyy.yyy.99 remote 20.xxx.xxx.116 remote port 500

Aug 20 23:00:34.891: ISAKMP:(1026):received initial contact, deleting SA

Aug 20 23:00:34.891: ISAKMP:(1026):peer does not do paranoid keepalives.

Aug 20 23:00:34.891: ISAKMP:(1026):deleting SA reason "Receive initial contact" state (I) MM_KEY_EXCH (peer 20.xxx.xxx.116)

Aug 20 23:00:34.891: ISAKMP: Trying to insert a peer 12.yyy.yyy.99/20.xxx.xxx.116/500/, and inserted successfully 317EF178.

Aug 20 23:00:34.891: ISAKMP:(1027):Input = IKE_MESG_INTERNAL, IKE_PROCESS_MAIN_MODE

Aug 20 23:00:34.891: ISAKMP:(1027):Old State = IKE_R_MM5 New State = IKE_R_MM5

Aug 20 23:00:34.891: IPSEC(key_engine): got a queue event with 1 KMI message(s)

Aug 20 23:00:34.891: ISAKMP:(1026):deleting SA reason "Receive initial contact" state (I) MM_KEY_EXCH (peer 20.xxx.xxx.116)

Aug 20 23:00:34.891: ISAKMP: Unlocking peer struct 0x29616CF0 for isadb_mark_sa_deleted(), count 0

Aug 20 23:00:34.891: ISAKMP: Deleting peer node by peer_reap for 20.xxx.xxx.116 29616CF0

Aug 20 23:00:34.891: ISAKMP:(1026):deleting node 1740016761 error FALSE reason "IKE deleted"

Aug 20 23:00:34.891: ISAKMP:(1026):deleting node 637678929 error FALSE reason "IKE deleted"

Aug 20 23:00:34.891: ISAKMP:(1026):Input = IKE_MESG_INTERNAL, IKE_PHASE1_DEL

Aug 20 23:00:34.891: ISAKMP:(1026):Old State = IKE_I_MM5 New State = IKE_DEST_SA

Aug 20 23:00:34.891: IPSEC(key_engine): got a queue event with 1 KMI message(s)

Aug 20 23:00:34.891: ISAKMP:(1027):SA is doing pre-shared key authentication using id type ID_IPV4_ADDR

Aug 20 23:00:34.891: ISAKMP (1027): ID payload

next-payload : 8

type : 1

address : 12.yyy.yyy.99

protocol : 17

port : 500

length : 12

Aug 20 23:00:34.891: ISAKMP:(1027):Total payload length: 12

Aug 20 23:00:34.891: ISAKMP:(1027): sending packet to 20.xxx.xxx.116 my_port 500 peer_port 500 (R) MM_KEY_EXCH

Aug 20 23:00:34.891: ISAKMP:(1027):Sending an IKE IPv4 Packet.

Aug 20 23:00:34.891: ISAKMP:(1027):Input = IKE_MESG_INTERNAL, IKE_PROCESS_COMPLETE

Aug 20 23:00:34.891: ISAKMP:(1027):Old State = IKE_R_MM5 New State = IKE_P1_COMPLETE

Aug 20 23:00:34.891: ISAKMP:(1027):Input = IKE_MESG_INTERNAL, IKE_PHASE1_COMPLETE

Aug 20 23:00:34.891: ISAKMP:(1027):Old State =

IKE_P1_COMPLETE New State = IKE_P1_COMPLETE

Aug 20 23:00:34.907: ISAKMP (1027): received packet from 20.xxx.xxx.116 dport 500 sport 500 Global (R) QM_IDLE

Aug 20 23:00:34.907: ISAKMP: set new node 33794445 to QM_IDLE

Aug 20 23:00:34.907: ISAKMP:(1027): processing HASH payload. message ID = 33794445

Aug 20 23:00:34.907: ISAKMP (1027): incrementing error counter on sa, attempt 1 of 5: IKMP_BAD_DOI_NOTIFY

Aug 20 23:00:34.907: ISAKMP:(1027): processing NOTIFY INVALID_ID_INFO protocol 1

spi 0, message ID = 33794445, sa = 0x293BAC84

Aug 20 23:00:34.907: ISAKMP:(1027):peer does not do paranoid keepalives.

Aug 20 23:00:34.907: ISAKMP:(1027):deleting SA reason "Recevied fatal informational" state (R) QM_IDLE (peer 20.xxx.xxx.116)

Aug 20 23:00:34.907: ISAKMP:(1027):deleting node 33794445 error FALSE reason "Informational (in) state 1"

Aug 20 23:00:34.907: ISAKMP:(1027):Input = IKE_MESG_FROM_PEER, IKE_INFO_NOTIFY

Aug 20 23:00:34.907: ISAKMP:(1027):Old State = IKE_P1_COMPLETE New State = IKE_P1_COMPLETE

Aug 20 23:00:34.907: ISAKMP: set new node 1441229695 to QM_IDLE

Aug 20 23:00:34.907: ISAKMP:(1027): sending packet to 20.xxx.xxx.116 my_port 500 peer_port 500 (R) QM_IDLE

Aug 20 23:00:34.907: ISAKMP:(1027):Sending an IKE IPv4 Packet.

Aug 20 23:00:34.907: ISAKMP:(1027):purging node 1441229695

Aug 20 23:00:34.907: ISAKMP:(1027):Input = IKE_MESG_INTERNAL, IKE_PHASE1_DEL

Aug 20 23:00:34.907: ISAKMP:(1027):Old State = IKE_P1_COMPLETE New State = IKE_DEST_SA

Aug 20 23:00:34.907: ISAKMP:(1027):deleting SA reason "Recevied fatal informational" state (R) QM_IDLE (peer 20.xxx.xxx.116)

Aug 20 23:00:34.907: ISAKMP: Unlocking peeror isadb_mark_sa_deleted(), count 0

Aug 20 23:00:54.163: ISAKMP: Deleting peer node by peer_reap for 20.xxx.xxx.116 293C4D28

Aug 20 23:00:54.163: ISAKMP:(1029):Input = IKE_MESG_FROM_PEER, IKE_MM_EXCH

Aug 20 23:00:54.163: ISAKMP:(1029):Old State = IKE_DEST_SA New State = IKE_DEST_SA

Aug 20 23:00:54.163: IPSEC(key_engine): got a queue event with 1 KMI message(s)

Aug 20 23:00:54.191: ISAKMP (1029): received packet from 20.xxx.xxx.116 dport 500 sport 500 Global (R) MM_NO_STATE

Aug 20 23:01:04.899: ISAKMP:(1024):purging node -711373466

Aug 20 23:01:04.899: ISAKMP:(1024):purging node 1545272828

Aug 20 23:01:04.951: ISAKMP:(1025):purging node 1907499187

Aug 20 23:01:08.843: IPSEC(key_engine): request timer fired: count = 2,

(identity) local= 12.yyy.yyy.99:0, remote= 20.xxx.xxx.1160,

local_proxy= 10.0.19.0/255.255.255.0/0/0 (type=4),

remote_proxy= 10.0.0.0/255.255.240.0/0/0 (type=4)

Aug 20 23:01:14.739: ISAKMP (0): received packet from 20.xxx.xxx.116 dport 500 sport 500 Global (N) NEW SA

Aug 20 23:01:14.739: ISAKMP: Created a peer struct for 20.xxx.xxx.116, peer port 500

Aug 20 23:01:14.739: ISAKMP: New peer created peer = 0x317EEA38 peer_handle = 0x80000020

Aug 20 23:01:14.739: ISAKMP: Locking peer struct 0x317EEA38, refcount 1 for crypto_isakmp_process_block

Aug 20 23:01:14.739: ISAKMP: local port 500, remote port 500

Aug 20 23:01:14.739: ISAKMP: Find a dup sa in the avl tree during calling isadb_insert sa = 293C7DE4

Aug 20 23:01:14.743: ISAKMP:(0):Input = IKE_MESG_FROM_PEER, IKE_MM_EXCH

Aug 20 23:01:14.743: ISAKMP:(0):Old State = IKE_READY New State = IKE_R_MM1

***********************************************************************************************************************************

Thank you,

Ab

Carlos Alberto Blas Gonza · ‎08-13-2015

I have this problem too. Did you resolve it? Please let me know how you do. I found that the problem is on phase 1. Tried to configure the keepalive (some blog said that this is the problem) but I didn't have success.

Regards,