08-21-2013 05:46 PM
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_COMPLETEAug 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
08-13-2015 08:17 AM
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,
Discover and save your favorite ideas. Come back to expert answers, step-by-step guides, recent topics, and more.
New here? Get started with these tips. How to use Community New member guide