Troubleshooting Cisco IPSec Site to Site VPN - "IPSec policy invalidated proposal with error 32" - 91Sec

Latest

91Sec

Learning, Sharing, Creating

Wednesday, April 27, 2016

Troubleshooting Cisco IPSec Site to Site VPN - "IPSec policy invalidated proposal with error 32"

There was vpn set up recently using Cisco Router to connect Check Point firewall. It seems quite simple task but "IPSec policy invalidated proposal with error 32" made me go through all troubleshooting steps which shows below.

Other examples to troubleshoot IPSec VPN issue:


Topology is quite simple:



Remote Site is using Check Point Firewall do to vpn gateway, and it has been used to all kinds of vpn connection.

Here is my original vpn configuration.

interface GigabitEthernet0/0
 ip address 19.24.11.142 255.255.255.0
 duplex auto
 speed auto
 crypto map vpn


crypto isakmp policy 1
 encr 3des
 authentication pre-share
 group 2
 lifetime 3600
crypto isakmp key cisco123 address 19.9.17.1
crypto isakmp aggressive-mode disable
!
!
crypto ipsec transform-set VPN-Set ah-sha-hmac esp-3des
!
crypto map vpn 10 ipsec-isakmp
 description VPN VPN
 set peer 198.96.178.1
 set transform-set VPN-Set
 set pfs group2
 match address VPN-VPN

 ip access-list extended VPN-VPN
 permit ip host 19.24.11.53 host 19.9.17.41
 permit ip host 19.24.11.245 host 19.9.17.41

Check Point Firewall is at remote and I am not managing. From the collected information, here is Check Point configuration looks like:
  • Center gateways: the object representing the Check Point enforcement point
  • Satellite gateways: the object representing the Cisco router - CiscoVPN
  • Encryption:
    • Encryption Method: IKEv1 Only
    • Encryption Suite: Custom with the following properties
    • IKE (Phase 1) Properties
    • Perform key exchange encryption with: 3Des
    • Perform data integrity with: SHA-1
    • IPSec (Phase 2) Properties
    • Perform IPSec data encryption with: 3Des
    • Perform data integrity with: SHA-1
  • Tunnel Management: VPN Tunnel sharing: One VPN tunnel per subnet pair
  • Advanced settings
    • VPN Routing: To center only
    • Shared Secret: Use only Shared Secret for all external members, then add the shared secret to CiscoVPN
    • Advanced VPN Properties:IKE (Phase 1): Use Diffie-Helman Group: Group 2


Looks like quite straighforward and it should not has any surprise.

Unfortunately the tunnel did not come up as expected. I got following debugging messages:
000421: Apr 26 21:40:20.568 EDT: ISAKMP (0): received packet from 19.9.17.1 dport 500 sport 500 Global (N) NEW SA
000422: Apr 26 21:40:20.568 EDT: ISAKMP: Created a peer struct for 19.9.17.1, peer port 500
000423: Apr 26 21:40:20.568 EDT: ISAKMP: New peer created peer = 0x2B149B28 peer_handle = 0x8000000D
000424: Apr 26 21:40:20.568 EDT: ISAKMP: Locking peer struct 0x2B149B28, refcount 1 for crypto_isakmp_process_block
000425: Apr 26 21:40:20.568 EDT: ISAKMP: local port 500, remote port 500
000426: Apr 26 21:40:20.568 EDT: ISAKMP:(0):insert sa successfully sa = 2A25BEAC
000427: Apr 26 21:40:20.568 EDT: ISAKMP:(0):Input = IKE_MESG_FROM_PEER, IKE_MM_EXCH
000428: Apr 26 21:40:20.568 EDT: ISAKMP:(0):Old State = IKE_READY  New State = IKE_R_MM1

000429: Apr 26 21:40:20.568 EDT: ISAKMP:(0): processing SA payload. message ID = 0
000430: Apr 26 21:40:20.568 EDT: ISAKMP:(0): processing vendor id payload
000431: Apr 26 21:40:20.568 EDT: ISAKMP:(0): vendor ID seems Unity/DPD but major 175 mismatch
000432: Apr 26 21:40:20.568 EDT: ISAKMP:(0): processing vendor id payload
000433: Apr 26 21:40:20.568 EDT: ISAKMP:(0): vendor ID seems Unity/DPD but major 194 mismatch
000434: Apr 26 21:40:20.568 EDT: ISAKMP:(0):found peer pre-shared key matching 19.9.17.1
000435: Apr 26 21:40:20.568 EDT: ISAKMP:(0): local preshared key found
000436: Apr 26 21:40:20.568 EDT: ISAKMP : Scanning profiles for xauth ...
000437: Apr 26 21:40:20.568 EDT: ISAKMP:(0):Checking ISAKMP transform 1 against priority 1 policy
000438: Apr 26 21:40:20.568 EDT: ISAKMP:      encryption 3DES-CBC
000439: Apr 26 21:40:20.568 EDT: ISAKMP:      hash SHA
000440: Apr 26 21:40:20.568 EDT: ISAKMP:      auth pre-share
000441: Apr 26 21:40:20.568 EDT: ISAKMP:      default group 2
000442: Apr 26 21:40:20.568 EDT: ISAKMP:      life type in seconds
000443: Apr 26 21:40:20.568 EDT: ISAKMP:      life duration (VPI) of  0x0 0x0 0xE 0x10
000444: Apr 26 21:40:20.568 EDT: ISAKMP:(0):atts are acceptable. Next payload is 0
000445: Apr 26 21:40:20.568 EDT: ISAKMP:(0):Acceptable atts:actual life: 0
000446: Apr 26 21:40:20.568 EDT: ISAKMP:(0):Acceptable atts:life: 0
000447: Apr 26 21:40:20.568 EDT: ISAKMP:(0):Fill atts in sa vpi_length:4
000448: Apr 26 21:40:20.568 EDT: ISAKMP:(0):Fill atts in sa life_in_seconds:3600
000449: Apr 26 21:40:20.568 EDT: ISAKMP:(0):Returning Actual lifetime: 3600
000450: Apr 26 21:40:20.568 EDT: ISAKMP:(0)::Started lifetime timer: 3600.

000451: Apr 26 21:40:20.588 EDT: ISAKMP:(0): processing vendor id payload
000452: Apr 26 21:40:20.588 EDT: ISAKMP:(0): vendor ID seems Unity/DPD but major 175 mismatch
000453: Apr 26 21:40:20.588 EDT: ISAKMP:(0): processing vendor id payload
000454: Apr 26 21:40:20.588 EDT: ISAKMP:(0): vendor ID seems Unity/DPD but major 194 mismatch
000455: Apr 26 21:40:20.588 EDT: ISAKMP:(0):Input = IKE_MESG_INTERNAL, IKE_PROCESS_MAIN_MODE
000456: Apr 26 21:40:20.588 EDT: ISAKMP:(0):Old State = IKE_R_MM1  New State = IKE_R_MM1

000457: Apr 26 21:40:20.588 EDT: ISAKMP:(0): sending packet to 19.9.17.1 my_port 500 peer_port 500 (R) MM_SA_SETUP
000458: Apr 26 21:40:20.588 EDT: ISAKMP:(0):Sending an IKE IPv4 Packet.
000459: Apr 26 21:40:20.588 EDT: ISAKMP:(0):Input = IKE_MESG_INTERNAL, IKE_PROCESS_COMPLETE
000460: Apr 26 21:40:20.588 EDT: ISAKMP:(0):Old State = IKE_R_MM1  New State = IKE_R_MM2

000461: Apr 26 21:40:20.616 EDT: ISAKMP (0): received packet from 19.9.17.1 dport 500 sport 500 Global (R) MM_SA_SETUP
000462: Apr 26 21:40:20.616 EDT: ISAKMP:(0):Input = IKE_MESG_FROM_PEER, IKE_MM_EXCH
000463: Apr 26 21:40:20.616 EDT: ISAKMP:(0):Old State = IKE_R_MM2  New State = IKE_R_MM3

000464: Apr 26 21:40:20.620 EDT: ISAKMP:(0): processing KE payload. message ID = 0
000465: Apr 26 21:40:20.644 EDT: ISAKMP:(0): processing NONCE payload. message ID = 0
000466: Apr 26 21:40:20.644 EDT: ISAKMP:(0):found peer pre-shared key matching 19.9.17.1
000467: Apr 26 21:40:20.644 EDT: ISAKMP:(1006):Input = IKE_MESG_INTERNAL, IKE_PROCESS_MAIN_MODE
000468: Apr 26 21:40:20.644 EDT: ISAKMP:(1006):Old State = IKE_R_MM3  New State = IKE_R_MM3

000469: Apr 26 21:40:20.644 EDT: ISAKMP:(1006): sending packet to 19.9.17.1 my_port 500 peer_port 500 (R) MM_KEY_EXCH
000470: Apr 26 21:40:20.644 EDT: ISAKMP:(1006):Sending an IKE IPv4 Packet.
000471: Apr 26 21:40:20.648 EDT: ISAKMP:(1006):Input = IKE_MESG_INTERNAL, IKE_PROCESS_COMPLETE
000472: Apr 26 21:40:20.648 EDT: ISAKMP:(1006):Old State = IKE_R_MM3  New State = IKE_R_MM4

000473: Apr 26 21:40:20.676 EDT: ISAKMP (1006): received packet from 19.9.17.1 dport 500 sport 500 Global (R) MM_KEY_EXCH
000474: Apr 26 21:40:20.676 EDT: ISAKMP:(1006):Input = IKE_MESG_FROM_PEER, IKE_MM_EXCH
000475: Apr 26 21:40:20.676 EDT: ISAKMP:(1006):Old State = IKE_R_MM4  New State = IKE_R_MM5

000476: Apr 26 21:40:20.680 EDT: ISAKMP:(1006): processing ID payload. message ID = 0
000477: Apr 26 21:40:20.680 EDT: ISAKMP (1006): ID payload
        next-payload : 8
        type         : 1
        address      : 19.9.17.1
        protocol     : 0
        port         : 0
        length       : 12
000478: Apr 26 21:40:20.680 EDT: ISAKMP:(0):: peer matches *none* of the profiles
000479: Apr 26 21:40:20.680 EDT: ISAKMP:(1006): processing HASH payload. message ID = 0
000480: Apr 26 21:40:20.680 EDT: ISAKMP:(1006):SA authentication status:
        authenticated
000481: Apr 26 21:40:20.680 EDT: ISAKMP:(1006):SA has been authenticated with 19.9.17.1
000482: Apr 26 21:40:20.680 EDT: ISAKMP: Trying to insert a peer 19.24.11.142/19.9.17.1/500/,  and inserted successfully 2B149B28.
000483: Apr 26 21:40:20.680 EDT: ISAKMP:(1006):Input = IKE_MESG_INTERNAL, IKE_PROCESS_MAIN_MODE
000484: Apr 26 21:40:20.680 EDT: ISAKMP:(1006):Old State = IKE_R_MM5  New State = IKE_R_MM5

000485: Apr 26 21:40:20.680 EDT: ISAKMP:(1006):SA is doing pre-shared key authentication using id type ID_IPV4_ADDR
000486: Apr 26 21:40:20.680 EDT: ISAKMP (1006): ID payload
        next-payload : 8
        type         : 1
        address      : 19.24.11.142
        protocol     : 17
        port         : 500
        length       : 12
000487: Apr 26 21:40:20.680 EDT: ISAKMP:(1006):Total payload length: 12
000488: Apr 26 21:40:20.680 EDT: ISAKMP:(1006): sending packet to 19.9.17.1 my_port 500 peer_port 500 (R) MM_KEY_EXCH
000489: Apr 26 21:40:20.680 EDT: ISAKMP:(1006):Sending an IKE IPv4 Packet.
000490: Apr 26 21:40:20.680 EDT: ISAKMP:(1006):Input = IKE_MESG_INTERNAL, IKE_PROCESS_COMPLETE
000491: Apr 26 21:40:20.680 EDT: ISAKMP:(1006):Old State = IKE_R_MM5  New State = IKE_P1_COMPLETE

000492: Apr 26 21:40:20.680 EDT: ISAKMP:(1006):Input = IKE_MESG_INTERNAL, IKE_PHASE1_COMPLETE
000493: Apr 26 21:40:20.680 EDT: ISAKMP:(1006):Old State = IKE_P1_COMPLETE  New State = IKE_P1_COMPLETE

000494: Apr 26 21:40:20.708 EDT: ISAKMP (1006): received packet from 19.9.17.1 dport 500 sport 500 Global (R) QM_IDLE     
000495: Apr 26 21:40:20.708 EDT: ISAKMP: set new node 565784744 to QM_IDLE     
000496: Apr 26 21:40:20.708 EDT: ISAKMP:(1006): processing HASH payload. message ID = 565784744
000497: Apr 26 21:40:20.708 EDT: ISAKMP:(1006): processing SA payload. message ID = 565784744
000498: Apr 26 21:40:20.708 EDT: ISAKMP:(1006):Checking IPSec proposal 1
000499: Apr 26 21:40:20.708 EDT: ISAKMP: transform 1, ESP_3DES
000500: Apr 26 21:40:20.708 EDT: ISAKMP:   attributes in transform:
000501: Apr 26 21:40:20.708 EDT: ISAKMP:      group is 2
000502: Apr 26 21:40:20.708 EDT: ISAKMP:      SA life type in seconds
000503: Apr 26 21:40:20.708 EDT: ISAKMP:      SA life duration (VPI) of  0x0 0x0 0xE 0x10
000504: Apr 26 21:40:20.708 EDT: ISAKMP:      authenticator is HMAC-SHA
000505: Apr 26 21:40:20.708 EDT: ISAKMP:      encaps is 1 (Tunnel)
000506: Apr 26 21:40:20.708 EDT: ISAKMP:(1006):atts are acceptable.
000507: Apr 26 21:40:20.708 EDT: ISAKMP:(1006): IPSec policy invalidated proposal with error 32
000508: Apr 26 21:40:20.708 EDT: ISAKMP:(1006): phase 2 SA policy not acceptable! (local 19.24.11.142 remote 19.9.17.1)
000509: Apr 26 21:40:20.708 EDT: ISAKMP: set new node -1495049782 to QM_IDLE     
000510: Apr 26 21:40:20.708 EDT: ISAKMP:(1006):Sending NOTIFY PROPOSAL_NOT_CHOSEN protocol 3
        spi 820964128, message ID = 2799917514
000511: Apr 26 21:40:20.708 EDT: ISAKMP:(1006): sending packet to 19.9.17.1 my_port 500 peer_port 500 (R) QM_IDLE     
000512: Apr 26 21:40:20.708 EDT: ISAKMP:(1006):Sending an IKE IPv4 Packet.
000513: Apr 26 21:40:20.708 EDT: ISAKMP:(1006):purging node -1495049782
000514: Apr 26 21:40:20.708 EDT: ISAKMP:(1006):deleting node 565784744 error TRUE reason "QM rejected"
000515: Apr 26 21:40:20.708 EDT: ISAKMP:(1006):Node 565784744, Input = IKE_MESG_FROM_PEER, IKE_QM_EXCH
000516: Apr 26 21:40:20.708 EDT: ISAKMP:(1006):Old State = IKE_QM_READY  New State = IKE_QM_READY

R-IPSEC1#show crypto isakmp sa
IPv4 Crypto ISAKMP SA
dst             src             state          conn-id status
19.24.11.142 19.9.17.1    QM_IDLE           1006 ACTIVE
 
There is "IPSec policy invalidated proposal with error 32". It is not having enough details for me to conclude the cause. L2L VPN TroubleShooting :"IPSec policy invalidated proposal with error 32" situation is not applying to me.

After second thought, I am thinking it may relates to access-list mis-mirrored on both end since that was common issue happened between Check Point and Cisco. Remote site vpn may use wider vpn encryption domain such as /24 network. But I am using /32 instead. So I changed my access-list to following:

R-IPSEC1(config-ext-nacl)#do sh access-list VPN-VPN
Extended IP access list VPN-VPN
    50 permit ip host 19.24.11.245 19.9.17.0 0.0.0.255
    60 permit ip host 19.24.11.53 19.9.17.0 0.0.0.255


Got a little better result but still similar messages.

001319: Apr 26 22:26:41.310 EDT: ISAKMP:(1010):Input = IKE_MESG_INTERNAL, IKE_PHASE1_COMPLETE
001320: Apr 26 22:26:41.310 EDT: ISAKMP:(1010):Old State = IKE_P1_COMPLETE  New State = IKE_P1_COMPLETE

001321: Apr 26 22:26:41.362 EDT: ISAKMP (1010): received packet from 19.9.17.1 dport 500 sport 500 Global (R) QM_IDLE     
001322: Apr 26 22:26:41.362 EDT: ISAKMP: set new node 1351243089 to QM_IDLE     
001323: Apr 26 22:26:41.362 EDT: ISAKMP:(1010): processing HASH payload. message ID = 1351243089
001324: Apr 26 22:26:41.362 EDT: ISAKMP:(1010): processing SA payload. message ID = 1351243089
001325: Apr 26 22:26:41.362 EDT: ISAKMP:(1010):Checking IPSec proposal 1
001326: Apr 26 22:26:41.362 EDT: ISAKMP: transform 1, ESP_3DES
001327: Apr 26 22:26:41.362 EDT: ISAKMP:   attributes in transform:
001328: Apr 26 22:26:41.362 EDT: ISAKMP:      group is 2
001329: Apr 26 22:26:41.362 EDT: ISAKMP:      SA life type in seconds
001330: Apr 26 22:26:41.362 EDT: ISAKMP:      SA life duration (VPI) of  0x0 0x0 0xE 0x10
001331: Apr 26 22:26:41.362 EDT: ISAKMP:      authenticator is HMAC-SHA
001332: Apr 26 22:26:41.362 EDT: ISAKMP:      encaps is 1 (Tunnel)
001333: Apr 26 22:26:41.362 EDT: ISAKMP:(1010):atts are acceptable.
001334: Apr 26 22:26:41.366 EDT: IPSEC(validate_proposal_request): proposal part #1
001335: Apr 26 22:26:41.366 EDT: IPSEC(validate_proposal_request): proposal part #1,
  (key eng. msg.) INBOUND local= 19.24.11.142:0, remote= 19.9.17.1:0,
    local_proxy= 19.24.11.245/255.255.255.255/0/0 (type=1),
    remote_proxy= 198.96.176.41/255.255.255.255/0/0 (type=1),
    protocol= ESP, transform= NONE  (Tunnel),
    lifedur= 0s and 0kb,
    spi= 0x0(0), conn_id= 0, keysize= 0, flags= 0x0
001336: Apr 26 22:26:41.366 EDT: IPSEC(ipsec_process_proposal): proxy identities not supported
001337: Apr 26 22:26:41.366 EDT: ISAKMP:(1010): IPSec policy invalidated proposal with error 32
001338: Apr 26 22:26:41.366 EDT: ISAKMP:(1010): phase 2 SA policy not acceptable! (local 19.24.11.142 remote 19.9.17.1)
001339: Apr 26 22:26:41.366 EDT: ISAKMP: set new node 1666670311 to QM_IDLE     
001340: Apr 26 22:26:41.366 EDT: ISAKMP:(1010):Sending NOTIFY PROPOSAL_NOT_CHOSEN protocol 3
        spi 820964128, message ID = 1666670311
001341: Apr 26 22:26:41.366 EDT: ISAKMP:(1010): sending packet to 19.9.17.1 my_port 500 peer_port 500 (R) QM_IDLE     
001342: Apr 26 22:26:41.366 EDT: ISAKMP:(1010):Sending an IKE IPv4 Packet.

001343: Apr 26 22:26:41.366 EDT: ISAKMP:(1010):purging node 1666670311
001344: Apr 26 22:26:41.366 EDT: ISAKMP:(1010):deleting node 1351243089 error TRUE reason "QM rejected"
001345: Apr 26 22:26:41.366 EDT: ISAKMP:(1010):Node 1351243089, Input = IKE_MESG_FROM_PEER, IKE_QM_EXCH
001346: Apr 26 22:26:41.366 EDT: ISAKMP:(1010):Old State = IKE_QM_READY  New State = IKE_QM_READY


After third thought and discussed with remote firewall administrator, I changed my access-list again to have all since his encryption domains includes specific ip and whole network.

R-IPSEC1(config-ext-nacl)#do show access-list VPN-VPN
Extended IP access list VPN-VPN
    110 permit ip host 19.24.11.53 host 19.9.17.41
    120 permit ip host 19.24.11.245 host 19.9.17.41
    130 permit ip host 19.24.11.53 19.9.17.0 0.0.0.255
    140 permit ip host 19.24.11.245 19.9.17.0 0.0.0.255


Debugging result shows much more details this time:

001565: Apr 26 22:40:20.200 EDT: ISAKMP:(1012):SA is doing pre-shared key authentication using id type ID_IPV4_ADDR
001566: Apr 26 22:40:20.200 EDT: ISAKMP (1012): ID payload
        next-payload : 8
        type         : 1
        address      : 19.24.11.142
        protocol     : 17
        port         : 500
        length       : 12
001567: Apr 26 22:40:20.200 EDT: ISAKMP:(1012):Total payload length: 12
001568: Apr 26 22:40:20.200 EDT: ISAKMP:(1012): sending packet to 19.9.17.1 my_port 500 peer_port 500 (R) MM_KEY_EXCH
001569: Apr 26 22:40:20.200 EDT: ISAKMP:(1012):Sending an IKE IPv4 Packet.
001570: Apr 26 22:40:20.200 EDT: ISAKMP:(1012):Input = IKE_MESG_INTERNAL, IKE_PROCESS_COMPLETE
001571: Apr 26 22:40:20.200 EDT: ISAKMP:(1012):Old State = IKE_R_MM5  New State = IKE_P1_COMPLETE

001572: Apr 26 22:40:20.200 EDT: ISAKMP:(1012):Input = IKE_MESG_INTERNAL, IKE_PHASE1_COMPLETE
001573: Apr 26 22:40:20.200 EDT: ISAKMP:(1012):Old State = IKE_P1_COMPLETE  New State = IKE_P1_COMPLETE

001574: Apr 26 22:40:20.264 EDT: ISAKMP (1012): received packet from 19.9.17.1 dport 500 sport 500 Global (R) QM_IDLE     
001575: Apr 26 22:40:20.264 EDT: ISAKMP: set new node -1828063596 to QM_IDLE     
001576: Apr 26 22:40:20.264 EDT: ISAKMP:(1012): processing HASH payload. message ID = 2466903700
001577: Apr 26 22:40:20.264 EDT: ISAKMP:(1012): processing SA payload. message ID = 2466903700
001578: Apr 26 22:40:20.264 EDT: ISAKMP:(1012):Checking IPSec proposal 1
001579: Apr 26 22:40:20.264 EDT: ISAKMP: transform 1, ESP_3DES
001580: Apr 26 22:40:20.264 EDT: ISAKMP:   attributes in transform:
001581: Apr 26 22:40:20.264 EDT: ISAKMP:      group is 2
001582: Apr 26 22:40:20.264 EDT: ISAKMP:      SA life type in seconds
001583: Apr 26 22:40:20.264 EDT: ISAKMP:      SA life duration (VPI) of  0x0 0x0 0xE 0x10
001584: Apr 26 22:40:20.264 EDT: ISAKMP:      authenticator is HMAC-SHA
001585: Apr 26 22:40:20.264 EDT: ISAKMP:      encaps is 1 (Tunnel)
001586: Apr 26 22:40:20.264 EDT: ISAKMP:(1012):atts are acceptable.
001587: Apr 26 22:40:20.264 EDT: IPSEC(validate_proposal_request): proposal part #1
001588: Apr 26 22:40:20.264 EDT: IPSEC(validate_proposal_request): proposal part #1,
  (key eng. msg.) INBOUND local= 19.24.11.142:0, remote= 19.9.17.1:0,
    local_proxy= 19.24.11.245/255.255.255.255/0/0 (type=1),
    remote_proxy= 19.9.17.41/255.255.255.255/0/0 (type=1),
    protocol= ESP, transform= NONE  (Tunnel),
    lifedur= 0s and 0kb,
    spi= 0x0(0), conn_id= 0, keysize= 0, flags= 0x0
001589: Apr 26 22:40:20.264 EDT: Crypto mapdb : proxy_match
        src addr     : 19.24.11.245
        dst addr     : 19.9.17.41
        protocol     : 0
        src port     : 0
        dst port     : 0
001590: Apr 26 22:40:20.264 EDT: IPSEC(ipsec_process_proposal): transform proposal not supported for identity:
    {esp-3des esp-sha-hmac }
001591: Apr 26 22:40:20.264 EDT: ISAKMP:(1012): IPSec policy invalidated proposal with error 256
001592: Apr 26 22:40:20.264 EDT: ISAKMP:(1012): phase 2 SA policy not acceptable! (local 19.24.11.142 remote 19.9.17.1)
001593: Apr 26 22:40:20.264 EDT: ISAKMP: set new node -760845603 to QM_IDLE     
001594: Apr 26 22:40:20.264 EDT: ISAKMP:(1012):Sending NOTIFY PROPOSAL_NOT_CHOSEN protocol 3
        spi 820964128, message ID = 3534121693
001595: Apr 26 22:40:20.264 EDT: ISAKMP:(1012): sending packet to 19.9.17.1 my_port 500 peer_port 500 (R) QM_IDLE     
001596: Apr 26 22:40:20.264 EDT: ISAKMP:(1012):Sending an IKE IPv4 Packet.
001597: Apr 26 22:40:20.264 EDT: ISAKMP:(1012):purging node -760845603
001598: Apr 26 22:40:20.264 EDT: ISAKMP:(1012):deleting node -1828063596 error TRUE reason "QM rejected"
001599: Apr 26 22:40:20.264 EDT: ISAKMP:(1012):Node 2466903700, Input = IKE_MESG_FROM_PEER, IKE_QM_EXCH
R-IPSEC1#debu
001600: Apr 26 22:40:20.264 EDT: ISAKMP:(1012):Old State = IKE_QM_READY  New State = IKE_QM_READY
R-IPSEC1#   
001601: Apr 26 22:41:10.264 EDT: ISAKMP:(1012):purging node -1828063596

"IPSEC(ipsec_process_proposal): transform proposal not supported for identity:
    {esp-3des esp-sha-hmac }" shows I used wrong transform set. I am using ah-sha-hmac.


Quickly changed to esp-sha-hmac:
crypto ipsec transform-set VPN-Set esp-3des esp-sha-hmac 

This time, finally vpn tunnel get fully up in phase 1 and phase 2. From output of "show crypto ipsec sa", encrypt and decrypt numbers are increasing when test it.



test 
001701: Apr 26 22:46:39.512 EDT: ISAKMP:(1013):Input = IKE_MESG_INTERNAL, IKE_PHASE1_COMPLETE
001702: Apr 26 22:46:39.512 EDT: ISAKMP:(1013):Old State = IKE_P1_COMPLETE  New State = IKE_P1_COMPLETE

001703: Apr 26 22:46:39.560 EDT: ISAKMP (1013): received packet from 19.9.17.1 dport 500 sport 500 Global (R) QM_IDLE     
001704: Apr 26 22:46:39.560 EDT: ISAKMP: set new node -963038103 to QM_IDLE     
001705: Apr 26 22:46:39.560 EDT: ISAKMP:(1013): processing HASH payload. message ID = 3331929193
001706: Apr 26 22:46:39.560 EDT: ISAKMP:(1013): processing SA payload. message ID = 3331929193
001707: Apr 26 22:46:39.560 EDT: ISAKMP:(1013):Checking IPSec proposal 1
001708: Apr 26 22:46:39.560 EDT: ISAKMP: transform 1, ESP_3DES
001709: Apr 26 22:46:39.560 EDT: ISAKMP:   attributes in transform:
001710: Apr 26 22:46:39.560 EDT: ISAKMP:      group is 2
001711: Apr 26 22:46:39.560 EDT: ISAKMP:      SA life type in seconds
001712: Apr 26 22:46:39.560 EDT: ISAKMP:      SA life duration (VPI) of  0x0 0x0 0xE 0x10
001713: Apr 26 22:46:39.560 EDT: ISAKMP:      authenticator is HMAC-SHA
001714: Apr 26 22:46:39.560 EDT: ISAKMP:      encaps is 1 (Tunnel)
001715: Apr 26 22:46:39.560 EDT: ISAKMP:(1013):atts are acceptable.
001716: Apr 26 22:46:39.560 EDT: IPSEC(validate_proposal_request): proposal part #1
001717: Apr 26 22:46:39.560 EDT: IPSEC(validate_proposal_request): proposal part #1,
  (key eng. msg.) INBOUND local= 19.24.11.142:0, remote= 19.9.17.1:0,
    local_proxy= 19.24.11.245/255.255.255.255/0/0 (type=1),
    remote_proxy= 198.96.176.41/255.255.255.255/0/0 (type=1),
    protocol= ESP, transform= NONE  (Tunnel),
    lifedur= 0s and 0kb,
    spi= 0x0(0), conn_id= 0, keysize= 0, flags= 0x0
001718: Apr 26 22:46:39.560 EDT: Crypto mapdb : proxy_match
        src addr     : 19.24.11.245
        dst addr     : 198.96.176.41
        protocol     : 0
        src port     : 0
        dst port     : 0
001719: Apr 26 22:46:39.580 EDT: ISAKMP:(1013): processing NONCE payload. message ID = 3331929193
001720: Apr 26 22:46:39.580 EDT: ISAKMP:(1013): processing KE payload. message ID = 3331929193
001721: Apr 26 22:46:39.608 EDT: ISAKMP:(1013): processing ID payload. message ID = 3331929193
001722: Apr 26 22:46:39.608 EDT: ISAKMP:(1013): processing ID payload. message ID = 3331929193
001723: Apr 26 22:46:39.608 EDT: ISAKMP:(1013):QM Responder gets spi
001724: Apr 26 22:46:39.608 EDT: ISAKMP:(1013):Node 3331929193, Input = IKE_MESG_FROM_PEER, IKE_QM_EXCH
001725: Apr 26 22:46:39.608 EDT: ISAKMP:(1013):Old State = IKE_QM_READY  New State = IKE_QM_SPI_STARVE
001726: Apr 26 22:46:39.608 EDT: ISAKMP:(1013): Creating IPSec SAs
001727: Apr 26 22:46:39.608 EDT:         inbound SA from 19.9.17.1 to 19.24.11.142 (f/i)  0/ 0
        (proxy 198.96.176.41 to 19.24.11.245)
001728: Apr 26 22:46:39.608 EDT:         has spi 0x4F77DACA and conn_id 0
001729: Apr 26 22:46:39.608 EDT:         lifetime of 3600 seconds
001730: Apr 26 22:46:39.608 EDT:         outbound SA from 19.24.11.142 to 19.9.17.1 (f/i) 0/0
        (proxy 19.24.11.245 to 198.96.176.41)
001731: Apr 26 22:46:39.608 EDT:         has spi  0x990B6255 and conn_id 0
001732: Apr 26 22:46:39.608 EDT:         lifetime of 3600 seconds
001733: Apr 26 22:46:39.608 EDT: ISAKMP:(1013): sending packet to 19.9.17.1 my_port 500 peer_port 500 (R) QM_IDLE     
001734: Apr 26 22:46:39.608 EDT: ISAKMP:(1013):Sending an IKE IPv4 Packet.
001735: Apr 26 22:46:39.608 EDT: ISAKMP:(1013):Node 3331929193, Input = IKE_MESG_INTERNAL, IKE_GOT_SPI
001736: Apr 26 22:46:39.608 EDT: ISAKMP:(1013):Old State = IKE_QM_SPI_STARVE  New State = IKE_QM_R_QM2
001737: Apr 26 22:46:39.608 EDT: IPSEC(key_engine): got a queue event with 1 KMI message(s)
001738: Apr 26 22:46:39.608 EDT: Crypto mapdb : proxy_match
        src addr     : 19.24.11.245
        dst addr     : 198.96.176.41
        protocol     : 0
        src port     : 0
        dst port     : 0
001739: Apr 26 22:46:39.612 EDT: IPSEC(crypto_ipsec_sa_find_ident_head): reconnecting with the same proxies and peer 19.9.17.1
001740: Apr 26 22:46:39.612 EDT: IPSEC(policy_db_add_ident): src 19.24.11.245, dest 198.96.176.41, dest_port 0

001741: Apr 26 22:46:39.612 EDT: IPSEC(create_sa): sa created,
  (sa) sa_dest= 19.24.11.142, sa_proto= 50,
    sa_spi= 0x4F77DACA(1333254858),
    sa_trans= esp-3des esp-sha-hmac , sa_conn_id= 2001
    sa_lifetime(k/sec)= (4586756/3600)
001742: Apr 26 22:46:39.612 EDT: IPSEC(create_sa): sa created,
  (sa) sa_dest= 19.9.17.1, sa_proto= 50,
    sa_spi= 0x990B6255(2567660117),
    sa_trans= esp-3des esp-sha-hmac , sa_conn_id= 2002
    sa_lifetime(k/sec)= (4586756/3600)
001743: Apr 26 22:46:39.656 EDT: ISAKMP (1013): received packet from 19.9.17.1 dport 500 sport 500 Global (R) QM_IDLE     
001744: Apr 26 22:46:39.656 EDT: ISAKMP:(1013):deleting node -963038103 error FALSE reason "QM done (await)"
001745: Apr 26 22:46:39.656 EDT: ISAKMP:(1013):Node 3331929193, Input = IKE_MESG_FROM_PEER, IKE_QM_EXCH
001746: Apr 26 22:46:39.656 EDT: ISAKMP:(1013):Old State = IKE_QM_R_QM2  New State = IKE_QM_PHASE2_COMPLETE
001747: Apr 26 22:46:39.656 EDT: IPSEC(key_engine): got a queue event with 1 KMI message(s)
001748: Apr 26 22:46:39.656 EDT: IPSEC(key_engine_enable_outbound): rec'd enable notify from ISAKMP
001749: Apr 26 22:46:39.656 EDT: IPSEC(key_engine_enable_outbound): enable SA with spi 2567660117/50
001750: Apr 26 22:46:39.656 EDT: IPSEC(update_current_outbound_sa): get enable SA peer 19.9.17.1 current outbound sa to SPI 990B6255
001751: Apr 26 22:46:39.656 EDT: IPSEC(update_current_outbound_sa): updated peer 19.9.17.1 current outbound sa to SPI 990B6255
001752: Apr 26 22:46:39.696 EDT: %AAA-3-BADSERVERTYPEERROR: Cannot process accounting server type tacacs+ (UNKNOWN)
001753: Apr 26 22:46:39.756 EDT: ISAKMP (1013): received packet from 19.9.17.1 dport 500 sport 500 Global (R) QM_IDLE     
001754: Apr 26 22:46:39.756 EDT: ISAKMP:(1013): phase 2 packet is a duplicate of a previous packet.
001755: Apr 26 22:46:39.756 EDT: ISAKMP:(1013): retransmitting due to retransmit phase 2
001756: Apr 26 22:46:39.756 EDT: ISAKMP:(1013): ignoring retransmission,because phase2 node marked dead -963038103
001757: Apr 26 22:46:39.856 EDT: ISAKMP (1013): received packet from 19.9.17.1 dport 500 sport 500 Global (R) QM_IDLE     
001758: Apr 26 22:46:39.856 EDT: ISAKMP:(1013): phase 2 packet is a duplicate of a previous packet.
[confirm]
001759: Apr 26 22:46:39.856 EDT: ISAKMP:(1013): retransmitting due to retransmit phase 2
001760: Apr 26 22:46:39.856 EDT: ISAKMP:(1013): ignoring retransmission,because phase2 node marked dead -963038103
[confirm]


Debugging Command:
  • debug crypto engine—Displays debug messages about crypto engines, which perform encryption and decryption.
  • debug crypto isakmp—Displays messages about IKE events.
  • debug crypto ipsec—Displays IPSec events.
  • clear crypto isakmp—Clears all active IKE connections.
  • clear crypto sa—Clears all IPSec SAs.
  •  IPSEC1#show crypto isakmp sa
    IPv4 Crypto ISAKMP SA
    dst                  src              state                conn-id status
    19.24.11.142 19.9.17.1    QM_IDLE           1014 ACTIVE
    19.24.11.142 19.9.17.1    QM_IDLE           1013 ACTIVE
  • clear crypto isakmp 1013—Clears connection id of SA.


Reference:



Read more

Subscribe via email

Author Image

About Netsec
Netsec - Learning, Sharing, Creating!

By -
Tags:

No comments:

Post a Comment

Subscribe to: Post Comments (Atom)

Banner

BANNER 728X90