Azure s2s between PA keeps restarting after 5min

[Janusz]

Hello,

i couldn't find answer to this anywhere even thought i found similiar problems. I followed this guide on how to set up vpn between Azure cloud and PA device: https://live.paloaltonetworks.com/t5/Integration-Articles/Configuring-IKEv2-VPN-for-Microsoft-Azure-...

Everything seems to be working except for one thing that makes it pretty much not working at all :): the tunnel goes down every 5min. Then it re-establish and works for next 5min and then it repeats. I found in logs that i am getting: IKEv2 IPSec SA delete message received from peer. Protocol ESP, Num of SPI: 1 

Any ideas what might be the cause of the problem? I do not feel like this is about missmatching anything on both ends because the tunnel would not come up in the first place, right?

PANOS is 7.1.0.

[TranceforLife]

Hello,

Azure s2s is always interesting. ok could you please post this output:

> tail lines 50 mp-log ikemgr.log

Make sure PA in the "passive mode" for the IKE Gateway configuration. 

[OtakarKlier]

Hello,

What are the seetings for the 'Key lifetime' and/or 'Lifesize' set? Perhapes they are set too low and the tunnel keeps rebuilding?

Just a thought.

Regards,

[Janusz]

---

@TranceforLife wrote:

Hello,

Azure s2s is always interesting. ok could you please post this output:

> tail lines 50 mp-log ikemgr.log

Make sure PA in the "passive mode" for the IKE Gateway configuration. 

---

Thank you for your reply.

Gateway is in passive mode, i found it before to check it this way, it did not help.

Anyway those are log files you asked for. I switched ip addresses for my and azure.

tail lines 100 mp-log ikemgr.log
2016-09-28 12:54:05 [INFO]: keymirror add start ++++++++++++++++
2016-09-28 12:54:05 [INFO]: keymirror add for gw 0x6, tn 10, selfSPI FEEA8C49, retcode 0.
2016-09-28 12:59:06 [INFO]: 420:MyIP[500] - AzureIP[500]:(nil):delete proto ESP spi 0xEB79E8FA
2016-09-28 12:59:06 [PROTO_NOTIFY]: ====> IPSEC KEY DELETED <====
====> Deleted SA: MyIP[500]-AzureIP[500] SPI:0xFEEA8C49/0xEB79E8FA <====
2016-09-28 12:59:06 [INFO]: SADB_DELETE ul_proto=255 src=MyIP[0] dst=AzureIP[0] satype=ESP spi=0xEB79E8FA
2016-09-28 12:59:06 [INFO]: received PFKEY_DELETE seq=0 satype=ESP spi=0xEB79E8FA
2016-09-28 12:59:06 [INFO]: SADB_DELETE ul_proto=255 src=AzureIP[0] dst=MyIP[0] satype=ESP spi=0xFEEA8C49
2016-09-28 12:59:06 [INFO]: received PFKEY_DELETE seq=0 satype=ESP spi=0xFEEA8C49
2016-09-28 12:59:06 [INFO]: 420:MyIP[500] - AzureIP[500]:(nil):received DELETE IKE_SA
2016-09-28 12:59:06.147 +0200 IKEv2  {AzureDomain:420-R}: received DELETE IKE_SA, SA state ESTABLISHED, SPI 123ef55fe13e6d94:4b90ec206f36da0f
2016-09-28 12:59:06 [INFO]: 420:MyIP[500] - AzureIP[500]:(nil):aborting IKEv2 SA AzureDomain:420
2016-09-28 12:59:06 [INFO]: keymirror del start ----------------
2016-09-28 12:59:06 [INFO]: keymirror del for gw 6, tn 10, selfSPI FEEA8C49, retcode 0.
2016-09-28 13:00:05 [PROTO_NOTIFY]: ====> IKEv2 IKE SA NEGOTIATION STARTED AS RESPONDER, non-rekey <====
====> Initiated SA: MyIP[500]-AzureIP[500] SPI:013bab07e54a9de1:05be6400222303ed SN:421 <====
2016-09-28 13:00:05 [PROTO_WARN]: 421:MyIP[500] - AzureIP[500]:0x10165520:ignoring unauthenticated notify payload (NAT_DETECTION_SOURCE_IP)
2016-09-28 13:00:05 [PROTO_WARN]: 421:MyIP[500] - AzureIP[500]:0x10165520:ignoring unauthenticated notify payload (NAT_DETECTION_DESTINATION_IP)
2016-09-28 13:00:05 [PROTO_WARN]: 421:MyIP[500] - AzureIP[500]:0x10165520:vendor id payload ignored
2016-09-28 13:00:05 [PROTO_WARN]: 421:MyIP[500] - AzureIP[500]:0x10165520:vendor id payload ignored
2016-09-28 13:00:05 [PROTO_WARN]: 421:MyIP[500] - AzureIP[500]:0x10165520:vendor id payload ignored
2016-09-28 13:00:05 [PROTO_WARN]: 421:MyIP[500] - AzureIP[500]:0x10165520:vendor id payload ignored
2016-09-28 13:00:05 [INFO]: 421:MyIP[500] - AzureIP[500]:0x102d7f90:authentication result: success
2016-09-28 13:00:05 [PROTO_NOTIFY]: ====> IKEv2 CHILD SA NEGOTIATION STARTED AS RESPONDER, non-rekey <====
====> Initiated SA: MyIP[500]-AzureIP[500] message id:0x00000001 parent SN:421 <====
2016-09-28 13:00:05.871 +0200  IKEv2 TS {AzureDomain:421-R}: TS matching for configured selector Azure:All(AzureDomain)_out 192.168.9.0[0]/24-192.168.11.0[0]/24 proto 0
2016-09-28 13:00:05.871 +0200 .. check local TS (num 2, TS0 is not specific) against selector 0:192.168.9.0[0]/24
2016-09-28 13:00:05.871 +0200 ... TS 0: ts type mismtach, selector is not IPv6
2016-09-28 13:00:05.871 +0200 ... TS 1: 0.0.0.0->255.255.255.255[0-65535](ts) is narrowed to the selector
2016-09-28 13:00:05.871 +0200 ... result: local TS > 192.168.9.0[0]/24
2016-09-28 13:00:05.871 +0200 .. check remote TS (num 2, TS0 is not specific) against selector 0:192.168.11.0[0]/24
2016-09-28 13:00:05.871 +0200 ... TS 0: ts type mismtach, selector is not IPv6
2016-09-28 13:00:05.871 +0200 ... TS 1: 0.0.0.0->255.255.255.255[0-65535](ts) is narrowed to the selector
2016-09-28 13:00:05.871 +0200 ... result: remote TS > 192.168.11.0[0]/24
2016-09-28 13:00:05.871 +0200 - IKEv2 TS {AzureDomain:421-R}: TS matching result: TS_l match(>), TS_r match(>) *
2016-09-28 13:00:05.871 +0200 *** IKEv2 TS {AzureDomain:421-R}: selector chosen Azure:All(AzureDomain)_out: tid 10
2016-09-28 13:00:05 [INFO]: SADB_UPDATE ul_proto=255 src=AzureIP[500] dst=MyIP[500] satype=ESP samode=tunl spi=0xDA511B54 authtype=SHA1 enctype=3DES enclen=24 lifetime soft time=3173 bytes=0 hard time=3600 bytes=0
2016-09-28 13:00:05 [INFO]: SADB_ADD ul_proto=255 src=MyIP[500] dst=AzureIP[500] satype=ESP samode=tunl spi=0x185719EC authtype=SHA1 enctype=3DES enclen=24 lifetime soft time=3008 bytes=0 hard time=3600 bytes=0
2016-09-28 13:00:05.872 +0200 sadb ts: port 0:65535 IP 192.168.9.0->192.168.9.255 proto:0 len:16
2016-09-28 13:00:05.872 +0200 sadb ts: port 0:65535 IP 192.168.11.0->192.168.11.255 proto:0 len:16
2016-09-28 13:00:05 [PROTO_NOTIFY]: ====> IPSEC KEY INSTALLATION SUCCEEDED <====
====> Installed SA: MyIP[500]-AzureIP[500] SPI:0xDA511B54/0x185719EC lifetime 3600 Sec lifesize unlimited <====
2016-09-28 13:00:05 [PROTO_NOTIFY]: ====> IKEv2 CHILD SA NEGOTIATION SUCCEEDED AS RESPONDER, non-rekey <====
====> Established SA: MyIP[500]-AzureIP[500] message id:0x00000001, SPI:0xDA511B54/0x185719EC parent SN:421 <====
2016-09-28 13:00:05 [PROTO_NOTIFY]: ====> IKEv2 IKE SA NEGOTIATION SUCCEEDED AS RESPONDER, non-rekey <====
====> Established SA: MyIP[500]-AzureIP[500] SPI:013bab07e54a9de1:05be6400222303ed SN:421 lifetime 28800 Sec <====
2016-09-28 13:00:05 [INFO]: keymirror add start ++++++++++++++++
2016-09-28 13:00:05 [INFO]: keymirror add for gw 0x6, tn 10, selfSPI DA511B54, retcode 0.
2016-09-28 13:02:26 [INFO]: sadb_acquire_callback: seq=0 satype=141 sa_src=MyIP[0] sa_dst=OtherSideIP[0] samode=137 tid=8 selid=270066400
2016-09-28 13:02:26 [PROTO_NOTIFY]: ====> PHASE-2 NEGOTIATION STARTED AS INITIATOR, (QUICK MODE) <====
====> Initiated SA: MyIP[500]-OtherSideIP[500] message id:0xF9920D88 <====
2016-09-28 13:02:26 [PROTO_NOTIFY]: ====> PHASE-2 NEGOTIATION SUCCEEDED AS INITIATOR, (QUICK MODE) <====
====> Established SA: MyIP[500]-OtherSideIP[500] message id:0xF9920D88, SPI:0xE7C665A4/0x81D5EE6F <====
2016-09-28 13:02:26 [INFO]: SADB_UPDATE ul_proto=255 src=OtherSideIP[500] dst=MyIP[500] satype=ESP samode=tunl spi=0xE7C665A4 authtype=SHA256 enctype=AES256 enclen=32 lifetime soft time=3600 bytes=67107840 hard time=3600 bytes=67107840
2016-09-28 13:02:26 [INFO]: SADB_ADD ul_proto=255 src=MyIP[500] dst=OtherSideIP[500] satype=ESP samode=tunl spi=0x81D5EE6F authtype=SHA256 enctype=AES256 enclen=32 lifetime soft time=2935 bytes=67107840 hard time=3600 bytes=67107840
2016-09-28 13:02:26 [INFO]: IPsec-SA established: ESP/Tunnel OtherSideIP[500]->MyIP[500] spi=3888539044(0xe7c665a4)
2016-09-28 13:02:26 [PROTO_NOTIFY]: ====> IPSEC KEY INSTALLATION SUCCEEDED <====
====> Installed SA: MyIP[500]-OtherSideIP[500] SPI:0xE7C665A4/0x81D5EE6F lifetime 3600 Sec lifesize 65535 KB <====
2016-09-28 13:02:26 [INFO]: keymirror add start ++++++++++++++++
2016-09-28 13:02:26 [INFO]: keymirror add for gw 0x5, tn 8, selfSPI E7C665A4, retcode 0.
2016-09-28 13:02:26 [INFO]: IKE IPSEC KEY_DELETE recvd:  SPI:0xEE662356.
2016-09-28 13:02:26 [PROTO_NOTIFY]: ====> IPSEC KEY DELETED <====
====> Deleted SA: MyIP[500]-OtherSideIP[500] SPI:0xEE98C59C/0xEE662356 <====
2016-09-28 13:02:26 [INFO]: SADB_DELETE ul_proto=0 src=MyIP[500] dst=OtherSideIP[500] satype=ESP spi=0xEE98C59C
2016-09-28 13:02:26 [INFO]: received PFKEY_DELETE seq=0 satype=ESP spi=0xEE98C59C
2016-09-28 13:02:27 [INFO]: keymirror del start ----------------
2016-09-28 13:02:27 [INFO]: keymirror del for gw 5, tn 8, selfSPI EE98C59C, retcode 0.
2016-09-28 13:02:30 [PROTO_NOTIFY]: notification message 36137:R-U-THERE-ACK, doi=1 proto_id=1 spi=574c34101ce39ffb 7419e233b5cd1329 (size=16).

[Janusz]

---

@OtakarKlier wrote:

Hello,

What are the seetings for the 'Key lifetime' and/or 'Lifesize' set? Perhapes they are set too low and the tunnel keeps rebuilding?

Just a thought.

Regards,

---

The same as those on the page i linked here.  Lifetime is 8h and lifesize is not set.

[TranceforLife]

Hello,

Thanks for this. Could you please try the following:

1) Disable the Liveness Check:

2) Because Palo is in the passive mode we want to make sure that Azure always will be an initiator for IKE Phase 1. Increase lifetime:

3) Same for Phase 2 (note if the Palo in passive mode it is still can be an initiator for the Phase 2). Disable lifesize:

Let me know how you getting on.

Thx,

Myky

[Janusz]

---

@TranceforLife wrote:

Hello,

Thanks for this. Could you please try the following:

1) Disable the Liveness Check:

2) Because Palo is in the passive mode we want to make sure that Azure always will be an initiator for IKE Phase 1. Increase lifetime:

3) Same for Phase 2 (note if the Palo in passive mode it is still can be an initiator for the Phase 2). Disable lifesize:

Let me know how you getting on.

Thx,

Myky

---

Hey,

1) Liveness was disabled.

2) Done.

3) Done.

But the issue remain :). Why would you change that lifetimes anyway? They were way higher than that 5mins.

[TranceforLife]

Hello,

We need to change lifetime to be higher from another side (Azure side in our case)  to make sure that Arure will be initiating for a Phase 1. Forgot to mention about the security policy, make sure it is bidirectional. Shame it didn't work for you

[Janusz · Accepted solution]

---

@TranceforLife wrote:

Hello,

We need to change lifetime to be higher from another side (Azure side in our case)  to make sure that Arure will be initiating for a Phase 1. Forgot to mention about the security policy, make sure it is bidirectional. Shame it didn't work for you

---

Hey,

just a follow up.

I contacted azure support and go my issue resolved. In the end it turned out it is not a issue it is a feature...

Anyway if there is no traffic flowing Azure drops the tunnel after 5min. You can't stop it. However, after it gets droped Azure starts initiating it once again anyway. Why is this working like this? No idea, got information it is like this by design.

Thank you for your help TracerforLife!

[TranceforLife]

🙂  Nice future to tear tunnel down)))  As l said before Azure is always interesting. Good to know some additional "futures" 

All the best,

Myky

[Anon1]

Hello,

please note there is also this issue documented:

https://live.paloaltonetworks.com/t5/Integration-Articles/Critical-Issues-Addressed-in-PAN-OS-Releas...

96415

All 7.0 versions, 7.1.3 and prior

Firewall fails to pass traffic to strongSwan and Azure IPSec peers while using IKEv2 protocol.

Traffic going through the tunnel is dropped after IKEv2 rekey.

IKEv2 process did not send CHILD_SA delete message to the peer before deleting the SA.

No workaround.

7.1.4

All firewall platforms.