PulseSecure Mojave, tunnel becomes unusable after 5 to 10 minutes

[rcharlet@alumni.calpoly.edu]

Howdy,
  I am using PulseSecure 9.1.6 on MacOS Mojave (10.14.6) connecting to my work VPN. I do not know what gear my work VPN is using on the server side.

  I can connect easily. My session will stay usable only for about 5 to 10 minute and then all traffic through the tunnel will stop (ping unreachable to basicaly anywhere in my work netwrok). During this time, the PusleSecure session stays "connected" and my mac0S interface, utun2, stays UP/RUNNING with a valid ipv4 address.
 A disconnect and connect always solves the problem. But it will show up again in another 5 to 10 minutes.
  If I take my laptop anywhere outside of my home (coffee shop, mother-in-law's house, use my phone as a hotspot...) Then I never have the session-becomes-unusable problem. So I know this is somehow related to my home isp (jrcomm+verizon:wireless/cellular).
   During the time my vpn connection becomes unusable, I have no problem connecting to anywhere else on the internet...so that implies my home ISP is working well. Hmmm...

  PulseSecure logs do show a change in pattern at the time-stamp-of-intrest boundary (12:06:41). But I don't know what this pattern change is implying....

----cut---
0146,09 2020/11/20 12:06:41.772 5 root dsAccessService iveConnectionMethod p0058 t38F13 udp.cpp:611 - 'ipsec' Sending 84 bytes UDP to 15.211.196.20:4500
00149,09 2020/11/20 12:06:41.899 5 root dsAccessService iveConnectionMethod p0058 t39407 dsio.cpp:628 - 'dsio' calling 0x7f875231cf70 IpsecUdpSocket SOCK 59
00150,09 2020/11/20 12:06:41.899 5 root dsAccessService iveConnectionMethod p0058 t39407 udp.cpp:671 - 'ipsec' Received 132 bytes UDP from 15.211.196.20:4500
00148,09 2020/11/20 12:06:41.899 5 root dsAccessService iveConnectionMethod p0058 t39407 esp.cpp:262 - 'ipsec' window advanced to 647/FFFFFFFF. no=00000001
00168,09 2020/11/20 12:06:41.899 5 root dsAccessService iveConnectionMethod p0058 t39407 ncIPSecSession.cpp:558 - 'ncAccessMethod' ncIPSecSession::sendToTun: 0x7f8757000820 84
00161,09 2020/11/20 12:06:41.899 5 root dsAccessService iveConnectionMethod p0058 t39407 ncSession.cpp:624 - 'ncAccessMethod' Received data 57000820 from server, len:84
00118,09 2020/11/20 12:06:41.899 5 root dsAccessService dsTMService p0058 t39407 packetImpl.h:146 - 'plugin' ipver=4, size=84
00132,09 2020/11/20 12:06:42.394 5 root dsAccessService dsTMService p0058 t38F13 packetImpl.h:210 - 'plugin' Read 88 bytes from the adapter
00153,09 2020/11/20 12:06:42.394 5 root dsAccessService iveConnectionMethod p0058 t38F13 ncIPSecSession.cpp:398 - 'ncAccessMethod' ncIPSecSession::sendData: 0 1
00147,09 2020/11/20 12:06:42.394 5 root dsAccessService iveConnectionMethod p0058 t38F13 udp.cpp:611 - 'ipsec' Sending 132 bytes UDP to 15.211.196.20:4500
00149,09 2020/11/20 12:06:42.499 5 root dsAccessService iveConnectionMethod p0058 t39407 dsio.cpp:628 - 'dsio' calling 0x7f875231cf70 IpsecUdpSocket SOCK 59
00150,09 2020/11/20 12:06:42.499 5 root dsAccessService iveConnectionMethod p0058 t39407 udp.cpp:671 - 'ipsec' Received 132 bytes UDP from 15.211.196.20:4500
00148,09 2020/11/20 12:06:42.499 5 root dsAccessService iveConnectionMethod p0058 t39407 esp.cpp:262 - 'ipsec' window advanced to 648/FFFFFFFF. no=00000001
00168,09 2020/11/20 12:06:42.499 5 root dsAccessService iveConnectionMethod p0058 t39407 ncIPSecSession.cpp:558 - 'ncAccessMethod' ncIPSecSession::sendToTun: 0x7f8757000020 84
00161,09 2020/11/20 12:06:42.499 5 root dsAccessService iveConnectionMethod p0058 t39407 ncSession.cpp:624 - 'ncAccessMethod' Received data 57000020 from server, len:84
00118,09 2020/11/20 12:06:42.499 5 root dsAccessService dsTMService p0058 t39407 packetImpl.h:146 - 'plugin' ipver=4, size=84
00132,09 2020/11/20 12:06:42.739 5 root dsAccessService dsTMService p0058 t38F13 packetImpl.h:210 - 'plugin' Read 88 bytes from the adapter
00153,09 2020/11/20 12:06:42.740 5 root dsAccessService iveConnectionMethod p0058 t38F13 ncIPSecSession.cpp:398 - 'ncAccessMethod' ncIPSecSession::sendData: 0 1
00147,09 2020/11/20 12:06:42.740 5 root dsAccessService iveConnectionMethod p0058 t38F13 udp.cpp:611 - 'ipsec' Sending 132 bytes UDP to 15.211.196.20:4500
00149,09 2020/11/20 12:06:42.898 5 root dsAccessService iveConnectionMethod p0058 t39407 dsio.cpp:628 - 'dsio' calling 0x7f875231cf70 IpsecUdpSocket SOCK 59
00150,09 2020/11/20 12:06:42.899 5 root dsAccessService iveConnectionMethod p0058 t39407 udp.cpp:671 - 'ipsec' Received 132 bytes UDP from 15.211.196.20:4500
00148,09 2020/11/20 12:06:42.899 5 root dsAccessService iveConnectionMethod p0058 t39407 esp.cpp:262 - 'ipsec' window advanced to 649/FFFFFFFF. no=00000001
00168,09 2020/11/20 12:06:42.899 5 root dsAccessService iveConnectionMethod p0058 t39407 ncIPSecSession.cpp:558 - 'ncAccessMethod' ncIPSecSession::sendToTun: 0x7f8753828820 84
00161,09 2020/11/20 12:06:42.899 5 root dsAccessService iveConnectionMethod p0058 t39407 ncSession.cpp:624 - 'ncAccessMethod' Received data 53828820 from server, len:84
00118,09 2020/11/20 12:06:42.899 5 root dsAccessService dsTMService p0058 t39407 packetImpl.h:146 - 'plugin' ipver=4, size=84
00132,09 2020/11/20 12:06:43.203 5 root dsAccessService dsTMService p0058 t38F13 packetImpl.h:210 - 'plugin' Read 67 bytes from the adapter
00153,09 2020/11/20 12:06:43.204 5 root dsAccessService iveConnectionMethod p0058 t38F13 ncIPSecSession.cpp:398 - 'ncAccessMethod' ncIPSecSession::sendData: 0 1
00147,09 2020/11/20 12:06:43.204 5 root dsAccessService iveConnectionMethod p0058 t38F13 udp.cpp:611 - 'ipsec' Sending 116 bytes UDP to 15.211.196.20:4500
00132,09 2020/11/20 12:06:43.399 5 root dsAccessService dsTMService p0058 t38F13 packetImpl.h:210 - 'plugin' Read 88 bytes from the adapter
00153,09 2020/11/20 12:06:43.399 5 root dsAccessService iveConnectionMethod p0058 t38F13 ncIPSecSession.cpp:398 - 'ncAccessMethod' ncIPSecSession::sendData: 0 1
00147,09 2020/11/20 12:06:43.399 5 root dsAccessService iveConnectionMethod p0058 t38F13 udp.cpp:611 - 'ipsec' Sending 132 bytes UDP to 15.211.196.20:4500
00132,09 2020/11/20 12:06:43.744 5 root dsAccessService dsTMService p0058 t38F13 packetImpl.h:210 - 'plugin' Read 88 bytes from the adapter
00153,09 2020/11/20 12:06:43.744 5 root dsAccessService iveConnectionMethod p0058 t38F13 ncIPSecSession.cpp:398 - 'ncAccessMethod' ncIPSecSession::sendData: 0 1
00147,09 2020/11/20 12:06:43.744 5 root dsAccessService iveConnectionMethod p0058 t38F13 udp.cpp:611 - 'ipsec' Sending 132 bytes UDP to 15.211.196.20:4500
00132,09 2020/11/20 12:06:44.209 5 root dsAccessService dsTMService p0058 t38F13 packetImpl.h:210 - 'plugin' Read 67 bytes from the adapter
00153,09 2020/11/20 12:06:44.209 5 root dsAccessService iveConnectionMethod p0058 t38F13 ncIPSecSession.cpp:398 - 'ncAccessMethod' ncIPSecSession::sendData: 0 1
00147,09 2020/11/20 12:06:44.209 5 root dsAccessService iveConnectionMethod p0058 t38F13 udp.cpp:611 - 'ipsec' Sending 116 bytes UDP to 15.211.196.20:4500
00132,09 2020/11/20 12:06:44.404 5 root dsAccessService dsTMService p0058 t38F13 packetImpl.h:210 - 'plugin' Read 88 bytes from the adapter
00153,09 2020/11/20 12:06:44.404 5 root dsAccessService iveConnectionMethod p0058 t38F13 ncIPSecSession.cpp:398 - 'ncAccessMethod' ncIPSecSession::sendData: 0 1
00147,09 2020/11/20 12:06:44.404 5 root dsAccessService iveConnectionMethod p0058 t38F13 udp.cpp:611 - 'ipsec' Sending 132 bytes UDP to 15.211.196.20:4500
00132,09 2020/11/20 12:06:44.749 5 root dsAccessService dsTMService p0058 t38F13 packetImpl.h:210 - 'plugin' Read 88 bytes from the adapter
00153,09 2020/11/20 12:06:44.749 5 root dsAccessService iveConnectionMethod p0058 t38F13 ncIPSecSession.cpp:398 - 'ncAccessMethod' ncIPSecSession::sendData: 0 1
00147,09 2020/11/20 12:06:44.749 5 root dsAccessService iveConnectionMethod p0058 t38F13 udp.cpp:611 - 'ipsec' Sending 132 bytes UDP to 15.211.196.20:4500

----paste----

[r@yElr3y]

rcharlet@alumni.calpoly.edu As a start, we would need to check if the Pulse Client is sending any traffic through the tunnel. Can you take a wireshark capture on the utun interface if possible and check if you're seeing packets being sent out?

[rcharlet@alumni.calpoly.edu · Accepted solution]

Howdy,

   Thing 1: I do not know if traffic was flowing on the tunnel even when it was unresponsive. Did not measure that.

   Thing 2: My problem has been fixed. It was an unreliable wifi access point inside my house. I replaced that and my PulseSecure problems went away.  

 This was not a PulseSecure probelm and this thread can close. But, If PulseSecure staff are interested, I do have a suggestion...keep reading:

My netowrk looked like

                                                                  (NAT Router)          (NAT Router)

{work}--{internet}--{verizon_cellular}--[home_lte_modem]--[home_wifi_router]--[Mac [PulseSecure]]

      ======================(tunnel)=============================

I changed it to:

                                                                  (NAT Router)          (L2 switch)

{work}--{internet}--{verizon_cellular}--[home_lte_modem]--[home_wifi_ap]--[Mac [PulseSecure]]

      ======================(tunnel)===========================

So basically, I removed the double NAT.
Looks like IPsec standards for NAT Traversal https://tools.ietf.org/html/rfc3947#section-3.2 involve keepalives.  If living behind a double NAT messes up the keepalives, that could explain the problem I was having.

Suggestion:
  Could the PulseSecure client detect either multiple NAT or loss of NAT-T keepalive and put up a helpful log message or even client-gui-waring-signal?

[kita]

Wow, this is very good feedback.  I don't think this is documented anywhere, but I'll put this onto the forums for everyone else.

Yes, the keep alive is handled by tcp port 443 which is a control channel while data is sent over UDP 4500.  If there is a NAT involved, then it is likely the keep alive is responded by the NAT and never reaching the PCS device.  If this is correct, then the PCS device has its own keep alive.  The logic is the following:

1. After 300 seconds (5 minutes), PCS will send a keep alive to the client.
2. If not response is received it will send a keep alive every 75 seconds up to 9 times for a total of 675 seconds.
3. If no response is received after 300 + 675 = 975 seconds, then the PCS device will drop the connection.