This website uses Cookies. By clicking Accept, you agree to the storing of cookies on your device to enhance your community and translation experience. Read our Privacy Policy.
Click Preferences to customize your cookie settings.
Accept
Reject
Preferences

VPN to Azure dropouts

cancel
Turn on suggestions
Auto-suggest helps you quickly narrow down your search results by suggesting possible matches as you type.
Showing results for 
Show  only  | Search instead for 
Did you mean: 

VPN to Azure dropouts

dmann2
L2 Linker

‎07-20-2016 04:24 PM

I have searched high and low for this and found a few articles regarding IKE configuration and nothing seems to fix it.

 

PAN 3020 v7.0.5. IKE 2 VPN to Azure. The VPN works but around every 50 mintues the tunnel drops out for a few minutes then re-establishes. I have tried various different IKE and IPsec settings as per advice from Palo Alto articles, Microsoft Azure articles and settings from a comment against a Palo Alto article that the commentor said worked. No joy.

 

From the Azure console there is no way of checking IPsec ettings.

 

Any help would be good.

2 people had this problem.
0 Likes Likes
35 REPLIES 35

dmann2
L2 Linker
In response to TranceforLife

‎07-26-2016 05:58 PM - edited ‎07-26-2016 06:36 PM

A bit more info for anyone watching.

It doesn't happen every time the tunnel is re-negotiated (every hour). In some cases there are no dropped packets. At various times I get the following sequence of events. The dropped packets seem to occur following these events. There is around a 10 second period of dropped packets between the event "IKEV2 IKE SA is down as determined by DPD" and the successful re-negotiation.

 

dpd.JPG

I'm not sure why it is starting a negotiation as initiator when in passive mode.

There is no setting for DPD when in "IKEV2 only mode" on the IKE Gateway.

0 Likes Likes

TranceforLife
L6 Presenter
In response to dmann2

‎07-26-2016 11:52 PM - edited ‎07-26-2016 11:59 PM

Hi,

 

DPD it is actually for IKEv1, Liveness check is a new term for IKEv2. Please disable this future:

 

liveness check.PNG

 

https://www.paloaltonetworks.com/documentation/70/pan-os/pan-os/vpns/site-to-site-vpn-concepts

 

 

Just to confirm you do have a security policy configured as  bi-directional for Azure peer. 

Good question why it is still initiating a tunnel when in passive mode.

 

Cheers

0 Likes Likes

dmann2
L2 Linker
In response to TranceforLife

‎07-27-2016 04:37 PM

I definitely have the Liveness box unchecked on the IKE gateway but when I look at the window that lists the IKE Gateways under Liveness for this gateway it has "default".

 

Your info on liveness check certainly describes what is happening according to the log entries.

 

Security policies are good.

0 Likes Likes

TranceforLife
L6 Presenter
In response to dmann2

‎07-28-2016 07:55 AM - edited ‎07-28-2016 08:07 AM

Hi,

 

Something weird  happening 🙂 When the passive mode is enabled, Palo still initiating a VPN tunnel or when Liveness check disabled it is still tear down the tunnel. I am confused ))) Please post the Ike Gateway screen shot and the output of the ikemgr.log:

 

> tail lines 200 mp-log ikemgr.log

 

Cheers

0 Likes Likes

dmann2
L2 Linker
In response to TranceforLife

‎07-28-2016 03:27 PM - edited ‎07-28-2016 03:59 PM

Yes weird.

It seems I cant attach a txt file so I''l copy the log here.Gateway.JPGGateway2.JPG

I think 3:19:42 to 3:19:58 in the first re-negotiation in this log is the time where It would drop packets.

 

2016-07-29 03:14:22 [PROTO_NOTIFY]: ====> IKEv2 CHILD SA NEGOTIATION STARTED AS INITIATOR, rekey <====
====> Initiated SA: 138.44.5.6[500]-13.75.156.231[500] message id:0x00000000 parent SN:465 <====
2016-07-29 03:19:41 [PROTO_ERR]: 465:138.44.5.6[500] - 13.75.156.231[500]:(nil):retransmission count exceeded the limit
2016-07-29 03:19:41 [INFO]: 465:138.44.5.6[500] - 13.75.156.231[500]:(nil):aborting IKEv2 SA Azure-IKE-Gateway:465
2016-07-29 03:19:41 [INFO]: SADB_DELETE ul_proto=255 src=13.75.156.231[0] dst=138.44.5.6[0] satype=ESP spi=0xBB1B49E4
2016-07-29 03:19:41 [INFO]: received PFKEY_DELETE seq=0 satype=ESP spi=0xBB1B49E4
2016-07-29 03:19:41 [PROTO_NOTIFY]: ====> IPSEC KEY DELETED <====
====> Deleted SA: 138.44.5.6[500]-13.75.156.231[500] SPI:0xBB1B49E4/0x2D0DC3C4 <====
2016-07-29 03:19:41 [INFO]: SADB_DELETE ul_proto=255 src=138.44.5.6[0] dst=13.75.156.231[0] satype=ESP spi=0x2D0DC3C4
2016-07-29 03:19:41 [INFO]: received PFKEY_DELETE seq=0 satype=ESP spi=0x2D0DC3C4
2016-07-29 03:19:41.376 +1000 IKEv2 liveness {Azure-IKE-Gateway:465-R}: DPD down, rekey vpn tunnel <Azure-IPsec-Tunnel(Azure-IKE-Gateway)>, SA state ESTABLISHED
2016-07-29 03:19:41 [INFO]: passive mode is specified for IKE gateway Azure-IKE-Gateway.
2016-07-29 03:19:42 [INFO]: keymirror del start ----------------
2016-07-29 03:19:42 [INFO]: keymirror del for gw 1, tn 1, selfSPI BB1B49E4, retcode 0.
2016-07-29 03:19:58 [PROTO_WARN]: 0:138.44.5.6[500] - 13.75.156.231[500]:0x8fe7ba0:message to a nonexistent ike_sa
2016-07-29 03:19:59 [PROTO_WARN]: 0:138.44.5.6[500] - 13.75.156.231[500]:0x8efc240:message to a nonexistent ike_sa
2016-07-29 03:20:00 [PROTO_WARN]: 0:138.44.5.6[500] - 13.75.156.231[500]:0x8f13fa0:message to a nonexistent ike_sa
2016-07-29 03:20:01 [PROTO_WARN]: 0:138.44.5.6[500] - 13.75.156.231[500]:0x8efc240:message to a nonexistent ike_sa
2016-07-29 03:20:05 [PROTO_NOTIFY]: ====> IKEv2 IKE SA NEGOTIATION STARTED AS RESPONDER, non-rekey <====
====> Initiated SA: 138.44.5.6[500]-13.75.156.231[500] SPI:8200c742bac96fe4:290a5d6bbc4c4ccf SN:466 <====
2016-07-29 03:20:05 [PROTO_WARN]: 466:138.44.5.6[500] - 13.75.156.231[500]:0x8f13fa0:ignoring unauthenticated notify payload (NAT_DETECTION_SOURCE_IP)
2016-07-29 03:20:05 [PROTO_WARN]: 466:138.44.5.6[500] - 13.75.156.231[500]:0x8f13fa0:ignoring unauthenticated notify payload (NAT_DETECTION_DESTINATION_IP)
2016-07-29 03:20:05 [PROTO_WARN]: 466:138.44.5.6[500] - 13.75.156.231[500]:0x8f13fa0:vendor id payload ignored
2016-07-29 03:20:05 [PROTO_WARN]: 466:138.44.5.6[500] - 13.75.156.231[500]:0x8f13fa0:vendor id payload ignored
2016-07-29 03:20:05 [PROTO_WARN]: 466:138.44.5.6[500] - 13.75.156.231[500]:0x8f13fa0:vendor id payload ignored
2016-07-29 03:20:05 [PROTO_WARN]: 466:138.44.5.6[500] - 13.75.156.231[500]:0x8f13fa0:vendor id payload ignored
2016-07-29 03:20:05 [INFO]: 466:138.44.5.6[500] - 13.75.156.231[500]:0x8fe64c8:authentication result: success
2016-07-29 03:20:05 [PROTO_NOTIFY]: ====> IKEv2 CHILD SA NEGOTIATION STARTED AS RESPONDER, non-rekey <====
====> Initiated SA: 138.44.5.6[500]-13.75.156.231[500] message id:0x00000001 parent SN:466 <====
2016-07-29 03:20:05 [INTERNAL_WARN]: selector Azure-IPsec-Tunnel(Azure-IKE-Gateway)_out src is ambiguous, using the first one of the expanded addresses
2016-07-29 03:20:05 [INTERNAL_WARN]: selector Azure-IPsec-Tunnel(Azure-IKE-Gateway)_out dst is ambiguous, using the first one of the expanded addresses
2016-07-29 03:20:05.294 +1000 IKEv2 TS {Azure-IKE-Gateway:466-R}: TS matching for configured selector Azure-IPsec-Tunnel(Azure-IKE-Gateway)_out 0.0.0.0[0]/0-0.0.0.0[0]/0 proto 0
2016-07-29 03:20:05.294 +1000 .. check local TS (num 2, TS0 is not specific) against selector 0:0.0.0.0[0]/0
2016-07-29 03:20:05.294 +1000 ... TS 0: ts type mismtach, selector is not IPv6
2016-07-29 03:20:05.294 +1000 ... TS 1: exact match
2016-07-29 03:20:05.294 +1000 ... result: local TS = 0.0.0.0[0]/0
2016-07-29 03:20:05.294 +1000 .. check remote TS (num 2, TS0 is not specific) against selector 0:0.0.0.0[0]/0
2016-07-29 03:20:05.294 +1000 ... TS 0: ts type mismtach, selector is not IPv6
2016-07-29 03:20:05.294 +1000 ... TS 1: exact match
2016-07-29 03:20:05.294 +1000 ... result: remote TS = 0.0.0.0[0]/0
2016-07-29 03:20:05.294 +1000 - IKEv2 TS {Azure-IKE-Gateway:466-R}: TS matching result: TS_l match(=), TS_r match(=) *
2016-07-29 03:20:05.294 +1000 *** IKEv2 TS {Azure-IKE-Gateway:466-R}: selector chosen Azure-IPsec-Tunnel(Azure-IKE-Gateway)_out: tid 1
2016-07-29 03:20:05 [INFO]: SADB_UPDATE ul_proto=255 src=13.75.156.231[500] dst=138.44.5.6[500] satype=ESP samode=tunl spi=0xA445D650 authtype=SHA1 enctype=3DES enclen=24 lifetime soft time=2965 bytes=0 hard time=3600 bytes=0
2016-07-29 03:20:05 [INFO]: SADB_ADD ul_proto=255 src=138.44.5.6[500] dst=13.75.156.231[500] satype=ESP samode=tunl spi=0x9969D73C authtype=SHA1 enctype=3DES enclen=24 lifetime soft time=3175 bytes=0 hard time=3600 bytes=0
2016-07-29 03:20:05.294 +1000 sadb ts: port 0:65535 IP 0.0.0.0->255.255.255.255 proto:0 len:16
2016-07-29 03:20:05.294 +1000 sadb ts: port 0:65535 IP 0.0.0.0->255.255.255.255 proto:0 len:16
2016-07-29 03:20:05 [PROTO_NOTIFY]: ====> IPSEC KEY INSTALLATION SUCCEEDED <====
====> Installed SA: 138.44.5.6[500]-13.75.156.231[500] SPI:0xA445D650/0x9969D73C lifetime 3600 Sec lifesize unlimited <====
2016-07-29 03:20:05 [PROTO_NOTIFY]: ====> IKEv2 CHILD SA NEGOTIATION SUCCEEDED AS RESPONDER, non-rekey <====
====> Established SA: 138.44.5.6[500]-13.75.156.231[500] message id:0x00000001, SPI:0xA445D650/0x9969D73C parent SN:466 <====
2016-07-29 03:20:05 [PROTO_NOTIFY]: ====> IKEv2 IKE SA NEGOTIATION SUCCEEDED AS RESPONDER, non-rekey <====
====> Established SA: 138.44.5.6[500]-13.75.156.231[500] SPI:8200c742bac96fe4:290a5d6bbc4c4ccf SN:466 lifetime 28800 Sec <====
2016-07-29 03:20:05 [INFO]: keymirror add start ++++++++++++++++
2016-07-29 03:20:05 [INFO]: keymirror add for gw 0x1, tn 1, selfSPI A445D650, retcode 0.
2016-07-29 04:12:59 [PROTO_NOTIFY]: ====> IKEv2 CHILD SA NEGOTIATION STARTED AS INITIATOR, rekey <====
====> Initiated SA: 138.44.5.6[500]-13.75.156.231[500] message id:0x00000000 parent SN:466 <====
2016-07-29 04:15:53 [PROTO_NOTIFY]: ====> IKEv2 CHILD SA NEGOTIATION STARTED AS RESPONDER, rekey <====
====> Initiated SA: 138.44.5.6[500]-13.75.156.231[500] message id:0x0000000C parent SN:466 <====
2016-07-29 04:15:53 [INTERNAL_WARN]: selector Azure-IPsec-Tunnel(Azure-IKE-Gateway)_out src is ambiguous, using the first one of the expanded addresses
2016-07-29 04:15:53 [INTERNAL_WARN]: selector Azure-IPsec-Tunnel(Azure-IKE-Gateway)_out dst is ambiguous, using the first one of the expanded addresses
2016-07-29 04:15:53.175 +1000 IKEv2 TS {Azure-IKE-Gateway:466-R}: TS matching for configured selector Azure-IPsec-Tunnel(Azure-IKE-Gateway)_out 0.0.0.0[0]/0-0.0.0.0[0]/0 proto 0
2016-07-29 04:15:53.175 +1000 .. check local TS (num 2, TS0 is not specific) against selector 0:0.0.0.0[0]/0
2016-07-29 04:15:53.175 +1000 ... TS 0: ts type mismtach, selector is not IPv6
2016-07-29 04:15:53.175 +1000 ... TS 1: exact match
2016-07-29 04:15:53.175 +1000 ... result: local TS = 0.0.0.0[0]/0
2016-07-29 04:15:53.175 +1000 .. check remote TS (num 2, TS0 is not specific) against selector 0:0.0.0.0[0]/0
2016-07-29 04:15:53.175 +1000 ... TS 0: ts type mismtach, selector is not IPv6
2016-07-29 04:15:53.175 +1000 ... TS 1: exact match
2016-07-29 04:15:53.175 +1000 ... result: remote TS = 0.0.0.0[0]/0
2016-07-29 04:15:53.175 +1000 - IKEv2 TS {Azure-IKE-Gateway:466-R}: TS matching result: TS_l match(=), TS_r match(=) *
2016-07-29 04:15:53.175 +1000 *** IKEv2 TS {Azure-IKE-Gateway:466-R}: selector chosen Azure-IPsec-Tunnel(Azure-IKE-Gateway)_out: tid 1
2016-07-29 04:15:53 [INFO]: SADB_UPDATE ul_proto=255 src=13.75.156.231[500] dst=138.44.5.6[500] satype=ESP samode=tunl spi=0xB9AC02C2 authtype=SHA1 enctype=3DES enclen=24 lifetime soft time=3140 bytes=0 hard time=3600 bytes=0
2016-07-29 04:15:53 [INFO]: SADB_ADD ul_proto=255 src=138.44.5.6[500] dst=13.75.156.231[500] satype=ESP samode=tunl spi=0x946BF430 authtype=SHA1 enctype=3DES enclen=24 lifetime soft time=3177 bytes=0 hard time=3600 bytes=0
2016-07-29 04:15:53.175 +1000 sadb ts: port 0:65535 IP 0.0.0.0->255.255.255.255 proto:0 len:16
2016-07-29 04:15:53.175 +1000 sadb ts: port 0:65535 IP 0.0.0.0->255.255.255.255 proto:0 len:16
2016-07-29 04:15:53 [PROTO_NOTIFY]: ====> IPSEC KEY INSTALLATION SUCCEEDED <====
====> Installed SA: 138.44.5.6[500]-13.75.156.231[500] SPI:0xB9AC02C2/0x946BF430 lifetime 3600 Sec lifesize unlimited <====
2016-07-29 04:15:53 [PROTO_NOTIFY]: ====> IKEv2 CHILD SA NEGOTIATION SUCCEEDED AS RESPONDER, rekey <====
====> Established SA: 138.44.5.6[500]-13.75.156.231[500] message id:0x0000000C, SPI:0xB9AC02C2/0x946BF430 parent SN:466 <====
2016-07-29 04:15:53 [INFO]: keymirror add start ++++++++++++++++
2016-07-29 04:15:53 [INFO]: keymirror add for gw 0x1, tn 1, selfSPI B9AC02C2, retcode 0.
2016-07-29 04:15:53 [INFO]: 466:138.44.5.6[500] - 13.75.156.231[500]:(nil):delete proto ESP spi 0x9969D73C
2016-07-29 04:15:53 [PROTO_NOTIFY]: ====> IPSEC KEY DELETED <====
====> Deleted SA: 138.44.5.6[500]-13.75.156.231[500] SPI:0xA445D650/0x9969D73C <====
2016-07-29 04:15:53 [INFO]: SADB_DELETE ul_proto=255 src=138.44.5.6[0] dst=13.75.156.231[0] satype=ESP spi=0x9969D73C
2016-07-29 04:15:53 [INFO]: received PFKEY_DELETE seq=0 satype=ESP spi=0x9969D73C
2016-07-29 04:15:53 [INFO]: SADB_DELETE ul_proto=255 src=13.75.156.231[0] dst=138.44.5.6[0] satype=ESP spi=0xA445D650
2016-07-29 04:15:53 [INFO]: received PFKEY_DELETE seq=0 satype=ESP spi=0xA445D650
2016-07-29 04:15:53 [INFO]: keymirror del start ----------------
2016-07-29 04:15:53 [INFO]: keymirror del for gw 1, tn 1, selfSPI A445D650, retcode 0.
2016-07-29 04:16:10 [PROTO_ERR]: 466:138.44.5.6[500] - 13.75.156.231[500]:(nil):received Notify payload protocol 0 type 12345
2016-07-29 04:16:10 [PROTO_NOTIFY]: ====> IKEv2 CHILD SA NEGOTIATION FAILED AS INITIATOR, rekey <====
====> Failed SA: 138.44.5.6[500]-13.75.156.231[500] message id:0x00000000 parent SN:466 <==== Error code 111
2016-07-29 05:08:49 [PROTO_NOTIFY]: ====> IKEv2 CHILD SA NEGOTIATION STARTED AS INITIATOR, rekey <====
====> Initiated SA: 138.44.5.6[500]-13.75.156.231[500] message id:0x00000000 parent SN:466 <====
2016-07-29 05:11:38 [PROTO_NOTIFY]: ====> IKEv2 CHILD SA NEGOTIATION STARTED AS RESPONDER, rekey <====
====> Initiated SA: 138.44.5.6[500]-13.75.156.231[500] message id:0x00000012 parent SN:466 <====
2016-07-29 05:11:38 [INTERNAL_WARN]: selector Azure-IPsec-Tunnel(Azure-IKE-Gateway)_out src is ambiguous, using the first one of the expanded addresses
2016-07-29 05:11:38 [INTERNAL_WARN]: selector Azure-IPsec-Tunnel(Azure-IKE-Gateway)_out dst is ambiguous, using the first one of the expanded addresses
2016-07-29 05:11:38.501 +1000 IKEv2 TS {Azure-IKE-Gateway:466-R}: TS matching for configured selector Azure-IPsec-Tunnel(Azure-IKE-Gateway)_out 0.0.0.0[0]/0-0.0.0.0[0]/0 proto 0
2016-07-29 05:11:38.501 +1000 .. check local TS (num 2, TS0 is not specific) against selector 0:0.0.0.0[0]/0
2016-07-29 05:11:38.501 +1000 ... TS 0: ts type mismtach, selector is not IPv6
2016-07-29 05:11:38.501 +1000 ... TS 1: exact match
2016-07-29 05:11:38.501 +1000 ... result: local TS = 0.0.0.0[0]/0
2016-07-29 05:11:38.501 +1000 .. check remote TS (num 2, TS0 is not specific) against selector 0:0.0.0.0[0]/0
2016-07-29 05:11:38.501 +1000 ... TS 0: ts type mismtach, selector is not IPv6
2016-07-29 05:11:38.501 +1000 ... TS 1: exact match
2016-07-29 05:11:38.501 +1000 ... result: remote TS = 0.0.0.0[0]/0
2016-07-29 05:11:38.501 +1000 - IKEv2 TS {Azure-IKE-Gateway:466-R}: TS matching result: TS_l match(=), TS_r match(=) *
2016-07-29 05:11:38.501 +1000 *** IKEv2 TS {Azure-IKE-Gateway:466-R}: selector chosen Azure-IPsec-Tunnel(Azure-IKE-Gateway)_out: tid 1
2016-07-29 05:11:38 [INFO]: SADB_UPDATE ul_proto=255 src=13.75.156.231[500] dst=138.44.5.6[500] satype=ESP samode=tunl spi=0xF30D6381 authtype=SHA1 enctype=3DES enclen=24 lifetime soft time=3203 bytes=0 hard time=3600 bytes=0
2016-07-29 05:11:38 [INFO]: SADB_ADD ul_proto=255 src=138.44.5.6[500] dst=13.75.156.231[500] satype=ESP samode=tunl spi=0xAE2BA4DC authtype=SHA1 enctype=3DES enclen=24 lifetime soft time=2913 bytes=0 hard time=3600 bytes=0
2016-07-29 05:11:38.501 +1000 sadb ts: port 0:65535 IP 0.0.0.0->255.255.255.255 proto:0 len:16
2016-07-29 05:11:38.501 +1000 sadb ts: port 0:65535 IP 0.0.0.0->255.255.255.255 proto:0 len:16
2016-07-29 05:11:38 [PROTO_NOTIFY]: ====> IPSEC KEY INSTALLATION SUCCEEDED <====
====> Installed SA: 138.44.5.6[500]-13.75.156.231[500] SPI:0xF30D6381/0xAE2BA4DC lifetime 3600 Sec lifesize unlimited <====
2016-07-29 05:11:38 [PROTO_NOTIFY]: ====> IKEv2 CHILD SA NEGOTIATION SUCCEEDED AS RESPONDER, rekey <====
====> Established SA: 138.44.5.6[500]-13.75.156.231[500] message id:0x00000012, SPI:0xF30D6381/0xAE2BA4DC parent SN:466 <====
2016-07-29 05:11:38 [INFO]: keymirror add start ++++++++++++++++
2016-07-29 05:11:38 [INFO]: keymirror add for gw 0x1, tn 1, selfSPI F30D6381, retcode 0.
2016-07-29 05:11:38 [INFO]: 466:138.44.5.6[500] - 13.75.156.231[500]:(nil):delete proto ESP spi 0x946BF430
2016-07-29 05:11:38 [PROTO_NOTIFY]: ====> IPSEC KEY DELETED <====
====> Deleted SA: 138.44.5.6[500]-13.75.156.231[500] SPI:0xB9AC02C2/0x946BF430 <====
2016-07-29 05:11:38 [INFO]: SADB_DELETE ul_proto=255 src=138.44.5.6[0] dst=13.75.156.231[0] satype=ESP spi=0x946BF430
2016-07-29 05:11:38 [INFO]: received PFKEY_DELETE seq=0 satype=ESP spi=0x946BF430
2016-07-29 05:11:38 [INFO]: SADB_DELETE ul_proto=255 src=13.75.156.231[0] dst=138.44.5.6[0] satype=ESP spi=0xB9AC02C2
2016-07-29 05:11:38 [INFO]: received PFKEY_DELETE seq=0 satype=ESP spi=0xB9AC02C2
2016-07-29 05:11:38 [INFO]: keymirror del start ----------------
2016-07-29 05:11:38 [INFO]: keymirror del for gw 1, tn 1, selfSPI B9AC02C2, retcode 0.
2016-07-29 05:12:00 [PROTO_ERR]: 466:138.44.5.6[500] - 13.75.156.231[500]:(nil):received Notify payload protocol 0 type 12345
2016-07-29 05:12:00 [PROTO_NOTIFY]: ====> IKEv2 CHILD SA NEGOTIATION FAILED AS INITIATOR, rekey <====
====> Failed SA: 138.44.5.6[500]-13.75.156.231[500] message id:0x00000001 parent SN:466 <==== Error code 111
2016-07-29 06:00:11 [PROTO_NOTIFY]: ====> IKEv2 CHILD SA NEGOTIATION STARTED AS INITIATOR, rekey <====
====> Initiated SA: 138.44.5.6[500]-13.75.156.231[500] message id:0x00000000 parent SN:466 <====
2016-07-29 06:00:11 [INFO]: SADB_UPDATE ul_proto=255 src=13.75.156.231[500] dst=138.44.5.6[500] satype=ESP samode=tunl spi=0xD8014654 authtype=SHA1 enctype=3DES enclen=24 lifetime soft time=3230 bytes=0 hard time=3600 bytes=0
2016-07-29 06:00:11 [INFO]: SADB_ADD ul_proto=255 src=138.44.5.6[500] dst=13.75.156.231[500] satype=ESP samode=tunl spi=0xFF5EF270 authtype=SHA1 enctype=3DES enclen=24 lifetime soft time=3009 bytes=0 hard time=3600 bytes=0
2016-07-29 06:00:11.389 +1000 sadb ts: port 0:65535 IP 0.0.0.0->255.255.255.255 proto:0 len:16
2016-07-29 06:00:11.389 +1000 sadb ts: port 0:65535 IP 0.0.0.0->255.255.255.255 proto:0 len:16
2016-07-29 06:00:11 [PROTO_NOTIFY]: ====> IPSEC KEY INSTALLATION SUCCEEDED <====
====> Installed SA: 138.44.5.6[500]-13.75.156.231[500] SPI:0xD8014654/0xFF5EF270 lifetime 3600 Sec lifesize unlimited <====
2016-07-29 06:00:11 [PROTO_NOTIFY]: ====> IKEv2 CHILD SA NEGOTIATION SUCCEEDED AS INITIATOR, rekey <====
====> Established SA: 138.44.5.6[500]-13.75.156.231[500] message id:0x00000002, SPI:0xD8014654/0xFF5EF270 parent SN:466 <====
2016-07-29 06:00:11 [INFO]: keymirror add start ++++++++++++++++
2016-07-29 06:00:11 [INFO]: keymirror add for gw 0x1, tn 1, selfSPI D8014654, retcode 0.
2016-07-29 06:00:11 [INFO]: keymirror del start ----------------
2016-07-29 06:00:11 [INFO]: keymirror del for gw 1, tn 1, selfSPI F30D6381, retcode 0.
2016-07-29 06:00:11 [INFO]: SADB_DELETE ul_proto=255 src=13.75.156.231[0] dst=138.44.5.6[0] satype=ESP spi=0xF30D6381
2016-07-29 06:00:11 [INFO]: received PFKEY_DELETE seq=0 satype=ESP spi=0xF30D6381
2016-07-29 06:00:11 [PROTO_NOTIFY]: ====> IPSEC KEY DELETED <====
====> Deleted SA: 138.44.5.6[500]-13.75.156.231[500] SPI:0xF30D6381/0xAE2BA4DC <====
2016-07-29 06:00:11 [INFO]: SADB_DELETE ul_proto=255 src=138.44.5.6[0] dst=13.75.156.231[0] satype=ESP spi=0xAE2BA4DC
2016-07-29 06:00:11 [INFO]: received PFKEY_DELETE seq=0 satype=ESP spi=0xAE2BA4DC
2016-07-29 06:05:11 [INFO]: 466:138.44.5.6[500] - 13.75.156.231[500]:(nil):delete proto ESP spi 0xAE2BA4DC
2016-07-29 06:05:11 [PROTO_WARN]: 466:138.44.5.6[500] - 13.75.156.231[500]:(nil):can't find sa for proto ESP spi 0xAE2BA4DC
2016-07-29 06:11:07 [PROTO_NOTIFY]: ====> IKEv2 IKE SA NEGOTIATION STARTED AS RESPONDER, rekey <====
====> Initiated SA: 138.44.5.6[500]-13.75.156.231[500] SPI:7b6ad57db0e66afd:af6028d3c14c9faa SN:467 <====
2016-07-29 06:11:07.404 +1000 >>> IKEv2 rekey {Azure-IKE-Gateway:467-R}: adopt children SA from IKE SA 466
2016-07-29 06:11:07.404 +1000 IKEv2 rekey {Azure-IKE-Gateway:467-R}: child SA 196717 is adopted, tid 1, state MATURE
2016-07-29 06:11:07 [PROTO_NOTIFY]: ====> IKEv2 IKE SA NEGOTIATION SUCCEEDED AS RESPONDER, rekey <====
====> Established SA: 138.44.5.6[500]-13.75.156.231[500] SPI:7b6ad57db0e66afd:af6028d3c14c9faa SN:467 lifetime 28800 Sec <====
2016-07-29 06:11:07 [INFO]: 466:138.44.5.6[500] - 13.75.156.231[500]:(nil):received DELETE IKE_SA
2016-07-29 06:11:07.420 +1000 IKEv2 {Azure-IKE-Gateway:466-R}: received DELETE IKE_SA, SA state ESTABLISHED, SPI 8200c742bac96fe4:290a5d6bbc4c4ccf
2016-07-29 06:11:07 [INFO]: 466:138.44.5.6[500] - 13.75.156.231[500]:(nil):aborting IKEv2 SA Azure-IKE-Gateway:466
2016-07-29 06:50:20 [PROTO_NOTIFY]: ====> IKEv2 CHILD SA NEGOTIATION STARTED AS INITIATOR, rekey <====
====> Initiated SA: 138.44.5.6[500]-13.75.156.231[500] message id:0x00000000 parent SN:467 <====
2016-07-29 06:50:20 [INFO]: SADB_UPDATE ul_proto=255 src=13.75.156.231[500] dst=138.44.5.6[500] satype=ESP samode=tunl spi=0xD4531654 authtype=SHA1 enctype=3DES enclen=24 lifetime soft time=3200 bytes=0 hard time=3600 bytes=0
2016-07-29 06:50:20 [INFO]: SADB_ADD ul_proto=255 src=138.44.5.6[500] dst=13.75.156.231[500] satype=ESP samode=tunl spi=0x58A1452E authtype=SHA1 enctype=3DES enclen=24 lifetime soft time=2997 bytes=0 hard time=3600 bytes=0
2016-07-29 06:50:20.392 +1000 sadb ts: port 0:65535 IP 0.0.0.0->255.255.255.255 proto:0 len:16
2016-07-29 06:50:20.392 +1000 sadb ts: port 0:65535 IP 0.0.0.0->255.255.255.255 proto:0 len:16
2016-07-29 06:50:20 [PROTO_NOTIFY]: ====> IPSEC KEY INSTALLATION SUCCEEDED <====
====> Installed SA: 138.44.5.6[500]-13.75.156.231[500] SPI:0xD4531654/0x58A1452E lifetime 3600 Sec lifesize unlimited <====
2016-07-29 06:50:20 [PROTO_NOTIFY]: ====> IKEv2 CHILD SA NEGOTIATION SUCCEEDED AS INITIATOR, rekey <====
====> Established SA: 138.44.5.6[500]-13.75.156.231[500] message id:0x00000000, SPI:0xD4531654/0x58A1452E parent SN:467 <====
2016-07-29 06:50:20 [INFO]: keymirror add start ++++++++++++++++
2016-07-29 06:50:20 [INFO]: keymirror add for gw 0x1, tn 1, selfSPI D4531654, retcode 0.
2016-07-29 06:50:21 [INFO]: keymirror del start ----------------
2016-07-29 06:50:21 [INFO]: keymirror del for gw 1, tn 1, selfSPI D8014654, retcode 0.
2016-07-29 06:50:21 [INFO]: SADB_DELETE ul_proto=255 src=13.75.156.231[0] dst=138.44.5.6[0] satype=ESP spi=0xD8014654
2016-07-29 06:50:21 [INFO]: received PFKEY_DELETE seq=0 satype=ESP spi=0xD8014654
2016-07-29 06:50:21 [PROTO_NOTIFY]: ====> IPSEC KEY DELETED <====
====> Deleted SA: 138.44.5.6[500]-13.75.156.231[500] SPI:0xD8014654/0xFF5EF270 <====
2016-07-29 06:50:21 [INFO]: SADB_DELETE ul_proto=255 src=138.44.5.6[0] dst=13.75.156.231[0] satype=ESP spi=0xFF5EF270
2016-07-29 06:50:21 [INFO]: received PFKEY_DELETE seq=0 satype=ESP spi=0xFF5EF270
2016-07-29 06:55:19 [INFO]: 467:138.44.5.6[500] - 13.75.156.231[500]:(nil):delete proto ESP spi 0xFF5EF270
2016-07-29 06:55:19 [PROTO_WARN]: 467:138.44.5.6[500] - 13.75.156.231[500]:(nil):can't find sa for proto ESP spi 0xFF5EF270
2016-07-29 07:40:17 [PROTO_NOTIFY]: ====> IKEv2 CHILD SA NEGOTIATION STARTED AS INITIATOR, rekey <====
====> Initiated SA: 138.44.5.6[500]-13.75.156.231[500] message id:0x00000000 parent SN:467 <====
2016-07-29 07:40:17 [INFO]: SADB_UPDATE ul_proto=255 src=13.75.156.231[500] dst=138.44.5.6[500] satype=ESP samode=tunl spi=0xC9083D8E authtype=SHA1 enctype=3DES enclen=24 lifetime soft time=3058 bytes=0 hard time=3600 bytes=0
2016-07-29 07:40:17 [INFO]: SADB_ADD ul_proto=255 src=138.44.5.6[500] dst=13.75.156.231[500] satype=ESP samode=tunl spi=0xDAA11134 authtype=SHA1 enctype=3DES enclen=24 lifetime soft time=2893 bytes=0 hard time=3600 bytes=0
2016-07-29 07:40:17.390 +1000 sadb ts: port 0:65535 IP 0.0.0.0->255.255.255.255 proto:0 len:16
2016-07-29 07:40:17.390 +1000 sadb ts: port 0:65535 IP 0.0.0.0->255.255.255.255 proto:0 len:16
2016-07-29 07:40:17 [PROTO_NOTIFY]: ====> IPSEC KEY INSTALLATION SUCCEEDED <====
====> Installed SA: 138.44.5.6[500]-13.75.156.231[500] SPI:0xC9083D8E/0xDAA11134 lifetime 3600 Sec lifesize unlimited <====
2016-07-29 07:40:17 [PROTO_NOTIFY]: ====> IKEv2 CHILD SA NEGOTIATION SUCCEEDED AS INITIATOR, rekey <====
====> Established SA: 138.44.5.6[500]-13.75.156.231[500] message id:0x00000001, SPI:0xC9083D8E/0xDAA11134 parent SN:467 <====
2016-07-29 07:40:17 [INFO]: keymirror add start ++++++++++++++++
2016-07-29 07:40:17 [INFO]: keymirror add for gw 0x1, tn 1, selfSPI C9083D8E, retcode 0.
2016-07-29 07:40:17 [INFO]: keymirror del start ----------------
2016-07-29 07:40:17 [INFO]: keymirror del for gw 1, tn 1, selfSPI D4531654, retcode 0.
2016-07-29 07:40:17 [INFO]: SADB_DELETE ul_proto=255 src=13.75.156.231[0] dst=138.44.5.6[0] satype=ESP spi=0xD4531654
2016-07-29 07:40:17 [INFO]: received PFKEY_DELETE seq=0 satype=ESP spi=0xD4531654
2016-07-29 07:40:17 [PROTO_NOTIFY]: ====> IPSEC KEY DELETED <====
====> Deleted SA: 138.44.5.6[500]-13.75.156.231[500] SPI:0xD4531654/0x58A1452E <====
2016-07-29 07:40:17 [INFO]: SADB_DELETE ul_proto=255 src=138.44.5.6[0] dst=13.75.156.231[0] satype=ESP spi=0x58A1452E
2016-07-29 07:40:17 [INFO]: received PFKEY_DELETE seq=0 satype=ESP spi=0x58A1452E
2016-07-29 07:45:14 [INFO]: 467:138.44.5.6[500] - 13.75.156.231[500]:(nil):delete proto ESP spi 0x58A1452E
2016-07-29 07:45:14 [PROTO_WARN]: 467:138.44.5.6[500] - 13.75.156.231[500]:(nil):can't find sa for proto ESP spi 0x58A1452E

0 Likes Likes

TranceforLife
L6 Presenter
In response to dmann2

‎07-28-2016 04:09 PM - edited ‎07-28-2016 04:14 PM

Hmm. For IKE SA  you are responder always. Fos CHILD_SA not. My logs suggest that it is  always responder for both tunnels. Cannot understand why it is still trying to initiate a tunnel when in passive mode. Same thing with DPD/Liveness check. Are you able to log a ticket with Palo?

0 Likes Likes

dmann2
L2 Linker
In response to TranceforLife

‎07-28-2016 04:50 PM

Trance..

 

I have Premium Partner Support so have logged a case with the ASC.

 

Thanks for your time on this.

0 Likes Likes

TranceforLife
L6 Presenter
In response to dmann2

‎07-28-2016 11:46 PM

Hi,

 

No problems. Could you please keep me posted. 

 

Thanks,

0 Likes Likes

TranceforLife
L6 Presenter
In response to dmann2

‎08-01-2016 08:55 AM

Hi,

 

Any news from Palo on this. Please, could you let me know a solution.

 

Regards,

Myky

0 Likes Likes

dmann2
L2 Linker
In response to TranceforLife

‎08-01-2016 03:26 PM

Haven't heard anything yet. Have supplied them with the Tech Support output for analysis.

0 Likes Likes

TranceforLife
L6 Presenter
In response to dmann2

‎08-02-2016 03:05 AM

Hi,

 

No worries. Awaiting for your update. Our VPN tunnel still ok. Just curious what is happening with your case/situation.

 

Cheers,

Myky

0 Likes Likes

dmann2
L2 Linker
In response to TranceforLife

‎08-02-2016 03:26 PM

Had a Go-To session with Palo Alto yesterday. By the logs it seems to be fixed. Will monitor today.

 

There was a couple of points to come out of it.

 

  • Even if the IKE gateway is passive phase 2 can be initiated by the Palo Alto device.
  • There was some sort of DPD or Liveness packets happening even though liveness disabled. I even disabled it via CLI in IKE v1 settings.
  • I should have had a better look at my policies as you suggested as it was policy that was blocking the DPD packets.

I will keep on eye on it today but looking at the logs overnight the key deletion determined by DPD has stopped.

TranceforLife
L6 Presenter
In response to dmann2

‎08-02-2016 11:51 PM

Hi,

 

This is what I thought: for phase 1 you are responder but for phase 2 could be both even in the passive mode. 

Thank you for sharing this info, very valuable.

 

All the best,

Myky

0 Likes Likes

dmann2
L2 Linker
In response to TranceforLife

‎08-04-2016 06:34 PM

More follow up. My PAN started dropping packets for about 5 minutes every 50 or so minutes.

 

From support (bold is supports comments):

- At 2016/08/03 23:08:15 IPSec key installed. Installed SA: 138.44.5.6[500]-13.75.156.231[500] SPI:0x9blahblah lifetime 3600 Sec lifesize unlimited.
- At 2016/08/04 00:00:38 IKEv2 child SA negotiation is started as initiator, rekey. Initiated SA: 138.44.5.6[500]-13.75.156.231[500] message id:0x00000000. Re-key happens here where PAN is the initiator.
- At 2016/08/04 00:00:38 IPSec key installed. Installed SA: 138.44.5.6[500]-13.75.156.231[500] SPI:0xC9blahblah lifetime 3600 Sec lifesize unlimited. New set of SPI were installed
- At 2016/08/04 00:00:39 IPSec key deleted. Deleted SA: 138.44.5.6[500]-13.75.156.231[500] SPI:0x9blahblah. Old SPI is deleted on PAN
- At 2016/08/04 00:05:15 IKEv2 IPSec SA delete message received from peer. Protocol ESP, Num of SPI: 1. After 5 mins then we are getting the SA delete message acknowledgement from MS Azure 13.75.156.231

 

I was advised to extend the phase2 lifetime another 1800 seconds to be outside the current 3600 to ensure Azure is the initiator, This is despite what Palo Alto's recommendations for Azure are.

 

Will wait and see.

0 Likes Likes

TranceforLife
L6 Presenter
In response to dmann2

‎08-04-2016 11:10 PM

Hi,

 

Thank you for the info. Usually, lifetime will be negotiated to the lower number ( for instance PA =  4000 Azure = 3600 lifetime is going to be 3600). Please try it

0 Likes Likes
  • 24251 Views
  • 35 replies
  • 0 Likes
Like what you see?

Show your appreciation!

Click Like if a post is helpful to you or if you just want to show your support.

Click Accept as Solution to acknowledge that the answer to your question has been provided.

The button appears next to the replies on topics you’ve started. The member who gave the solution and all future visitors to this topic will appreciate it!

These simple actions take just seconds of your time, but go a long way in showing appreciation for community members and the LIVEcommunity as a whole!

The LIVEcommunity thanks you for your participation!

LEGAL NOTICES
RESOURCES
Khoros awards 2022
Copyright 2007 - 2024 - Palo Alto Networks