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

Slow Browsing after enabling security features

Hi!

We are testing a Sophos XG 230 Firewall. Internet access works but when we enable something like HTTPS Scan or Web policy or prevention internet speed extremly slows down. Especially HTTPS websites take 20-30 sec. to load.

I already checked various posts on that topic - they all point to DNS errors, so I checked DNS:

  • Static DNS is configured with 2 IPv4-DNS servers from our ISP.
  • Testing DNS name resolution is not working!

Could it be that something is wrong with our DNS configuration? How can we use all the security features without loss of performance?



This thread was automatically locked due to age.
Parents
  • You should check quickly awarrenhttp_access.log on the CLI. There you can see exactly what is consuming time regarding your Webrequests.

  • Hi Christian!

    Can you please provide more detailed information on how to check awarrenhttp_access.log?

  • Hello Aditya,

    I followed the steps you provided, here is the log:

    XG230_WP02_SFOS 17.1.3 MR-3# tail -f /log/awarrenhttp_access.log | grep 103.23.140.55
    1543930722.681615786 [ 3735/0x7f4163a1ec00] fwid=2 fwflag="VN" iap=0 aap=0 conn_id=3998701248 id="0001" name="http access" action="pass" method="GET" srcip="192.168.30.138" dstip="54.247.166.237" user="" statuscode=200 cached=0 trxlen=199 rxlen=68 url="http.00.s.sophosxl.net/.../" referer="" type="" upload_file_name="" upload_file_type="" download_file_name="" download_file_type="" authtime=0 dnstime=6030752 cattime=0 avscantime=0 fullreqtime=6094419 ua="SXL/3.1" activity="" av_transaction_id="" categoryname="None" category="" app_id=0 app_name="None" app_cat="None" exceptions=""
    1543930722.961287601 [ 3735/0x7f416507a800] fwid=2 fwflag="VN" iap=0 aap=0 conn_id=3859885312 id="0001" name="http access" action="pass" method="GET" srcip="192.168.30.138" dstip="103.23.140.55" user="" statuscode=302 cached=0 trxlen=442 rxlen=333 url="http://103.23.140.55/" referer="" type="text/html" upload_file_name="" upload_file_type="" download_file_name="" download_file_type="" authtime=0 dnstime=0 cattime=6059672 avscantime=1752 fullreqtime=6365649 ua="Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/70.0.3538.110 Safari/537.36" activity="" av_transaction_id="" categoryname="IPAddress" category="83" app_id=0 app_name="None" app_cat="None" exceptions="" sandbox="off"
    1543930723.401867049 [ 3735/0x7f416507a800] fwid=2 fwflag="VN" iap=0 aap=0 conn_id=3859885312 id="0001" name="http access" action="pass" method="GET" srcip="192.168.30.138" dstip="103.23.140.55" user="" statuscode=200 cached=0 trxlen=455 rxlen=5454 url="103.23.140.55/.../login.php" referer="" type="text/html" upload_file_name="" upload_file_type="" download_file_name="" download_file_type="" authtime=0 dnstime=0 cattime=35337 avscantime=3946 fullreqtime=383889 ua="Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/70.0.3538.110 Safari/537.36" activity="" av_transaction_id="" categoryname="IPAddress" category="83" app_id=0 app_name="None" app_cat="None" exceptions="" sandbox="off"
    1543930723.689412147 [ 3735/0x7f416507a800] fwid=2 fwflag="VN" iap=0 aap=0 conn_id=3859885312 id="0001" name="http access" action="pass" method="GET" srcip="192.168.30.138" dstip="103.23.140.55" user="" statuscode=200 cached=0 trxlen=464 rxlen=2392 url="103.23.140.55/.../default.css" referer="103.23.140.55/.../login.php" type="text/css" upload_file_name="" upload_file_type="" download_file_name="" download_file_type="" authtime=0 dnstime=0 cattime=30 avscantime=637 fullreqtime=152894 ua="Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/70.0.3538.110 Safari/537.36" activity="" av_transaction_id="" categoryname="IPAddress" category="83" app_id=0 app_name="None" app_cat="None" exceptions="" sandbox="off"
    1543930723.887755718 [ 3735/0x7f416507a800] fwid=2 fwflag="VN" iap=0 aap=0 conn_id=3859885312 id="0001" name="http access" action="pass" method="GET" srcip="192.168.30.138" dstip="103.23.140.55" user="" statuscode=200 cached=0 trxlen=486 rxlen=440 url="103.23.140.55/.../submit.gif" referer="103.23.140.55/.../login.php" type="image/gif" upload_file_name="" upload_file_type="" download_file_name="" download_file_type="" authtime=0 dnstime=0 cattime=58 avscantime=627 fullreqtime=152632 ua="Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/70.0.3538.110 Safari/537.36" activity="" av_transaction_id="" categoryname="IPAddress" category="83" app_id=0 app_name="None" app_cat="None" exceptions="" sandbox="off"
    1543930723.968072185 [ 3735/0x7f4163a1b000] fwid=2 fwflag="VN" iap=0 aap=0 conn_id=3859887808 id="0001" name="http access" action="pass" method="GET" srcip="192.168.30.138" dstip="103.23.140.55" user="" statuscode=200 cached=0 trxlen=485 rxlen=3975 url="103.23.140.55/.../login.gif" referer="103.23.140.55/.../login.php" type="image/gif" upload_file_name="" upload_file_type="" download_file_name="" download_file_type="" authtime=0 dnstime=0 cattime=18 avscantime=620 fullreqtime=431321 ua="Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/70.0.3538.110 Safari/537.36" activity="" av_transaction_id="" categoryname="IPAddress" category="83" app_id=0 app_name="None" app_cat="None" exceptions="" sandbox="off"
    1543930723.987270920 [ 3735/0x7f416507bc00] fwid=2 fwflag="VN" iap=0 aap=0 conn_id=3998695424 id="0001" name="http access" action="pass" method="GET" srcip="192.168.30.138" dstip="103.23.140.55" user="" statuscode=200 cached=0 trxlen=488 rxlen=3561 url="103.23.140.55/.../login-02.gif" referer="103.23.140.55/.../login.php" type="image/gif" upload_file_name="" upload_file_type="" download_file_name="" download_file_type="" authtime=0 dnstime=0 cattime=57 avscantime=575 fullreqtime=451873 ua="Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/70.0.3538.110 Safari/537.36" activity="" av_transaction_id="" categoryname="IPAddress" category="83" app_id=0 app_name="None" app_cat="None" exceptions="" sandbox="off"
    1543930724.168227474 [ 3735/0x7f416513d400] fwid=2 fwflag="VN" iap=0 aap=0 conn_id=3861962752 id="0001" name="http access" action="pass" method="GET" srcip="192.168.30.138" dstip="103.23.140.55" user="" statuscode=200 cached=0 trxlen=488 rxlen=3991 url="103.23.140.55/.../login-04.gif" referer="103.23.140.55/.../login.php" type="image/gif" upload_file_name="" upload_file_type="" download_file_name="" download_file_type="" authtime=0 dnstime=0 cattime=25 avscantime=630 fullreqtime=432776 ua="Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/70.0.3538.110 Safari/537.36" activity="" av_transaction_id="" categoryname="IPAddress" category="83" app_id=0 app_name="None" app_cat="None" exceptions="" sandbox="off"
    1543930724.180107644 [ 3735/0x7f41641ee000] fwid=2 fwflag="VN" iap=0 aap=0 conn_id=3861965664 id="0001" name="http access" action="pass" method="GET" srcip="192.168.30.138" dstip="103.23.140.55" user="" statuscode=200 cached=0 trxlen=488 rxlen=5693 url="103.23.140.55/.../login-03.gif" referer="103.23.140.55/.../login.php" type="image/gif" upload_file_name="" upload_file_type="" download_file_name="" download_file_type="" authtime=0 dnstime=0 cattime=40 avscantime=617 fullreqtime=434955 ua="Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/70.0.3538.110 Safari/537.36" activity="" av_transaction_id="" categoryname="IPAddress" category="83" app_id=0 app_name="None" app_cat="None" exceptions="" sandbox="off"
    1543930724.392589213 [ 3735/0x7f41641ee000] fwid=2 fwflag="VN" iap=0 aap=0 conn_id=3861965664 id="0001" name="http access" action="pass" method="GET" srcip="192.168.30.138" dstip="103.23.140.55" user="" statuscode=404 cached=0 trxlen=474 rxlen=521 url="103.23.140.55/favicon.ico" referer="103.23.140.55/.../login.php" type="text/html" upload_file_name="" upload_file_type="" download_file_name="" download_file_type="" authtime=0 dnstime=0 cattime=57 avscantime=1691 fullreqtime=145307 ua="Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/70.0.3538.110 Safari/537.36" activity="" av_transaction_id="" categoryname="IPAddress" category="83" app_id=0 app_name="None" app_cat="None" exceptions="" sandbox="off"

  • This is quite informative. See first Package:

    authtime=0 dnstime=6030752 cattime=0 avscantime=0 fullreqtime=6094419

    This means, nearly all the time of your fullrequest is needed by DNS Categorization. You are probably using a slow DNS Server. 

     

    In your second request, there is no more DNS Resolution needed, (Because it probably allready has the IP of your Name in Cache). But here, Categorization time again is using nearly all of your Requesttime:

    authtime=0 dnstime=0 cattime=6059672 avscantime=1752 fullreqtime=6365649

    Depending on the Version, Categorization is done by DNS as well if I remember correctly.

     

    Maybe you can switch to another DNS Server, preferably the one of your ISP?

  • Hi HuberChristian ,

    Could you share the logs from the following 

    Use Advance Shell Option 5>3

    1. less /log/WINGc.log

    2. less /log/nSXLd.log

  • Here are the logs. I truncated the WINGc.log - hopefully you get the information you are looking for.

    3438.WINGc.txt

    [2018-01-09 00:38:41] <4142233536> [info] nSXLd: Parent proxy disabled
    [2018-01-09 00:38:41] <4142233536> [info] nSXLd: Cache created with maximum number of 204800 records
    [2018-01-09 00:38:41] <4142233536> [info] nSXLd: nSXLd started log level: info
    [2018-01-09 00:39:46] <4142233536> [info] nSXLd: caught SIGINT or SIGTERM signal. Stopping daemon
    [2018-01-09 00:39:46] <4142233536> [info] nSXLd: nSXLd finished
    [2018-10-04 10:29:13] <4141479872> [info] nSXLd: Parent proxy disabled
    [2018-10-04 10:29:13] <4141479872> [info] nSXLd: Cache created with maximum number of 204800 records
    [2018-10-04 10:29:13] <4141479872> [info] nSXLd: nSXLd started log level: info
    [2018-10-04 10:46:34] <4141488064> [info] nSXLd: Parent proxy disabled
    [2018-10-04 10:46:34] <4141488064> [info] nSXLd: Cache created with maximum number of 204800 records
    [2018-10-04 10:46:34] <4141488064> [info] nSXLd: nSXLd started log level: info
    [2018-10-04 10:49:49] <4141488064> [info] nSXLd: Parent proxy disabled
    [2018-10-04 10:49:49] <4141488064> [info] nSXLd: Cought SIGHUP. Configuration was reloaded with log severity: info
    [2018-10-04 10:13:02] <4141488064> [info] nSXLd: caught SIGINT or SIGTERM signal. Stopping daemon
    [2018-10-04 10:13:02] <4141488064> [info] nSXLd: nSXLd finished
    [2018-10-04 11:16:06] <140414395914432> [info] nSXLd: Parent proxy disabled
    [2018-10-04 11:16:06] <140414395914432> [info] nSXLd: Cache created with maximum number of 102400 records
    [2018-10-04 11:16:06] <140414395914432> [info] nSXLd: nSXLd started log level: info
    [2018-10-15 08:30:10] <140414395914432> [info] nSXLd: caught SIGINT or SIGTERM signal. Stopping daemon
    [2018-10-15 08:30:10] <140414395914432> [info] nSXLd: nSXLd finished
    [2018-10-15 08:32:35] <139649003874496> [info] nSXLd: Parent proxy disabled
    [2018-10-15 08:32:35] <139649003874496> [info] nSXLd: Cache created with maximum number of 102400 records
    [2018-10-15 08:32:35] <139649003874496> [info] nSXLd: nSXLd started log level: info
    [2018-10-16 09:30:23] <140128346560704> [info] nSXLd: Parent proxy disabled
    [2018-10-16 09:30:23] <140128346560704> [info] nSXLd: Cache created with maximum number of 102400 records
    [2018-10-16 09:30:23] <140128346560704> [info] nSXLd: nSXLd started log level: info
    [2018-10-22 07:09:26] <140128346560704> [info] nSXLd: caught SIGINT or SIGTERM signal. Stopping daemon
    [2018-10-22 07:09:26] <140128346560704> [info] nSXLd: nSXLd finished
    [2018-10-22 07:29:10] <139760833509568> [info] nSXLd: Parent proxy disabled
    [2018-10-22 07:29:10] <139760833509568> [info] nSXLd: Cache created with maximum number of 102400 records
    [2018-10-22 07:29:10] <139760833509568> [info] nSXLd: nSXLd started log level: info
    [2018-10-24 09:45:18] <139664994441408> [info] nSXLd: Parent proxy disabled
    [2018-10-24 09:45:18] <139664994441408> [info] nSXLd: Cache created with maximum number of 102400 records
    [2018-10-24 09:45:18] <139664994441408> [info] nSXLd: nSXLd started log level: info
    [2018-10-26 09:37:02] <140034087237824> [info] nSXLd: Parent proxy disabled
    [2018-10-26 09:37:02] <140034087237824> [info] nSXLd: Cache created with maximum number of 102400 records
    [2018-10-26 09:37:02] <140034087237824> [info] nSXLd: nSXLd started log level: info
    [2018-10-26 11:08:17] <140136532351168> [info] nSXLd: Parent proxy disabled
    [2018-10-26 11:08:17] <140136532351168> [info] nSXLd: Cache created with maximum number of 102400 records
    [2018-10-26 11:08:17] <140136532351168> [info] nSXLd: nSXLd started log level: info
    [2018-11-05 08:14:40] <139880479586496> [info] nSXLd: Parent proxy disabled
    [2018-11-05 08:14:40] <139880479586496> [info] nSXLd: Cache created with maximum number of 102400 records
    [2018-11-05 08:14:40] <139880479586496> [info] nSXLd: nSXLd started log level: info
    [2018-11-06 14:45:17] <139880479586496> [info] nSXLd: caught SIGINT or SIGTERM signal. Stopping daemon
    [2018-11-06 14:45:17] <139880479586496> [info] nSXLd: nSXLd finished
    [2018-11-19 09:28:13] <139727068072128> [info] nSXLd: Parent proxy disabled
    [2018-11-19 09:28:13] <139727068072128> [info] nSXLd: Cache created with maximum number of 102400 records
    [2018-11-19 09:28:13] <139727068072128> [info] nSXLd: nSXLd started log level: info
    [2018-11-19 10:10:13] <139727068072128> [info] nSXLd: caught SIGINT or SIGTERM signal. Stopping daemon
    [2018-11-19 10:10:13] <139727068072128> [info] nSXLd: nSXLd finished
    [2018-11-19 10:24:31] <139691304495296> [info] nSXLd: Parent proxy disabled
    [2018-11-19 10:24:32] <139691304495296> [info] nSXLd: Cache created with maximum number of 102400 records
    [2018-11-19 10:24:32] <139691304495296> [info] nSXLd: nSXLd started log level: info
    [2018-11-20 16:12:46] <140271521704128> [info] nSXLd: Parent proxy disabled
    [2018-11-20 16:12:46] <140271521704128> [info] nSXLd: Cache created with maximum number of 102400 records
    [2018-11-20 16:12:46] <140271521704128> [info] nSXLd: nSXLd started log level: info
    

  • Hi Aditya,

    did you get any further information from the logs I provided?

    Nevertheless, we changed the DNS servers to our internal servers and that seems solve the problem.

    DNS-lookup now shows results and the request time seems to be ok (before, I had a blank results page):

    Allthough I don't know why, browsing speed is now fast with enabled security features! 

  • Hi Christian,

    I'm having this exact issue. I tried changing DNS server (local, google, opendns). Usually opendns works better but the slow browsing presents randomly.

    I get the same errors when checking the tcpdump for DNS (tcpdump -ni any port 53)

       ethertype Unknown (0x0af7)

       ethertype Unknown (0x0f3e)

       ethertype Unknown (0x0f3c)

     

    Have you got a solution for this? are you using PPPoE?

  • Do you dump on a specific Interface? 

    ethertype Unknown could be a VLAN Interface and you are dumping on the hardware interface. 

  • Hi sross,

    I'm afraid I can't help you since my originally problem didn't get solved [:^)]

    We are not using PPPoE.

  • LuCar,

    I have been following this related thread:
    community.sophos.com/.../xg-blocking-dns-lookup---dns-request-timeout-error

    tcpdump for a specific VLAN does not show "ethertype Unknown".

    nslookup from the XG takes long randomly.
    Clients using the XG as DNS server are affected.
    Clients using external DNS servers resolve ok (nslookup). However, browsing randomly fails. Webfiltering is DNS based, right?

     

    I have many devices affected by this.

  • We have managed to solve this slow random DNS issue. The problem was having more than one WAN interface and only one of them having internet access.

     

    It helped having the weight of the WAN links configured but the problem still happened.

    In our scenario, it was viable to leave only one WAN interface to access the internet and set the other networks as LAN. DNS itself is directly consumed from public server.

    It worries me that XG probes all WAN interfaces to get DNS queries. Firewall rules do not affect the internal XG DNS client behaviour.

Reply
  • We have managed to solve this slow random DNS issue. The problem was having more than one WAN interface and only one of them having internet access.

     

    It helped having the weight of the WAN links configured but the problem still happened.

    In our scenario, it was viable to leave only one WAN interface to access the internet and set the other networks as LAN. DNS itself is directly consumed from public server.

    It worries me that XG probes all WAN interfaces to get DNS queries. Firewall rules do not affect the internal XG DNS client behaviour.

Children
  • Hi,

    did you set p the DNS in the XG and are you using the XG DNS in your search path?

    Ian

  • The DNS in the XG are set directly to the public servers.

    Guest clients receive the same DNS servers (public) through the DHCP.

    Only one client has the XG as the DNS server (required as the XG has 1 DNS entry registered).

    Having only one WAN interface solved all DNS problems. It wasn't a DNS problem per se. I get that I should only use WAN zones if the actually have internet access.

    I have not found a way to direct the XG DNS queries through a specific gateway.