SRX Services Gateway
Blogs
Discussion Forums
Programs & Events
turn on suggestions Auto-suggest helps you quickly narrow down your search results by suggesting possible matches as you type.
Auto-suggest helps you quickly narrow down your search results by suggesting possible matches as you type.
Reply
Topic Options
zvitins
Contributor
zvitins
Posts: 119
Registered: ‎12-04-2009
0

Policy based VPN - Phase1

Options

‎04-19-2012 05:13 AM

Hello,

 

I try to set up policy based VPN on SRX-240, on other side VPN device is Cisco ASA

 

My configuration is

Ike:

 

set security ike traceoptions file vpn-debug-ike
set security ike traceoptions flag all
set security ike proposal pre-g2-3des-sha authentication-method pre-shared-keys
set security ike proposal pre-g2-3des-sha dh-group group2
set security ike proposal pre-g2-3des-sha authentication-algorithm sha1
set security ike proposal pre-g2-3des-sha encryption-algorithm 3des-cbc
set security ike proposal pre-g2-3des-sha lifetime-seconds 3600
set security ike policy ike-policy-rs proposals pre-g2-3des-sha
set security ike policy ike-policy-rs pre-shared-key ascii-text "......"
set security ike gateway ike-gate-rs ike-policy ike-policy-rs
set security ike gateway ike-gate-rs address 1.1.1.9
set security ike gateway ike-gate-rs external-interface ge-0/0/0.0

 Phase2

set security ipsec traceoptions flag all
set security ipsec proposal g2-esp-3des-sha protocol esp
set security ipsec proposal g2-esp-3des-sha authentication-algorithm hmac-sha1-96
set security ipsec proposal g2-esp-3des-sha encryption-algorithm 3des-cbc
set security ipsec proposal g2-esp-3des-sha lifetime-seconds 3600
set security ipsec policy vpn-policy-rs perfect-forward-secrecy keys group2
set security ipsec policy vpn-policy-rs proposals g2-esp-3des-sha
set security ipsec vpn ike-vpn-rs ike gateway ike-gate-rs
set security ipsec vpn ike-vpn-rs ike ipsec-policy vpn-policy-rs

 Policy:

set security policies from-zone trust to-zone untrust policy vpnpolicy-rstr-unt match source-address local-net
set security policies from-zone trust to-zone untrust policy vpnpolicy-rstr-unt match destination-address 192.168.200.0/22
set security policies from-zone trust to-zone untrust policy vpnpolicy-rstr-unt match application any
set security policies from-zone trust to-zone untrust policy vpnpolicy-rstr-unt then permit tunnel ipsec-vpn ike-vpn-rs
set security policies from-zone trust to-zone untrust policy vpnpolicy-rstr-unt then permit tunnel pair-policy vpnpolicy-rsunt-tr
set security policies from-zone trust to-zone untrust policy vpnpolicy-rs2tr-unt match source-address local-net
set security policies from-zone trust to-zone untrust policy vpnpolicy-rs2tr-unt match destination-address 192.168.99.0/24
set security policies from-zone trust to-zone untrust policy vpnpolicy-rs2tr-unt match application any
set security policies from-zone trust to-zone untrust policy vpnpolicy-rs2tr-unt then permit tunnel ipsec-vpn ike-vpn-rs
set security policies from-zone trust to-zone untrust policy vpnpolicy-rs2tr-unt then permit tunnel pair-policy vpnpolicy-rs2unt-tr
set security policies from-zone untrust to-zone trust policy vpnpolicy-rsunt-tr match source-address 192.168.200.0/22
set security policies from-zone untrust to-zone trust policy vpnpolicy-rsunt-tr match destination-address local-net
set security policies from-zone untrust to-zone trust policy vpnpolicy-rsunt-tr match application any
set security policies from-zone untrust to-zone trust policy vpnpolicy-rsunt-tr then permit tunnel ipsec-vpn ike-vpn-rs
set security policies from-zone untrust to-zone trust policy vpnpolicy-rsunt-tr then permit tunnel pair-policy vpnpolicy-rstr-unt
set security policies from-zone untrust to-zone trust policy vpnpolicy-rs2unt-tr match source-address 192.168.99.0/24
set security policies from-zone untrust to-zone trust policy vpnpolicy-rs2unt-tr match destination-address local-net
set security policies from-zone untrust to-zone trust policy vpnpolicy-rs2unt-tr match application any
set security policies from-zone untrust to-zone trust policy vpnpolicy-rs2unt-tr then permit tunnel ipsec-vpn ike-vpn-rs
set security policies from-zone untrust to-zone trust policy vpnpolicy-rs2unt-tr then permit tunnel pair-policy vpnpolicy-rs2tr-unt

 

vpn-logfile:

 

Apr 18 15:07:45 The remote server at 1.1.1.9:500 is 'draft-ietf-ipsec-nat-t-ike-02'
Apr 18 15:07:45 Not setting PMDATA_PEER_IS_OURS for 1.1.1.9
Apr 18 15:07:45 ike_st_i_vid: VID[0..20] = 4048b7d5 6ebce885 ...
Apr 18 15:07:45 The remote server at 1.1.1.9:500 is '40 48 b7 d5 6e bc e8 85 25 e7 de 7f 00 d6 c2 d3 c0 00 00 00'
Apr 18 15:07:45 ike_st_i_private: Start
Apr 18 15:07:45 ike_st_o_ke: Start
Apr 18 15:07:45 ike_st_o_nonce: Start
Apr 18 15:07:45 ike_policy_reply_isakmp_nonce_data_len: Start
Apr 18 15:07:45 ike_st_o_private: Start
Apr 18 15:07:45 ike_policy_reply_private_payload_out: Start
Apr 18 15:07:45 my_ipaddr_as_ike_id: add <2.3.4.5>
Apr 18 15:07:45 ike_policy_reply_private_payload_out: Start
Apr 18 15:07:45 ike_policy_reply_private_payload_out: Start
Apr 18 15:07:45 ike_encode_packet: Start, SA = { 0xf6333480 58003800 - 9d6b1ee5 07a564b8 } / 00000000, nego = -1
Apr 18 15:07:45 ike_send_packet: Start, send SA = { f6333480 58003800 - 9d6b1ee5 07a564b8}, nego = -1, src=2.3.4.5:500, dst = 1.1.1.9:500, routing table id = 0
Apr 18 15:07:50 ike_retransmit_callback: Start, retransmit SA = { f6333480 58003800 - 9d6b1ee5 07a564b8}, nego = -1
Apr 18 15:07:50 ike_send_packet: Start, retransmit previous packet SA = { f6333480 58003800 - 9d6b1ee5 07a564b8}, nego = -1, src=2.3.4.5:500, dst = 1.1.1.9:500, routing table id = 0
Apr 18 15:07:50 ike_get_sa: Start, SA = { f6333480 58003800 - 9d6b1ee5 07a564b8 } / 00000000, remote = 1.1.1.9:500
Apr 18 15:07:50 ike_sa_find: Found SA = { f6333480 58003800 - 9d6b1ee5 07a564b8 }
Apr 18 15:07:50 ike_alloc_negotiation: Start, SA = { f6333480 58003800 - 9d6b1ee5 07a564b8}
Apr 18 15:07:50 ike_decode_packet: Start
Apr 18 15:07:50 ike_decode_packet: Start, SA = { f6333480 58003800 - 9d6b1ee5 07a564b8} / 00000000, nego = 0
Apr 18 15:07:50 ike_st_i_n: Start, doi = 1, protocol = 0, code = Invalid Cookie (4), spi[0..0] = 00000000 00000000 ..., data[0..28] = a89009ab d8ccadab ...
Apr 18 15:07:50 2.3.4.5:500 (Responder) <-> 1.1.1.9:500 { f6333480 58003800 - 9d6b1ee5 07a564b8 [0] / 0x00000000 } Info; Invalid protocol_id = 0
Apr 18 15:07:50 2.3.4.5:500 (Responder) <-> 1.1.1.9:500 { f6333480 58003800 - 9d6b1ee5 07a564b8 [0] / 0x00000000 } Info; Error = Invalid protocol ID (10)
Apr 18 15:07:50 ike_send_notify: Notification to informational exchange ignored
Apr 18 15:07:50 ike_delete_negotiation: Start, SA = { f6333480 58003800 - 9d6b1ee5 07a564b8}, nego = 0
Apr 18 15:07:50 ike_free_negotiation_info: Start, nego = 0
Apr 18 15:07:50 ike_free_negotiation: Start, nego = 0

 

But Phase1 is down

 

show security ike security-associations
Index   Remote Address  State  Initiator cookie  Responder cookie  Mode
7778567 1.1.1.9     DOWN   890f019bc1911e0b  4719399f76e85b74  Main 

 

What is wrong in this configuration?

How to debug and find the problem?

 

Thanks

Zigmunds

 

Message 1 of 5 (1,014 Views)
 
Reply
Distinguished Expert
Distinguished Expert
MMcD
Posts: 528
Registered: ‎07-20-2010
0

Re: Policy based VPN - Phase1

Options

‎04-19-2012 06:54 AM

Hi there,

 

Is that all that is contained in the ike trace? If not can you post more.

 

Can you confirm that ike is enabled as an inbound service on ge-0/0/0.0?

 

Are there any logs from the ASA side?

MMcD [JNCIS-SEC, CCNA, MCP]
____________________________________________________

[Please Mark My Solution Accepted if it Helped, Kudos are Appreciated Too]
Message 2 of 5 (1,007 Views)
 
Reply
zvitins
Contributor
zvitins
Posts: 119
Registered: ‎12-04-2009
0

Re: Policy based VPN - Phase1

[ Edited ]
Options

‎04-19-2012 07:30 AM - edited ‎04-19-2012 07:42 AM

Hello,

 

this is full log:

 


Apr 18 17:32:42 The remote server at 1.1.1.9:500 is 'draft-ietf-ipsec-nat-t-ike-02'
Apr 18 17:32:42 Not setting PMDATA_PEER_IS_OURS for 1.1.1.9
Apr 18 17:32:42 ike_st_i_vid: VID[0..20] = 4048b7d5 6ebce885 ...
Apr 18 17:32:42 The remote server at 1.1.1.9:500 is '40 48 b7 d5 6e bc e8 85 25 e7 de 7f 00 d6 c2 d3 c0 00 00 00'
Apr 18 17:32:42 ike_st_i_private: Start
Apr 18 17:32:42 ike_st_o_ke: Start
Apr 18 17:32:42 ike_st_o_nonce: Start
Apr 18 17:32:42 ike_policy_reply_isakmp_nonce_data_len: Start
Apr 18 17:32:42 ike_st_o_private: Start
Apr 18 17:32:42 ike_policy_reply_private_payload_out: Start
Apr 18 17:32:42 my_ipaddr_as_ike_id: add <2.2.2.2>
Apr 18 17:32:42 ike_policy_reply_private_payload_out: Start
Apr 18 17:32:42 ike_policy_reply_private_payload_out: Start
Apr 18 17:32:42 ike_encode_packet: Start, SA = { 0x8668d300 e729401d - c5eba674 387f9690 } / 00000000, nego = -1
Apr 18 17:32:42 ike_send_packet: Start, send SA = { 8668d300 e729401d - c5eba674 387f9690}, nego = -1, src=2.2.2.2:500, dst = 1.1.1.9:500, routing table id = 0
Apr 18 17:32:47 ike_retransmit_callback: Start, retransmit SA = { 8668d300 e729401d - c5eba674 387f9690}, nego = -1
Apr 18 17:32:47 ike_send_packet: Start, retransmit previous packet SA = { 8668d300 e729401d - c5eba674 387f9690}, nego = -1, src=2.2.2.2:500, dst = 1.1.1.9:500, routing table id = 0
Apr 18 17:32:47 ike_get_sa: Start, SA = { 8668d300 e729401d - c5eba674 387f9690 } / 00000000, remote = 1.1.1.9:500
Apr 18 17:32:47 ike_sa_find: Found SA = { 8668d300 e729401d - c5eba674 387f9690 }
Apr 18 17:32:47 ike_alloc_negotiation: Start, SA = { 8668d300 e729401d - c5eba674 387f9690}
Apr 18 17:32:47 ike_decode_packet: Start
Apr 18 17:32:47 ike_decode_packet: Start, SA = { 8668d300 e729401d - c5eba674 387f9690} / 00000000, nego = 0
Apr 18 17:32:47 ike_st_i_n: Start, doi = 1, protocol = 0, code = Invalid Cookie (4), spi[0..0] = 00000000 00000000 ..., data[0..28] = a89009ab d8ccadab ...
Apr 18 17:32:47 2.2.2.2:500 (Responder) <-> 1.1.1.9:500 { 8668d300 e729401d - c5eba674 387f9690 [0] / 0x00000000 } Info; Invalid protocol_id = 0
Apr 18 17:32:47 2.2.2.2:500 (Responder) <-> 1.1.1.9:500 { 8668d300 e729401d - c5eba674 387f9690 [0] / 0x00000000 } Info; Error = Invalid protocol ID (10)
Apr 18 17:32:47 ike_send_notify: Notification to informational exchange ignored
Apr 18 17:32:47 ike_delete_negotiation: Start, SA = { 8668d300 e729401d - c5eba674 387f9690}, nego = 0
Apr 18 17:32:47 ike_free_negotiation_info: Start, nego = 0
Apr 18 17:32:47 ike_free_negotiation: Start, nego = 0
Apr 18 17:32:51 kmd_pm_ike_start_p1
Apr 18 17:32:51 Phase-1 negotiation already started for p1_local=ipv4(udp:500,[0..3]=2.2.2.2) p1_remote=ipv4(udp:500,[0..3]=1.1.1.9)
Apr 18 17:32:51 Queue phase-2 negotiation for p1_local=ipv4(udp:500,[0..3]=2.2.2.2) p1_remote=ipv4(udp:500,[0..3]=1.1.1.9)
Apr 18 17:32:57 ike_retransmit_callback: Start, retransmit SA = { 8668d300 e729401d - c5eba674 387f9690}, nego = -1
Apr 18 17:32:57 ike_send_packet: Start, retransmit previous packet SA = { 8668d300 e729401d - c5eba674 387f9690}, nego = -1, src=2.2.2.2:500, dst = 1.1.1.9:500, routing table id = 0
Apr 18 17:32:57 ike_get_sa: Start, SA = { 8668d300 e729401d - c5eba674 387f9690 } / 00000000, remote = 1.1.1.9:500
Apr 18 17:32:57 ike_sa_find: Found SA = { 8668d300 e729401d - c5eba674 387f9690 }
Apr 18 17:32:57 ike_alloc_negotiation: Start, SA = { 8668d300 e729401d - c5eba674 387f9690}
Apr 18 17:32:57 ike_decode_packet: Start
Apr 18 17:32:57 ike_decode_packet: Start, SA = { 8668d300 e729401d - c5eba674 387f9690} / 00000000, nego = 0
Apr 18 17:32:57 ike_st_i_n: Start, doi = 1, protocol = 0, code = Invalid Cookie (4), spi[0..0] = 00000000 00000000 ..., data[0..28] = a89009ab 58990eab ...
Apr 18 17:32:57 2.2.2.2:500 (Responder) <-> 1.1.1.9:500 { 8668d300 e729401d - c5eba674 387f9690 [0] / 0x00000000 } Info; Invalid protocol_id = 0
Apr 18 17:32:57 2.2.2.2:500 (Responder) <-> 1.1.1.9:500 { 8668d300 e729401d - c5eba674 387f9690 [0] / 0x00000000 } Info; Error = Invalid protocol ID (10)
Apr 18 17:32:57 ike_send_notify: Notification to informational exchange ignored
Apr 18 17:32:57 ike_delete_negotiation: Start, SA = { 8668d300 e729401d - c5eba674 387f9690}, nego = 0
Apr 18 17:32:57 ike_free_negotiation_info: Start, nego = 0
Apr 18 17:32:57 ike_free_negotiation: Start, nego = 0
Apr 18 17:33:01 kmd_pm_ike_start_p1
Apr 18 17:33:01 Phase-1 negotiation already started for p1_local=ipv4(udp:500,[0..3]=2.2.2.2) p1_remote=ipv4(udp:500,[0..3]=1.1.1.9)
Apr 18 17:33:01 Phase-2 negotiation already queued for p1_local=ipv4(udp:500,[0..3]=2.2.2.2) p1_remote=ipv4(udp:500,[0..3]=1.1.1.9)
Apr 18 17:33:11 kmd_pm_ike_start_p1
Apr 18 17:33:11 Phase-1 negotiation already started for p1_local=ipv4(udp:500,[0..3]=2.2.2.2) p1_remote=ipv4(udp:500,[0..3]=1.1.1.9)
Apr 18 17:33:11 Phase-2 negotiation already queued for p1_local=ipv4(udp:500,[0..3]=2.2.2.2) p1_remote=ipv4(udp:500,[0..3]=1.1.1.9)
Apr 18 17:33:17 ike_retransmit_callback: Start, retransmit SA = { 8668d300 e729401d - c5eba674 387f9690}, nego = -1
Apr 18 17:33:17 ike_send_packet: Start, retransmit previous packet SA = { 8668d300 e729401d - c5eba674 387f9690}, nego = -1, src=2.2.2.2:500, dst = 1.1.1.9:500, routing table id = 0
Apr 18 17:33:17 ike_get_sa: Start, SA = { 8668d300 e729401d - c5eba674 387f9690 } / 00000000, remote = 1.1.1.9:500
Apr 18 17:33:17 ike_sa_find: Found SA = { 8668d300 e729401d - c5eba674 387f9690 }
Apr 18 17:33:17 ike_alloc_negotiation: Start, SA = { 8668d300 e729401d - c5eba674 387f9690}
Apr 18 17:33:17 ike_decode_packet: Start
Apr 18 17:33:17 ike_decode_packet: Start, SA = { 8668d300 e729401d - c5eba674 387f9690} / 00000000, nego = 0
Apr 18 17:33:17 ike_st_i_n: Start, doi = 1, protocol = 0, code = Invalid Cookie (4), spi[0..0] = 00000000 00000000 ..., data[0..28] = a89009ab d8ccadab ...
Apr 18 17:33:17 2.2.2.2:500 (Responder) <-> 1.1.1.9:500 { 8668d300 e729401d - c5eba674 387f9690 [0] / 0x00000000 } Info; Invalid protocol_id = 0
Apr 18 17:33:17 2.2.2.2:500 (Responder) <-> 1.1.1.9:500 { 8668d300 e729401d - c5eba674 387f9690 [0] / 0x00000000 } Info; Error = Invalid protocol ID (10)
Apr 18 17:33:17 ike_send_notify: Notification to informational exchange ignored
Apr 18 17:33:17 ike_delete_negotiation: Start, SA = { 8668d300 e729401d - c5eba674 387f9690}, nego = 0
Apr 18 17:33:17 ike_free_negotiation_info: Start, nego = 0
Apr 18 17:33:17 ike_free_negotiation: Start, nego = 0
Apr 18 17:33:22 kmd_pm_ike_start_p1
Apr 18 17:33:22 Phase-1 negotiation already started for p1_local=ipv4(udp:500,[0..3]=2.2.2.2) p1_remote=ipv4(udp:500,[0..3]=1.1.1.9)
Apr 18 17:33:22 Phase-2 negotiation already queued for p1_local=ipv4(udp:500,[0..3]=2.2.2.2) p1_remote=ipv4(udp:500,[0..3]=1.1.1.9)
Apr 18 17:33:32 kmd_pm_ike_start_p1
Apr 18 17:33:32 Phase-1 negotiation already started for p1_local=ipv4(udp:500,[0..3]=2.2.2.2) p1_remote=ipv4(udp:500,[0..3]=1.1.1.9)
Apr 18 17:33:32 Phase-2 negotiation already queued for p1_local=ipv4(udp:500,[0..3]=2.2.2.2) p1_remote=ipv4(udp:500,[0..3]=1.1.1.9)
Apr 18 17:33:42 kmd_pm_ike_start_p1
Apr 18 17:33:42 Phase-1 negotiation already started for p1_local=ipv4(udp:500,[0..3]=2.2.2.2) p1_remote=ipv4(udp:500,[0..3]=1.1.1.9)
Apr 18 17:33:42 Phase-2 negotiation already queued for p1_local=ipv4(udp:500,[0..3]=2.2.2.2) p1_remote=ipv4(udp:500,[0..3]=1.1.1.9)
Apr 18 17:33:52 kmd_pm_ike_start_p1
Apr 18 17:33:52 Phase-1 negotiation already started for p1_local=ipv4(udp:500,[0..3]=2.2.2.2) p1_remote=ipv4(udp:500,[0..3]=1.1.1.9)
Apr 18 17:33:52 Phase-2 negotiation already queued for p1_local=ipv4(udp:500,[0..3]=2.2.2.2) p1_remote=ipv4(udp:500,[0..3]=1.1.1.9)
Apr 18 17:33:57 ike_retransmit_callback: Start, retransmit SA = { 8668d300 e729401d - c5eba674 387f9690}, nego = -1
Apr 18 17:33:57 ike_send_packet: Start, retransmit previous packet SA = { 8668d300 e729401d - c5eba674 387f9690}, nego = -1, src=2.2.2.2:500, dst = 1.1.1.9:500, routing table id = 0
Apr 18 17:33:57 ike_get_sa: Start, SA = { 8668d300 e729401d - c5eba674 387f9690 } / 00000000, remote = 1.1.1.9:500
Apr 18 17:33:57 ike_sa_find: Found SA = { 8668d300 e729401d - c5eba674 387f9690 }
Apr 18 17:33:57 ike_alloc_negotiation: Start, SA = { 8668d300 e729401d - c5eba674 387f9690}
Apr 18 17:33:57 ike_decode_packet: Start
Apr 18 17:33:57 ike_decode_packet: Start, SA = { 8668d300 e729401d - c5eba674 387f9690} / 00000000, nego = 0
Apr 18 17:33:57 ike_st_i_n: Start, doi = 1, protocol = 0, code = Invalid Cookie (4), spi[0..0] = 00000000 00000000 ..., data[0..28] = a89009ab 58990eab ...
Apr 18 17:33:57 2.2.2.2:500 (Responder) <-> 1.1.1.9:500 { 8668d300 e729401d - c5eba674 387f9690 [0] / 0x00000000 } Info; Invalid protocol_id = 0
Apr 18 17:33:57 2.2.2.2:500 (Responder) <-> 1.1.1.9:500 { 8668d300 e729401d - c5eba674 387f9690 [0] / 0x00000000 } Info; Error = Invalid protocol ID (10)
Apr 18 17:33:57 ike_send_notify: Notification to informational exchange ignored
Apr 18 17:33:57 ike_delete_negotiation: Start, SA = { 8668d300 e729401d - c5eba674 387f9690}, nego = 0
Apr 18 17:33:57 ike_free_negotiation_info: Start, nego = 0
Apr 18 17:33:57 ike_free_negotiation: Start, nego = 0
Apr 18 17:34:02 kmd_pm_ike_start_p1
Apr 18 17:34:02 Phase-1 negotiation already started for p1_local=ipv4(udp:500,[0..3]=2.2.2.2) p1_remote=ipv4(udp:500,[0..3]=1.1.1.9)
Apr 18 17:34:02 Phase-2 negotiation already queued for p1_local=ipv4(udp:500,[0..3]=2.2.2.2) p1_remote=ipv4(udp:500,[0..3]=1.1.1.9)
Apr 18 17:34:12 kmd_pm_ike_start_p1
Apr 18 17:34:12 Phase-1 negotiation already started for p1_local=ipv4(udp:500,[0..3]=2.2.2.2) p1_remote=ipv4(udp:500,[0..3]=1.1.1.9)
Apr 18 17:34:12 Phase-2 negotiation already queued for p1_local=ipv4(udp:500,[0..3]=2.2.2.2) p1_remote=ipv4(udp:500,[0..3]=1.1.1.9)
Apr 18 17:34:22 kmd_pm_ike_start_p1
Apr 18 17:34:22 Phase-1 negotiation already started for p1_local=ipv4(udp:500,[0..3]=2.2.2.2) p1_remote=ipv4(udp:500,[0..3]=1.1.1.9)
Apr 18 17:34:22 Phase-2 negotiation already queued for p1_local=ipv4(udp:500,[0..3]=2.2.2.2) p1_remote=ipv4(udp:500,[0..3]=1.1.1.9)
Apr 18 17:34:32 kmd_pm_ike_start_p1
Apr 18 17:34:32 Phase-1 negotiation already started for p1_local=ipv4(udp:500,[0..3]=2.2.2.2) p1_remote=ipv4(udp:500,[0..3]=1.1.1.9)
Apr 18 17:34:32 Phase-2 negotiation already queued for p1_local=ipv4(udp:500,[0..3]=2.2.2.2) p1_remote=ipv4(udp:500,[0..3]=1.1.1.9)
Apr 18 17:34:42 kmd_pm_ike_start_p1
Apr 18 17:34:42 Phase-1 negotiation already started for p1_local=ipv4(udp:500,[0..3]=2.2.2.2) p1_remote=ipv4(udp:500,[0..3]=1.1.1.9)
Apr 18 17:34:42 Phase-2 negotiation already queued for p1_local=ipv4(udp:500,[0..3]=2.2.2.2) p1_remote=ipv4(udp:500,[0..3]=1.1.1.9)
Apr 18 17:34:57 kmd_pm_ike_start_p1
Apr 18 17:34:57 Phase-1 negotiation already started for p1_local=ipv4(udp:500,[0..3]=2.2.2.2) p1_remote=ipv4(udp:500,[0..3]=1.1.1.9)
Apr 18 17:34:57 Phase-2 negotiation already queued for p1_local=ipv4(udp:500,[0..3]=2.2.2.2) p1_remote=ipv4(udp:500,[0..3]=1.1.1.9)
Apr 18 17:35:07 kmd_pm_ike_start_p1
Apr 18 17:35:07 Phase-1 negotiation already started for p1_local=ipv4(udp:500,[0..3]=2.2.2.2) p1_remote=ipv4(udp:500,[0..3]=1.1.1.9)
Apr 18 17:35:07 Phase-2 negotiation already queued for p1_local=ipv4(udp:500,[0..3]=2.2.2.2) p1_remote=ipv4(udp:500,[0..3]=1.1.1.9)
Apr 18 17:35:17 kmd_pm_ike_start_p1
Apr 18 17:35:17 Phase-1 negotiation already started for p1_local=ipv4(udp:500,[0..3]=2.2.2.2) p1_remote=ipv4(udp:500,[0..3]=1.1.1.9)
Apr 18 17:35:17 Phase-2 negotiation already queued for p1_local=ipv4(udp:500,[0..3]=2.2.2.2) p1_remote=ipv4(udp:500,[0..3]=1.1.1.9)
Apr 18 17:35:17 ike_retransmit_callback: Start, retransmit SA = { 8668d300 e729401d - c5eba674 387f9690}, nego = -1
Apr 18 17:35:17 ike_send_packet: Start, retransmit previous packet SA = { 8668d300 e729401d - c5eba674 387f9690}, nego = -1, src=2.2.2.2:500, dst = 1.1.1.9:500, routing table id = 0
Apr 18 17:35:17 ike_get_sa: Start, SA = { 8668d300 e729401d - c5eba674 387f9690 } / 00000000, remote = 1.1.1.9:500
Apr 18 17:35:17 ike_sa_find: Found SA = { 8668d300 e729401d - c5eba674 387f9690 }
Apr 18 17:35:17 ike_alloc_negotiation: Start, SA = { 8668d300 e729401d - c5eba674 387f9690}
Apr 18 17:35:17 ike_decode_packet: Start
Apr 18 17:35:17 ike_decode_packet: Start, SA = { 8668d300 e729401d - c5eba674 387f9690} / 00000000, nego = 0
Apr 18 17:35:17 ike_st_i_n: Start, doi = 1, protocol = 0, code = Invalid Cookie (4), spi[0..0] = 00000000 00000000 ..., data[0..28] = a89009ab d8ccadab ...
Apr 18 17:35:17 2.2.2.2:500 (Responder) <-> 1.1.1.9:500 { 8668d300 e729401d - c5eba674 387f9690 [0] / 0x00000000 } Info; Invalid protocol_id = 0
Apr 18 17:35:17 2.2.2.2:500 (Responder) <-> 1.1.1.9:500 { 8668d300 e729401d - c5eba674 387f9690 [0] / 0x00000000 } Info; Error = Invalid protocol ID (10)
Apr 18 17:35:17 ike_send_notify: Notification to informational exchange ignored
Apr 18 17:35:17 ike_delete_negotiation: Start, SA = { 8668d300 e729401d - c5eba674 387f9690}, nego = 0
Apr 18 17:35:17 ike_free_negotiation_info: Start, nego = 0
Apr 18 17:35:17 ike_free_negotiation: Start, nego = 0
Apr 18 17:35:27 kmd_pm_ike_start_p1
Apr 18 17:35:27 Phase-1 negotiation already started for p1_local=ipv4(udp:500,[0..3]=2.2.2.2) p1_remote=ipv4(udp:500,[0..3]=1.1.1.9)
Apr 18 17:35:27 Phase-2 negotiation already queued for p1_local=ipv4(udp:500,[0..3]=2.2.2.2) p1_remote=ipv4(udp:500,[0..3]=1.1.1.9)
Apr 18 17:35:37 kmd_pm_ike_start_p1
Apr 18 17:35:37 Phase-1 negotiation already started for p1_local=ipv4(udp:500,[0..3]=2.2.2.2) p1_remote=ipv4(udp:500,[0..3]=1.1.1.9)
Apr 18 17:35:37 Phase-2 negotiation already queued for p1_local=ipv4(udp:500,[0..3]=2.2.2.2) p1_remote=ipv4(udp:500,[0..3]=1.1.1.9)
Apr 18 17:35:42 ike_remove_callback: Start, delete SA = { 8668d300 e729401d - c5eba674 387f9690}, nego = -1
Apr 18 17:35:42 2.2.2.2:500 (Initiator) <-> 1.1.1.9:500 { 8668d300 e729401d - c5eba674 387f9690 [-1] / 0x00000000 } IP; Connection timed out or error, calling callback
Apr 18 17:35:42 Phase-1 negotiation failed with error Timeout for p1_local=ipv4(udp:500,[0..3]=2.2.2.2) p1_remote=ipv4(udp:500,[0..3]=1.1.1.9)
Apr 18 17:35:42 Phase-2 sa_cfg lookup with local_id=ipv4_subnet(any:0,[0..7]=192.168.10.0/24), remote_id=ipv4_subnet(any:0,[0..7]=192.168.200.0/22)
Apr 18 17:35:42 Failed to match the peer proxy ids: p2_remote=ipv4_subnet(any:0,[0..7]=192.168.200.0/22) p2_local=ipv4_subnet(any:0,[0..7]=192.168.10.0/24) with the configured proxy ids: remote=ipv4_subnet(any:0,[0..7]=192.168.99.0/24) local=ipv4_subnet(any:0,[0..7]=19)
Apr 18 17:35:42 ike_delete_negotiation: Start, SA = { 8668d300 e729401d - c5eba674 387f9690}, nego = -1
Apr 18 17:35:42 jnp_ike_tunnel_table_entry_delete: Deleting tunnel_id: 6359416 from IKE tunnel table
Apr 18 17:35:42 ike_sa_delete: Start, SA = { 8668d300 e729401d - c5eba674 387f9690 }
Apr 18 17:35:42 ike_free_negotiation_isakmp: Start, nego = -1
Apr 18 17:35:42 ike_free_negotiation: Start, nego = -1
Apr 18 17:35:42 P1 freeing list PMdata c14800
Apr 18 17:35:42 P1 freeing PMdata c14400
Apr 18 17:35:42 ike_free_id_payload: Start, id type = 1
Apr 18 17:35:42 ike_free_sa: Start
Apr 18 17:35:47 kmd_pm_ike_start_p1
Apr 18 17:35:47 jnp_ike_connect: Start, remote_name = 1.1.1.9:500, local = 2.2.2.2:500 xchg = 2, flags = 00000000
Apr 18 17:35:47 ike_sa_allocate: Start, SA = { 97c1acb8 a1010fa7 - 00000000 00000000 }
Apr 18 17:35:47 ike_init_isakmp_sa: Start, remote = 1.1.1.9:500, initiator = 1
Apr 18 17:35:47 jnp_ike_connect: SA = { 97c1acb8 a1010fa7 - 00000000 00000000}, nego = -1
Apr 18 17:35:47 ike_st_o_sa_proposal: Start
Apr 18 17:35:47 NAT is enabled
 
Apr 18 17:35:47 Advertizing DPD capability
 
Apr 18 17:35:47 ike_policy_reply_isakmp_vendor_ids: Start
Apr 18 17:35:47 ike_st_o_private: Start
Apr 18 17:35:47 ike_policy_reply_private_payload_out: Start
Apr 18 17:35:47 ike_encode_packet: Start, SA = { 0x97c1acb8 a1010fa7 - 00000000 00000000 } / 00000000, nego = -1
Apr 18 17:35:47 ike_send_packet: Start, send SA = { 97c1acb8 a1010fa7 - 00000000 00000000}, nego = -1, src=2.2.2.2:500, dst = 1.1.1.9:500, routing table id = 0
Apr 18 17:35:47 ike_get_sa: Start, SA = { 97c1acb8 a1010fa7 - 5f00afc0 14e3491d } / 00000000, remote = 1.1.1.9:500
Apr 18 17:35:47 ike_sa_find: Not found SA = { 97c1acb8 a1010fa7 - 5f00afc0 14e3491d }
Apr 18 17:35:47 ike_sa_find_half: Found half SA = { 97c1acb8 a1010fa7 - 00000000 00000000 }
Apr 18 17:35:47 ike_sa_upgrade: Start, SA = { 97c1acb8 a1010fa7 - 00000000 00000000 } -> { ... - 5f00afc0 14e3491d }
Apr 18 17:35:47 ike_decode_packet: Start
Apr 18 17:35:47 ike_decode_packet: Start, SA = { 97c1acb8 a1010fa7 - 5f00afc0 14e3491d} / 00000000, nego = -1
Apr 18 17:35:47 ike_decode_payload_sa: Start
Apr 18 17:35:47 ike_decode_payload_t: Start, # trans = 1
Apr 18 17:35:47 ike_st_i_sa_value: Start
Apr 18 17:35:47 ike_st_i_cr: Start
Apr 18 17:35:47 ike_st_i_cert: Start
Apr 18 17:35:47 ike_st_i_vid: VID[0..16] = 90cb8091 3ebb696e ...
Apr 18 17:35:47 Setting natt remote version to 3

 external interface:

 

show security zones security-zone untrust 
address-book {
    address 192.168.200.0/22 192.168.200.0/22;
    address 192.168.99.0/24 192.168.99.0/24;
}
host-inbound-traffic {
    system-services {
        ssh;
        http;
        ping;
        ike;
    }
}
interfaces {
    ge-0/0/0.0;
}

 

No, ASA logs are not accessible right now, but I already send question to ASA administrator.

 

Thanks.

Message 3 of 5 (1,003 Views)
 
Reply
Distinguished Expert
Distinguished Expert
MMcD
Posts: 528
Registered: ‎07-20-2010
0

Re: Policy based VPN - Phase1

Options

‎04-19-2012 08:07 AM

Hi there,

 

It looks like there is no response from the remote gateway or the IKE packet is dropped/lost on the way:

 

Apr 18 17:35:42 Phase-1 negotiation failed with error Timeout for p1_local=ipv4(udp:500,[0..3]=2.2.2.2) p1_remote=ipv4(udp:500,[0..3]=1.1.1.9)
MMcD [JNCIS-SEC, CCNA, MCP]
____________________________________________________

[Please Mark My Solution Accepted if it Helped, Kudos are Appreciated Too]
Message 4 of 5 (995 Views)
 
Reply
zvitins
Contributor
zvitins
Posts: 119
Registered: ‎12-04-2009
0

Re: Policy based VPN - Phase1

Options

‎04-19-2012 09:18 AM

Hello,

 

I will try to get VPN logs from ASA

 

Thanks.

Message 5 of 5 (990 Views)
 
Reply
Copyright© 1999-2013 Juniper Networks, Inc. All rights reserved.