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

9.4 Endpoint Web Protection is NOT working

I've noticed that after a clean install of 9.4, Endpoint Web Protection logs are not populating on my UTM and my endpoints (Windows 10) appear to be able to surf anywhere without any protection.  The Sophos Agent shows Web Control enabled, but it is not blocking sites that it's supposed to.  I'll reiterate, I have cleanly installed 9.400-9 and have refreshed from scratch the Endpoint Protection and I'm still seeing the issue (this was not an upgrade...after the upgrade, this failed as well, so I did everything from scratch and still see the issue).  My endpoints are showing up just fine under Endpoint Protection on the gateway and the antivirus appears to be working, just not the web protection.  Here is a sample of the Endpoint Protection Logs:

2016:03:25-10:11:27 rickshome epsecd[10282]: I id="4211" severity="info" sys="System" sub="epsecd" name="Received report(s) from Sophos LiveConnect"
2016:03:25-10:11:27 rickshome epsecd[10282]: I id="4212" severity="info" sys="System" sub="epsecd" name="Acknowledging report(s)" reports="-1"
2016:03:25-10:13:15 rickshome epsecd[10282]: I id="4211" severity="info" sys="System" sub="epsecd" name="Received report(s) from Sophos LiveConnect"
2016:03:25-10:13:15 rickshome epsecd[10282]: I id="4212" severity="info" sys="System" sub="epsecd" name="Acknowledging report(s)" reports="-1"
2016:03:25-10:15:03 rickshome epsecd[10282]: I id="4211" severity="info" sys="System" sub="epsecd" name="Received report(s) from Sophos LiveConnect"
2016:03:25-10:15:03 rickshome epsecd[10282]: I id="4212" severity="info" sys="System" sub="epsecd" name="Acknowledging report(s)" reports="-1"
2016:03:25-10:17:46 rickshome epsecd[10282]: I id="4211" severity="info" sys="System" sub="epsecd" name="Received report(s) from Sophos LiveConnect"
2016:03:25-10:17:46 rickshome epsecd[10282]: I id="4212" severity="info" sys="System" sub="epsecd" name="Acknowledging report(s)" reports="-1"
2016:03:25-10:19:04 rickshome epsecd[10796]: I main::_log:435() =>  severity="info" sys="System" sub="eplog" name="curl_base_url: e53611b9-7d74-339e-b3f2-4e2addb92ca2-wdx-7d74.broker.sophos.com/.../"
2016:03:25-10:19:34 rickshome epsecd[10282]: I id="4211" severity="info" sys="System" sub="epsecd" name="Received report(s) from Sophos LiveConnect"
2016:03:25-10:19:34 rickshome epsecd[10282]: I id="4212" severity="info" sys="System" sub="epsecd" name="Acknowledging report(s)" reports="-1"
2016:03:25-10:19:35 rickshome epsecd[10282]: I id="4233" severity="info" sys="System" sub="epsecd" name="Sending data to Sophos LiveConnect to sync UTM Web Policy Changeset"
2016:03:25-10:19:38 rickshome epsecd[10282]: I id="4213" severity="info" sys="System" sub="epsecd" name="User triggered changes in webadmin"
2016:03:25-10:22:21 rickshome epsecd[10282]: I id="4211" severity="info" sys="System" sub="epsecd" name="Received report(s) from Sophos LiveConnect"
2016:03:25-10:22:21 rickshome epsecd[10282]: I id="4212" severity="info" sys="System" sub="epsecd" name="Acknowledging report(s)" reports="-1"
2016:03:25-10:23:16 rickshome epsecd[10282]: I id="4233" severity="info" sys="System" sub="epsecd" name="Sending data to Sophos LiveConnect to sync UTM Web Policy Changeset"
2016:03:25-10:23:19 rickshome epsecd[10282]: I id="4213" severity="info" sys="System" sub="epsecd" name="User triggered changes in webadmin"
2016:03:25-10:24:12 rickshome epsecd[10282]: I id="4211" severity="info" sys="System" sub="epsecd" name="Received report(s) from Sophos LiveConnect"
2016:03:25-10:24:12 rickshome epsecd[10282]: I id="4212" severity="info" sys="System" sub="epsecd" name="Acknowledging report(s)" reports="-1"

I do see the reports coming in, but I'm a little bit concerned on the "-1" for acknowledgement.

Any ideas on what I can do next? If you need more information, please let me know!


This thread was automatically locked due to age.
Parents
  • You mentioned Windows 10 clients are having the issue... Do you have any older versions of Windows and are they behaving properly?

    Also, did you have any issues prior to moving to 9.4? It's hard to tell if this related to Win10 or UTM 9.4.

  • This very well could be.  I do know it worked on Windows 10 at one time (have several clients on Windows 10 and it worked fine on multiple versions of 9.3 from September, 2015 -- February, 2016)...but stopped working back in February on version 9.355.  I am doing more testing and have found the following:

    1.)  I have one Windows 10 box that was working and I have never "uninstalled" the client agent.  I have installed OVER the client agent when I installed the new 9.4 from scratch.  The directory structure on that box under C:\ProgramData\Sophos\Web Control\Policy shows that there is a policy there (there are files in that directory), but it doesn't appear to be updating when I make changes to the web content filter.   No Web Control logs are getting to Sophos, however.

    2.)  I have another Windows 10 box that is brand new.  I installed the 9.4 client agent on that box from scratch.  The directory structure under C:\ProgramData\Sophos\Web Control\Policy shows nothing.  It's almost like the policy can't get into the directory or it isn't updating for some reason?

    I will try to spin up a Windows 7 box and see if I have the same issues.  I do know the Sophos Endpoint Cloud works fine on Windows 10 (tried and installed this and it worked just great), just not the endpoint web control service using the UTM.

    Another thing I have found... I just downgraded my UTM to 9.351 and I still am experiencing the same issues!  Either something changed in Windows 10 that is blocking endpoint web control policy changes or something changed on the Sophos server side and how it communicates with the agent.

    I'll continue to research!

  • Maybe, have the problem in the Sophos Agent ...

  • Based on the log lines:

    v 16040814384024 swi_service.exe:004108:0009c4 Failed to validate index signature using server key [Sophos::PublicKey 3c 40 57 81 a0 ea f5 b9 9b eb 61 f8 66 27 ff 78 91 04 12 87]. Does the endpoint need to re-register? [WebControlCrypto.cpp:301 reginfo::reginfo]
    e 16040814384024 swi_service.exe:004108:0009c4 Policy: invalid index err:0 

    It would suggest that the endpoint is downloading (in your case) the following index file:
    http://e53611b9-7d74-339e-b3f2-4e2addb92ca2-wdx-7d74.broker.sophos.com/wdx/policy/index.txt 

    It is then attempting to validate the signature and not being able to.  As a result the index file is deemed to be invalid so it will not progress to downloading the policy fragments.

    I can only think that either:

    1. The file is being corrupted on download by swi_service.exe.

    2. The endpoint is getting unexpected signature data.

    As the index file contains hashes of the policy fragments, an update to the policy would generate a new index file so that might be worth while.

    I've taken a quick look on a UTM at: 

    /var/epsecd/etc/eplog.conf

    and I see:

    private_key = /var/epsecd/resources/client.pem
    certificate = /var/epsecd/resources/client.crt
    ca_certificate = /var/epsecd/resources/aws.ca.crt
    sc_ini = /var/chroot-http/etc/sc.ini

    so under: /var/epsecd/resources/ we see:

    aws.ca.crt  client.crt  client.pem  postgresql  templates

    Note: Adding customer resources via the web interface (Management - Customisation - Web Templates /images) go to:

    /var/epsecd/resources/templates/[xxxxxxxxxx]/static/custom/

    So these would also be part of the index. For example with a custom file the index would have at the top of the fragment list:

    version 1

    custom_image 85864 cad136604af290b9fd9682f4139e7d87a4eb49e9 Sophos-icon.png

    where Sophos-icon.png is a custom file, the size and checksum are also listed.

    I wonder if cross referencing the endpoint trace logs with the info in the above certificates and the files on the endpoints under: "C:\ProgramData\Sophos\Web Control\Keys\" the problem could be understood.

    Failing which maybe try adding a custom resource to force a new index, then check your index file by just downloading it in a browser by adding /wdx/policy/index.txt to URL based on your appliance ID.  This can be found in the endpoint registry under: HKEY_LOCAL_MACHINE\SOFTWARE\Sophos\Web Intelligence\Web Control\PolicyURL. Finally restart the Sophos Web intelligence service on a client to force a new sync.

    Regards,

    Jak

  • Communication within Spohos has been a big problem as of late.  I had to threaten termination of all of my current sales leads and refusal to renew and move to another product to get a response.  Sophos is the victim of too many acquisitions too quickly and it is now showing.  Hopefully they will get their internal issues straightened out very soon.

    Owner:  Emmanuel Technology Consulting

    http://etc-md.com

    Former Sophos SG(Astaro) advocate/researcher/Silver Partner

    PfSense w/Suricata, ntopng, 

    Other addons to follow

  • That is a highly loaded question.  I am running 9.4 on my test system but my clients are running 9.35x

    Owner:  Emmanuel Technology Consulting

    http://etc-md.com

    Former Sophos SG(Astaro) advocate/researcher/Silver Partner

    PfSense w/Suricata, ntopng, 

    Other addons to follow

  • Yes it has been pretty bad lately... I'm using a national US reseller and they're having a hell of a time getting answers. 

  • I also installed 9.4 on my test system, everything works well, except for Agent...

  • Huh... looks like it's working again -- at least in our case.  Just looked at a laptop and the log data is there (in the UTM) as well as reporting, and blocking stuff as it is supposed to.  Must've fixed something in the back end.

    CTO, Convergent Information Security Solutions, LLC

    https://www.convergesecurity.com

    Sophos Platinum Partner

    --------------------------------------

    Advice given as posted on this forum does not construe a support relationship or other relationship with Convergent Information Security Solutions, LLC or its subsidiaries.  Use the advice given at your own risk.

  • I've completely turned off Endpoint Protection and restarted it and erased all the data.  I've installed the agent on the endpoint again and turned on the logging in the registry in order to get the swisdiag log files.  The results are below:

     

    I 16041215155742 swi_service.exe:002244:001310 20160412 151557.423 T00001310 ------ 3 - Processing request=196\n [oem-log.cpp:29 oem_log]
    I 16041215155742 swi_service.exe:002244:001310 20160412 151557.423 T00001310 ------ 3 - Queueing request 196\n [oem-log.cpp:29 oem_log]
    I 16041215155742 swi_service.exe:002244:000e78 20160412 151557.423 T00000e78 ------ 3 - Processing request=196, 00F328B0\n [oem-log.cpp:29 oem_log]
    A 16041215155792 swi_service.exe:002244:000e78 20160412 151557.922 T00000e78 ------ 2 - Send request (WinHttpReceiveResponse) error 12152: The server returned an invalid or unrecognized response\n [oem-log.cpp:25 oem_log]
    v 16041215155792 swi_service.exe:002244:001028 Policy response: event=1; status=0 [WebControlSync.cpp:1058 WebControlSync::handlePolicyResponse]
    e 16041215155792 swi_service.exe:002244:001028 Policy: failure downloading index.txt: status=0 err:0 [WebControlSync.cpp:1062 WebControlSync::handlePolicyResponse]
    v 16041215155792 swi_service.exe:002244:001028 [SymmetricKey d6 77 2f 3f 42 a7 50 d1 8f a3 d5 d5 7a 32 ea 46 ec be d9 69].decrypt(sha1=e6b05cd675e63188482dc80736b6a49ad8846657) [SophosSymmetricKey.cpp:244 Sophos::SymmetricKey::decrypt]
    v 16041215155792 swi_service.exe:002244:001028 decrypted sha1=af006394ac52ffb2e15e3aef5418c254535825fe [SophosSymmetricKey.cpp:156 Sophos::SymmetricKey::impl::decrypt]
    v 16041215155792 swi_service.exe:002244:001028 Successfully decrypted keyinfo.dat from disk [WebControlCrypto.cpp:301 reginfo::reginfo]
    v 16041215155792 swi_service.exe:002244:001028 fallback URL:e53611b9-7d74-339e-b3f2-4e2addb92ca2-wdx-7d74.broker.sophos.com/ [WebControlSync.cpp:493 WebControlSync::makeUrl]
    v 16041215155792 swi_service.exe:002244:001028 Signing X-Sophos-Filter header contents: e53611b9-7d74-339e-b3f2-4e2addb92ca2-wdx-7d74.broker.sophos.com/wdx/policy/index.txt [WebControlSync.cpp:513 WebControlSync::signedFilterHeader]
    v 16041215155792 swi_service.exe:002244:001028 [SymmetricKey d6 77 2f 3f 42 a7 50 d1 8f a3 d5 d5 7a 32 ea 46 ec be d9 69].decrypt(sha1=e6b05cd675e63188482dc80736b6a49ad8846657) [SophosSymmetricKey.cpp:244 Sophos::SymmetricKey::decrypt]
    v 16041215155792 swi_service.exe:002244:001028 decrypted sha1=af006394ac52ffb2e15e3aef5418c254535825fe [SophosSymmetricKey.cpp:156 Sophos::SymmetricKey::impl::decrypt]
    v 16041215155792 swi_service.exe:002244:001028 Successfully decrypted keyinfo.dat from disk [WebControlCrypto.cpp:301 reginfo::reginfo]
    v 16041215155792 swi_service.exe:002244:001028 [SymmetricKey 3b 15 7d 59 3c 1e e2 65 25 ff 69 11 1e 9d 66 f9 1a e7 a2 bc].sign(sha1=dd2294ecea9a85a7f9a2d75640c9933ea515e7b1) [SophosSymmetricKey.cpp:251 Sophos::SymmetricKey::sign]
    v 16041215155792 swi_service.exe:002244:001028 signature sha1=3bdb711e168957d1e07f5eecf67e34176263aa4a [SophosSymmetricKey.cpp:174 Sophos::SymmetricKey::impl::sign]
    v 16041215155792 swi_service.exe:002244:001028 Signed WDX header: X-Sophos-Filter: 566b1ba59834da6e4d8ad204efe44d8e7e10a873 [e53611b9-7d74-339e-b3f2-4e2addb92ca2-wdx-7d74.broker.sophos.com/wdx/policy/index.txt] [WebControlSync.cpp:543 WebControlSync::signWdxRequestHeaders]
    v 16041215155792 swi_service.exe:002244:001028 [PROXY:AUTODETECT FORCE] Policy: GET e53611b9-7d74-339e-b3f2-4e2addb92ca2-wdx-7d74.broker.sophos.com/.../index.txt [WebControlSync.cpp:640 WebControlSync::startPolicy]
    v 16041215155792 swi_service.exe:002244:001028 NOT resetting failure count -- intermediate proxy failure [WebControlSync.cpp:825 WebControlSync::httpEventCallback]
    I 16041215155792 swi_service.exe:002244:001310 20160412 151557.922 T00001310 ------ 3 - Processing request=195\n [oem-log.cpp:29 oem_log]
    I 16041215155798 swi_service.exe:002244:001310 20160412 151557.984 T00001310 ------ 3 - Queueing request 195\n [oem-log.cpp:29 oem_log]
    I 16041215155798 swi_service.exe:002244:0001f4 20160412 151557.984 T000001f4 ------ 3 - Processing request=195, 00F32270\n [oem-log.cpp:29 oem_log]
    A 16041215155865 swi_service.exe:002244:0001f4 20160412 151558.655 T000001f4 ------ 2 - Send request (WinHttpReceiveResponse) error 12152: The server returned an invalid or unrecognized response\n [oem-log.cpp:25 oem_log]

    It appears I am unable to download the index.txt file from Sophos, but I can't figure out as to why (or if it's an issue on my end or there end).  I am still not seeing any data and my web protection still does not work on 9.4.

Reply
  • I've completely turned off Endpoint Protection and restarted it and erased all the data.  I've installed the agent on the endpoint again and turned on the logging in the registry in order to get the swisdiag log files.  The results are below:

     

    I 16041215155742 swi_service.exe:002244:001310 20160412 151557.423 T00001310 ------ 3 - Processing request=196\n [oem-log.cpp:29 oem_log]
    I 16041215155742 swi_service.exe:002244:001310 20160412 151557.423 T00001310 ------ 3 - Queueing request 196\n [oem-log.cpp:29 oem_log]
    I 16041215155742 swi_service.exe:002244:000e78 20160412 151557.423 T00000e78 ------ 3 - Processing request=196, 00F328B0\n [oem-log.cpp:29 oem_log]
    A 16041215155792 swi_service.exe:002244:000e78 20160412 151557.922 T00000e78 ------ 2 - Send request (WinHttpReceiveResponse) error 12152: The server returned an invalid or unrecognized response\n [oem-log.cpp:25 oem_log]
    v 16041215155792 swi_service.exe:002244:001028 Policy response: event=1; status=0 [WebControlSync.cpp:1058 WebControlSync::handlePolicyResponse]
    e 16041215155792 swi_service.exe:002244:001028 Policy: failure downloading index.txt: status=0 err:0 [WebControlSync.cpp:1062 WebControlSync::handlePolicyResponse]
    v 16041215155792 swi_service.exe:002244:001028 [SymmetricKey d6 77 2f 3f 42 a7 50 d1 8f a3 d5 d5 7a 32 ea 46 ec be d9 69].decrypt(sha1=e6b05cd675e63188482dc80736b6a49ad8846657) [SophosSymmetricKey.cpp:244 Sophos::SymmetricKey::decrypt]
    v 16041215155792 swi_service.exe:002244:001028 decrypted sha1=af006394ac52ffb2e15e3aef5418c254535825fe [SophosSymmetricKey.cpp:156 Sophos::SymmetricKey::impl::decrypt]
    v 16041215155792 swi_service.exe:002244:001028 Successfully decrypted keyinfo.dat from disk [WebControlCrypto.cpp:301 reginfo::reginfo]
    v 16041215155792 swi_service.exe:002244:001028 fallback URL:e53611b9-7d74-339e-b3f2-4e2addb92ca2-wdx-7d74.broker.sophos.com/ [WebControlSync.cpp:493 WebControlSync::makeUrl]
    v 16041215155792 swi_service.exe:002244:001028 Signing X-Sophos-Filter header contents: e53611b9-7d74-339e-b3f2-4e2addb92ca2-wdx-7d74.broker.sophos.com/wdx/policy/index.txt [WebControlSync.cpp:513 WebControlSync::signedFilterHeader]
    v 16041215155792 swi_service.exe:002244:001028 [SymmetricKey d6 77 2f 3f 42 a7 50 d1 8f a3 d5 d5 7a 32 ea 46 ec be d9 69].decrypt(sha1=e6b05cd675e63188482dc80736b6a49ad8846657) [SophosSymmetricKey.cpp:244 Sophos::SymmetricKey::decrypt]
    v 16041215155792 swi_service.exe:002244:001028 decrypted sha1=af006394ac52ffb2e15e3aef5418c254535825fe [SophosSymmetricKey.cpp:156 Sophos::SymmetricKey::impl::decrypt]
    v 16041215155792 swi_service.exe:002244:001028 Successfully decrypted keyinfo.dat from disk [WebControlCrypto.cpp:301 reginfo::reginfo]
    v 16041215155792 swi_service.exe:002244:001028 [SymmetricKey 3b 15 7d 59 3c 1e e2 65 25 ff 69 11 1e 9d 66 f9 1a e7 a2 bc].sign(sha1=dd2294ecea9a85a7f9a2d75640c9933ea515e7b1) [SophosSymmetricKey.cpp:251 Sophos::SymmetricKey::sign]
    v 16041215155792 swi_service.exe:002244:001028 signature sha1=3bdb711e168957d1e07f5eecf67e34176263aa4a [SophosSymmetricKey.cpp:174 Sophos::SymmetricKey::impl::sign]
    v 16041215155792 swi_service.exe:002244:001028 Signed WDX header: X-Sophos-Filter: 566b1ba59834da6e4d8ad204efe44d8e7e10a873 [e53611b9-7d74-339e-b3f2-4e2addb92ca2-wdx-7d74.broker.sophos.com/wdx/policy/index.txt] [WebControlSync.cpp:543 WebControlSync::signWdxRequestHeaders]
    v 16041215155792 swi_service.exe:002244:001028 [PROXY:AUTODETECT FORCE] Policy: GET e53611b9-7d74-339e-b3f2-4e2addb92ca2-wdx-7d74.broker.sophos.com/.../index.txt [WebControlSync.cpp:640 WebControlSync::startPolicy]
    v 16041215155792 swi_service.exe:002244:001028 NOT resetting failure count -- intermediate proxy failure [WebControlSync.cpp:825 WebControlSync::httpEventCallback]
    I 16041215155792 swi_service.exe:002244:001310 20160412 151557.922 T00001310 ------ 3 - Processing request=195\n [oem-log.cpp:29 oem_log]
    I 16041215155798 swi_service.exe:002244:001310 20160412 151557.984 T00001310 ------ 3 - Queueing request 195\n [oem-log.cpp:29 oem_log]
    I 16041215155798 swi_service.exe:002244:0001f4 20160412 151557.984 T000001f4 ------ 3 - Processing request=195, 00F32270\n [oem-log.cpp:29 oem_log]
    A 16041215155865 swi_service.exe:002244:0001f4 20160412 151558.655 T000001f4 ------ 2 - Send request (WinHttpReceiveResponse) error 12152: The server returned an invalid or unrecognized response\n [oem-log.cpp:25 oem_log]

    It appears I am unable to download the index.txt file from Sophos, but I can't figure out as to why (or if it's an issue on my end or there end).  I am still not seeing any data and my web protection still does not work on 9.4.

Children
No Data