This discussion has been locked.
You can no longer post new replies to this discussion. If you have a question you can start a new discussion

IPS/NTP HTTPS Decryption - ERR_EMPTY_RESPONSE issues since latest upgrade to NTP64 2023.2.573

Hey Sophos,

you managed to bring one of our websites out of production with your new NTP64 component.

Since installed, endpoints will not load it or only parts of it. Intercept-X kills the connection during TLS handshake.

HTTPS Decryption enabled.

Working NTP version yesterday:

2023-11-30T08:37:39.828Z [ 6960:16792] I Successfully installed product NTP64.
2023-11-30T08:37:39.838Z [ 9172: 6492] I [SAU] Successfully installed product NTP64 (NTP64) 1.17.3508

Not working NTP version today:

2023-12-01T08:23:52.249Z [16248:16324] I Successfully installed product NTP64.
2023-12-01T08:23:52.261Z [12576: 9776] I [SAU] Successfully installed product NTP64 (NTP64) 2023.2.573

Loading the site yesterday was fine:

2023-11-30T09:42:32.544Z [ 8244: 8324] I [webengine] New connection 0x262427ae5e0
2023-11-30T09:42:32.545Z [ 8244: 8324] I Connection from '\Device\HarddiskVolume3\Program Files\Mozilla Firefox\firefox.exe' with Spid: (5344,133458102324959521) and flowId:15186
2023-11-30T09:42:32.546Z [ 8244: 8280] I [clienthello] connection:0x262427ae5e0 sni:website.load.me ip:123.123.123.123 flowId:15186 decision:nodecrypt source:sxl4_cache
2023-11-30T09:42:32.548Z [ 8244:16656] I [request] connection: 0x262427ae5e0 url:https://website.load.me ip:123.123.123.123 flowId:15186 decision:allowed riskLevel:2 universalCategory:6
2023-11-30T09:42:32.548Z [ 8244:16656] I page allowed: https://website.load.me
2023-11-30T09:42:32.587Z [ 8244: 8324] I [webengine] New connection 0x262427af9c0

Today it's messed up with logs like this:

2023-12-01T17:04:50.037Z [ 7748: 8016] I [webengine] New connection 0x27eabc4e7c0
2023-12-01T17:04:50.037Z [ 7748: 8016] I Connection from '\Device\HarddiskVolume3\Program Files (x86)\Google\Chrome\Application\chrome.exe' with Spid: (16052,133459235343051278) and flowId:3210
2023-12-01T17:04:50.037Z [ 7748: 8016] I [clienthello] connection:0x27eabc4e7c0 sni:website.load.me ip:123.123.123.123 flowId:3210 decision:nodecrypt source:snf_cache webControl:[ decision:allow reason:category policyName:[Base Policy] version:1 ]
2023-12-01T17:04:50.058Z [ 7748: 8004] I Completing offload for flowId 3210
2023-12-01T17:04:50.058Z [ 7748: 8004] I [webengine] Closing connection 0x27eabc4e7c0 for '': request=669B, response=0B, lifetime=21ms, businessLogicDelay=0ms, timeInCache=0ms, in=0ms, out=0ms
2023-12-01T17:04:51.064Z [ 7748: 8000] I [webengine] New connection 0x27eac0c0dc0

Todays Debug Log.

2023-12-01T17:25:59.778Z [18120:15632] A Log level changed from Info to Debug. Source: SOFTWARE\Sophos\Logging\NTP
2023-12-01T17:26:04.046Z [18120: 4264] D [SED:COMMS]: Sending 541 bytes
2023-12-01T17:26:04.046Z [18120: 4264] D [SED:COMMS]: Sending 524 bytes
2023-12-01T17:26:04.047Z [18120:18836] D [SED:COMMS]: [0] Received 76 bytes
2023-12-01T17:26:04.047Z [18120:18836] D [SED:COMMS]: Received command reply
2023-12-01T17:26:04.047Z [18120:18836] D [SED:COMMS]: [0] Received 76 bytes
2023-12-01T17:26:04.047Z [18120:18836] D [SED:COMMS]: Received command reply
2023-12-01T17:26:06.184Z [18120:12360] D Didn't find a context with flowId=7941
2023-12-01T17:26:06.184Z [18120:12360] I [webengine] New connection 0x2493c5ac840
2023-12-01T17:26:06.184Z [18120:12360] D Created context for flowId=7941
2023-12-01T17:26:06.184Z [18120:12360] I Connection from '\Device\HarddiskVolume3\Program Files (x86)\Google\Chrome\Application\chrome.exe' with Spid: (6572,133459239622300236) and flowId:7941
2023-12-01T17:26:06.184Z [18120:12360] I [clienthello] connection:0x2493c5ac840 sni:website.load.me ip:123.123.123.123 flowId:7941 decision:nodecrypt source:snf_cache webControl:[ decision:allow reason:category policyName:[Base Policy] version:1 ]
2023-12-01T17:26:06.184Z [18120:12360] D Client Hello SNI lookup: website.load.me - allow=true, offload=false, nodecrypt=1
2023-12-01T17:26:06.184Z [18120:12360] D Client Hello - Processing WebControl policy
2023-12-01T17:26:06.184Z [18120:12360] D Lookup URL https://website.load.me
2023-12-01T17:26:06.184Z [18120:12360] D [SED:COMMS]: Sending 842 bytes
2023-12-01T17:26:06.186Z [18120: 5528] D [SED:COMMS]: [0] Received 512 bytes
2023-12-01T17:26:06.186Z [18120: 5528] D [SED:COMMS]: Received command reply
2023-12-01T17:26:06.186Z [18120:18824] I [request] connection: 0x2493c5ac840 url:https://website.load.me ip:123.123.123.123 flowId:7941 decision:allowed riskLevel:2 universalCategory:6 webControl:[ decision:allow reason:category policyName:[Base Policy] version:1 ]
2023-12-01T17:26:06.186Z [18120:18824] D NetFilter is using WebControl result from webrule
2023-12-01T17:26:06.186Z [18120:18824] I page allowed: https://website.load.me
2023-12-01T17:26:06.267Z [18120:12360] D Erasing context for flowId=7941
2023-12-01T17:26:06.267Z [18120:12360] D Storing web flow journal event for 13345925166-7941. Number of certs stored: 0
2023-12-01T17:26:06.267Z [18120:12360] I [webengine] Closing connection 0x2493c5ac840 for 'https://website.load.me': request=2176B, response=5467B, lifetime=83ms, firstResponse=30ms, businessLogicDelay=0ms, timeInCache=0ms, in=30ms, out=67ms, l.eos=82ms, r.eos=82ms
2023-12-01T17:26:08.317Z [18120:18448] D Didn't find a context with flowId=7947
2023-12-01T17:26:08.318Z [18120:18448] I [webengine] New connection 0x2493c64f540
2023-12-01T17:26:08.318Z [18120:18448] D Created context for flowId=7947
2023-12-01T17:26:08.318Z [18120:18448] I Connection from '\Device\HarddiskVolume3\Program Files (x86)\Google\Chrome\Application\chrome.exe' with Spid: (6572,133459239622300236) and flowId:7947
2023-12-01T17:26:08.318Z [18120:18448] I [clienthello] connection:0x2493c64f540 sni:website.load.me ip:123.123.123.123 flowId:7947 decision:nodecrypt source:snf_cache webControl:[ decision:allow reason:category policyName:[Base Policy] version:1 ]
2023-12-01T17:26:08.318Z [18120:18448] D Client Hello SNI lookup: website.load.me - allow=true, offload=false, nodecrypt=1
2023-12-01T17:26:08.318Z [18120:18448] D Client Hello - Processing WebControl policy
2023-12-01T17:26:08.318Z [18120:18448] D Lookup URL https://website.load.me
2023-12-01T17:26:08.318Z [18120:18448] D [SED:COMMS]: Sending 842 bytes
2023-12-01T17:26:08.319Z [18120: 5528] D [SED:COMMS]: [0] Received 512 bytes
2023-12-01T17:26:08.319Z [18120: 5528] D [SED:COMMS]: Received command reply
2023-12-01T17:26:08.319Z [18120:18824] I [request] connection: 0x2493c64f540 url:https://website.load.me ip:123.123.123.123 flowId:7947 decision:allowed riskLevel:2 universalCategory:6 webControl:[ decision:allow reason:category policyName:[Base Policy] version:1 ]
2023-12-01T17:26:08.319Z [18120:18824] D NetFilter is using WebControl result from webrule
2023-12-01T17:26:08.319Z [18120:18824] I page allowed: https://website.load.me
2023-12-01T17:26:08.494Z [18120:18780] D Erasing context for flowId=7947
2023-12-01T17:26:08.494Z [18120:18780] D Storing web flow journal event for 13345925168-7947. Number of certs stored: 0
2023-12-01T17:26:08.494Z [18120:18780] I [webengine] Closing connection 0x2493c64f540 for 'https://website.load.me': request=2112B, response=5467B, lifetime=176ms, firstResponse=108ms, businessLogicDelay=0ms, timeInCache=0ms, in=108ms, out=144ms, l.eos=176ms, r.eos=176ms
2023-12-01T17:26:09.653Z [18120:12360] D Didn't find a context with flowId=7952
2023-12-01T17:26:09.653Z [18120:12360] I [webengine] New connection 0x2493c5ac540

Must I say, it works, when disabling Sophos modules?

I'm a bit tired.



This thread was automatically locked due to age.
Parents
  • Hi LHerzog,

    I regret to hear about your frustrations. 

    In terms of establishing an immediate workaround, is using the Update Management policy's "Software Package" dropdown an option? 

    Could you try creating an exclusion of the type "Website" in the Threat protection policy applied to the affected device which excludes the website in question? It should not be necessary to create an exclusion for both HTTPS decryption and the threat protection policy, but this may shed some more light on the issue.

    Kushal Lakhan
    Team Lead, Global Community Support
    Connect with Sophos Support, get alerted, and be informed.
    If a post solves your question, please use the "Verify Answer" button.
    The New Home of Sophos Support Videos!  Visit Sophos Techvids
Reply
  • Hi LHerzog,

    I regret to hear about your frustrations. 

    In terms of establishing an immediate workaround, is using the Update Management policy's "Software Package" dropdown an option? 

    Could you try creating an exclusion of the type "Website" in the Threat protection policy applied to the affected device which excludes the website in question? It should not be necessary to create an exclusion for both HTTPS decryption and the threat protection policy, but this may shed some more light on the issue.

    Kushal Lakhan
    Team Lead, Global Community Support
    Connect with Sophos Support, get alerted, and be informed.
    If a post solves your question, please use the "Verify Answer" button.
    The New Home of Sophos Support Videos!  Visit Sophos Techvids
Children
  • support suggested to create global exclusion for IP address of the website. that is the only thing that worked as a workaround.

    why there are so many locations where you can define web exclusions?

    In our case it is some how related to endpoint's network protection module. So I assumed, it should work with the already existing exclusion, defined for that module. We have excluded the whole network range there - to not run in such kind of issues some day. Now we have reached that day, regardless of this exception.

    So that does not work.

    The only thing that works to bypass the problem is that kind of exclusion: Global -> Website Exclusion

  • Development reference number:

    WINEP-51962

  • it works with FTS 2023.2.0.50-SPECIAL-51962

    that special software pack uses NTP 2023.2.847

    What I understood from the support case is that the original NTP engine was not handling the TLS Session correctly.