(Solved) Pfsense 2.2.2 Squid3, squidGuard, every new page need to refresh twice



  • Hello all,

    i have set up box with Squid3 and SquidGuard which was working well so far. But lately, i need to refresh every new page twice to actually load. Usually at status bar it says "waiting for: www.whatever.com/jgfdj/etc". When we press F5 it loads instantly. No matter which browser, it is same. Both wired LAN or OPT1 WiFi.

    Did anyone encounter anything similar, or have any thoughts how to diagnose, or even fix the problem?

    Many thnx in avance.



  • Check your squid logs in /var/squid/logs/access.log and cache.log for clues.  Are you running transparent mode?  Are these typically HTTP or HTTPS sites?



  • Hello,

    thank you for reply. It is transparent mode. As far i can see its only HTTP which is only cached by Squid. Eg. Facebook,a nd Google are ok cause its HTTPS. Could it be that hard-drive is quite full? Does squid delete old files, etc?

    I think that either im miss-configure something, or could it be Squid Guard too? Trying to block let say advertizement and hang there?

    Ill check logs and try to figure it out. Ill try to post what i found here, i just hope it will be relevant.

    Thank you :)

    edit:
    mine access.log is 256MB and cache.log is 77MB. Is that even normal??? I dont need log since 1945. I need it last 10-30 days. How to do that?

    EDIT2: in cache log i have spam of this:

    http://pastebin.com/EnU1Uup1

    Thank you again.



  • Could it be that hard-drive is quite full?

    Perhaps.  What is your disk usage according to the System Information widget?

    Does squid delete old files, etc?

    Yes.  Part of squid's config is how big the cache is.  Default is 100MB.

    or could it be Squid Guard too? Trying to block let say advertizement and hang there?

    Again, perhaps.  I would start by disabling squidguard and see if the problem goes away or not.  I notice that the log says it can't write to squidguard.log:

    2015/06/24 07:31:51 kid1| Starting new redirector helpers...
    2015-06-24 07:31:51 [14434] /usr/local/bin/squidGuard: can't write to logfile /var/log/squidGuard/squidGuard.log
    

    This could also be a disk space issue, but I would expect a lot more to be going wrong than just double-loading a page.  Does /var/log/squidGuard/squidGuard.log exist on your system?  When was the last time it was written to?



  • Perhaps.  What is your disk usage according to the System Information widget?

    / (ufs): 92% of 218G

    This could also be a disk space issue, but I would expect a lot more to be going wrong than just double-loading a page.  Does /var/log/squidGuard/squidGuard.log exist on your system?  When was the last time it was written to?

    squidGuard.log   89 Kb 2015.06.25 15:23:48 - seems its writing to it.

    As for disabling SquidGuard i tried, then Squid process wont start. I tried even to deinstall it, - Squid wont start and http pages cannot be accessed. Only https. On one http pages i saw it says waiting for counter.yadro.ru - then i press F% and page loads instantly.

    I hope this helps?

    Thanks :)



  • I'm wondering if its time to blow away your cache and start fresh.  Stop squid and then shell in and run squid -z to recreate the cache structure.



  • Theres no way to stop it! Only way to have that process red is to uninstall SquidGuard. And when i uninstall it and execute i have this:

    $ squid -z
    2015/06/25 16:53:01| Warning: empty ACL: acl throttle_exts urlpath_regex -i "/var/squid/acl/throttle_exts.acl"
    2015/06/25 16:53:01 kid1| Warning: empty ACL: acl throttle_exts urlpath_regex -i "/var/squid/acl/throttle_exts.acl"
    2015/06/25 16:53:01 kid1| Creating missing swap directories

    How to stop it and pause it long enough? Mine Squid restarts automatically after, well, instantly.



  • Now i have

    / (ufs): 10% of 218G

    Still same issue. Really don't understand whats happening here :/



  • I'm not quite sure how you managed to execute squid -z after uninstalling squid…

    At least you have some disk space now.  Are you running squid3?  386 or x64?  Install squid3 and get it working first.  AFter installation, go to every tab in the Squid service config and click Save.  Either restart the service or reboot the unit and then check access.log, cache.log and system log.



  • I did not stop anything. I just decreased cache disk size by 90% and wait until delete it self.  Then just increased it to original size.

    Its x64 platform,

    squid3 0.2.8
    squidGuard 1.9.14

    BTW, all processes work excellent. Real time logs are showing things, both squid and Guard. Light-squid has about 8% hits. So it works, but, http sites need additional refresh to load instantly. Otherwise they never loads. Mostly all that im using just to filter insane amount adverts and some other minor things.

    Many thnx for patience trying to resolve this with me. Is there any way to to extract configuration page so it is readable in txt format? Maybe i tick something i should not?

    Thanks :)



  • There is no way to make it perform the way it is for you.  In fact, I have not heard this error before in the year that I've been hanging around here.

    Which browser are you testing with?



  • Hahahah, well theres always 1st time. If you dont believe me theres always teamviewer :)

    Im using mostly Mozilla, but its same on IE, on 4 different PCa. Both Wireless and cord connection.

    If you are curious indeed please PM me ill share mine skype data, so if you want to check, please do.

    Cheers :)



  • Next time it happens, I would let it hang and then force a refresh with F5.  Then look at access.log and see if there is anything of note that happens during that exact session.  For instance, when it hangs vs when it finishes, which file is it having a problem with?  Is it always the same file?  When you force it to load, does it pull the problem file from the cache or does it have to fetch it?



  • I dont know does it pull from cache or fetch it from net. Thing is thats happening all time. No excuse. Its not random at all.

    I just did it as you said and here is excerpt from access.log

    1435332218.630    208 192.168.1.212 TCP_REFRESH_UNMODIFIED/304 356 GET http://www.vojvodinanet.com/.s/t/841/15.gif - ORIGINAL_DST/193.109.246.48 -
    1435332218.660    231 192.168.1.212 TCP_REFRESH_UNMODIFIED/304 286 GET http://www.vojvodinanet.com/_pu/338/59272459.jpg - ORIGINAL_DST/193.109.246.48 -
    1435332218.661    227 192.168.1.212 TCP_REFRESH_UNMODIFIED/304 287 GET http://www.vojvodinanet.com/razno/Header/VN_HEDER_OKTOBAR_2013_bez_stakla.jpg - ORIGINAL_DST/193.109.246.48 -
    1435332218.681    213 192.168.1.212 TCP_MISS/304 280 GET http://www.download-baza.ucoz.com/js/hint.js - ORIGINAL_DST/193.109.246.157 -
    1435332218.961    330 192.168.1.212 TCP_REFRESH_UNMODIFIED/304 285 GET http://www.vojvodinanet.com/images/submenu-bottom.png - ORIGINAL_DST/193.109.246.48 -
    1435332218.965    336 192.168.1.212 TCP_REFRESH_UNMODIFIED/304 285 GET http://www.vojvodinanet.com/images/submenu-top.png - ORIGINAL_DST/193.109.246.48 -
    1435332218.967    337 192.168.1.212 TCP_REFRESH_UNMODIFIED/304 285 GET http://www.vojvodinanet.com/images/right.png - ORIGINAL_DST/193.109.246.48 -
    1435332218.968    307 192.168.1.212 TCP_REFRESH_UNMODIFIED/304 284 GET http://www.vojvodinanet.com/images/sep-sub.png - ORIGINAL_DST/193.109.246.48 -
    1435332218.968    339 192.168.1.212 TCP_REFRESH_UNMODIFIED/304 285 GET http://www.vojvodinanet.com/images/left.png - ORIGINAL_DST/193.109.246.48 -
    1435332218.969    307 192.168.1.212 TCP_REFRESH_UNMODIFIED/304 285 GET http://www.vojvodinanet.com/novi_smajliji/bye.gif - ORIGINAL_DST/193.109.246.48 -
    1435332219.121    363 192.168.1.212 TCP_MISS/304 280 GET http://www.download-baza.ucoz.com/js/hint.js - ORIGINAL_DST/193.109.246.157 -
    1435332219.186    225 192.168.1.212 TCP_REFRESH_UNMODIFIED/304 286 GET http://www.vojvodinanet.com/avatar/61/653217.jpg - ORIGINAL_DST/193.109.246.48 -
    1435332219.187    221 192.168.1.212 TCP_REFRESH_UNMODIFIED/304 286 GET http://www.vojvodinanet.com/avatar/34/276805.jpg - ORIGINAL_DST/193.109.246.48 -
    1435332219.187    220 192.168.1.212 TCP_MISS/304 279 GET http://www.vojvodinanet.com/novi_smajliji/smile.gif - ORIGINAL_DST/193.109.246.48 -
    1435332219.188   1199 192.168.1.212 TCP_MISS/200 10280 GET http://stattds.club/s8194/scripts/track.js? - ORIGINAL_DST/136.243.2.204 text/javascript
    1435332219.202      2 192.168.1.212 TCP_MEM_HIT/200 4523 GET http://s48.ucoz.net/a/_9/11.gif - HIER_NONE/- image/gif
    1435332219.362    161 192.168.1.212 TCP_MISS/304 280 GET http://www.download-baza.ucoz.com/js/hint.js - ORIGINAL_DST/193.109.246.157 -
    1435332219.366    124 192.168.1.212 TCP_MISS/200 412 GET http://st.stattds.club/Content/track.gif? - ORIGINAL_DST/109.206.188.63 image/gif
    1435332219.412    210 192.168.1.212 TCP_REFRESH_UNMODIFIED/304 285 GET http://www.vojvodinanet.com/novi_smajliji/mig.gif - ORIGINAL_DST/193.109.246.48 -
    1435332219.606    183 192.168.1.212 TCP_MISS/304 280 GET http://www.download-baza.ucoz.com/js/hint.js - ORIGINAL_DST/193.109.246.157 -
    1435332219.607    183 192.168.1.212 TCP_REFRESH_UNMODIFIED/304 286 GET http://www.vojvodinanet.com/avatar/47/801559.jpg - ORIGINAL_DST/193.109.246.48 -
    1435332219.677      4 192.168.1.212 TCP_MEM_HIT/200 4390 GET http://s48.ucoz.net/a/04/1057.jpg - HIER_NONE/- image/jpeg
    1435332219.678      4 192.168.1.212 TCP_MEM_HIT/200 1153 GET http://www.vojvodinanet.com/novi_smajliji/lele.gif - HIER_NONE/- image/gif
    1435332219.679      4 192.168.1.212 TCP_MEM_HIT/200 2918 GET http://www.vojvodinanet.com/novi_smajliji/ljut.gif - HIER_NONE/- image/gif
    1435332219.839    163 192.168.1.212 TCP_MISS/304 280 GET http://www.download-baza.ucoz.com/js/hint.js - ORIGINAL_DST/193.109.246.157 -
    1435332220.040    142 192.168.1.212 TCP_MISS/304 280 GET http://www.download-baza.ucoz.com/js/hint.js - ORIGINAL_DST/193.109.246.157 -
    1435332220.105      2 192.168.1.212 TCP_MEM_HIT/200 6804 GET http://www.vojvodinanet.com/novi_smajliji/yahoo.gif - HIER_NONE/- image/gif
    1435332220.254    150 192.168.1.212 TCP_MISS/304 280 GET http://www.download-baza.ucoz.com/js/hint.js - ORIGINAL_DST/193.109.246.157 -
    1435332220.255    151 192.168.1.212 TCP_REFRESH_UNMODIFIED/304 286 GET http://www.vojvodinanet.com/novi_smajliji/hug.gif - ORIGINAL_DST/193.109.246.48 -
    1435332220.454    132 192.168.1.212 TCP_MISS/304 280 GET http://www.download-baza.ucoz.com/js/hint.js - ORIGINAL_DST/193.109.246.157 -
    1435332220.661    153 192.168.1.212 TCP_MISS/304 280 GET http://www.download-baza.ucoz.com/js/hint.js - ORIGINAL_DST/193.109.246.157 -
    1435332220.661    153 192.168.1.212 TCP_REFRESH_UNMODIFIED/304 286 GET http://www.vojvodinanet.com/novi_smajliji/pospana.gif - ORIGINAL_DST/193.109.246.48 -
    1435332220.720    102 192.168.1.212 TCP_HIT/200 516334 GET http://static.tumblr.com/f11433c27576381f043a737342562ed1/z7kz7hn/BMpmmihh0/tumblr_static_tumblr_inline_mmgeczokdi1qz4rgp.gif - HIER_NONE/- image/gif
    1435332220.841    115 192.168.1.212 TCP_MISS/304 280 GET http://www.download-baza.ucoz.com/js/hint.js - ORIGINAL_DST/193.109.246.157 -
    1435332220.908      2 192.168.1.212 TCP_MEM_HIT/200 10100 GET http://www.vojvodinanet.com/razno/no_avatar.gif - HIER_NONE/- image/gif
    1435332221.077    171 192.168.1.212 TCP_MISS/304 280 GET http://www.download-baza.ucoz.com/js/hint.js - ORIGINAL_DST/193.109.246.157 -
    1435332221.343    195 192.168.1.212 TCP_MISS/304 280 GET http://www.download-baza.ucoz.com/js/hint.js - ORIGINAL_DST/193.109.246.157 -
    1435332221.376    227 192.168.1.212 TCP_REFRESH_UNMODIFIED/304 286 GET http://www.vojvodinanet.com/avatar/91/034614.jpg - ORIGINAL_DST/193.109.246.48 -
    1435332221.412      1 192.168.1.212 TCP_MEM_HIT/200 7109 GET http://www.vojvodinanet.com/avatar/04/899388.jpg - HIER_NONE/- image/jpeg
    
    


  • This tells me nothing other than a bunch of successful misses and hits.  I was hoping you would show a log where you have it hung with a timestamp, and then maybe 10 seconds later you force a refresh so I can see the entire chain of actions.  Your log shows 4 seconds worth and I can't tell when it was hung and when you did a refresh manually or anything.  For example, the session starts with your browser trying to fetch 15.gif.  I don't see another reference to that file in the rest of your log.  Try this:

    1. Look at access.log and note the timestamp on the far left
    2. In your browser, fetch a page and when it hangs, count to 10
    3. Manually refresh the page until it finishes loading
    4. Go back to access.log and copy only the part starting with timestamp from #1 to the end.  That should show the entire thing including the 10 seconds in between as a divider of the two attempts



  • Hello, thank you for your guidance. I think that i solve problem,… actually dont know what it was but. I deleted whole WiFi OPT1 requirements. Bridge, interface, rules, everything. And recreated it from scratch cause i got better WiFi card. And guess what - it works now without any issue.

    I put back old one just to be sure was it hardware issue or not, it works too. Seems that it was glitch somewhere, something, i dont know. But recreating WiFi settings it works fine again.

    Many thnx for keep pushing me to read logs, things and everything.

    Problem solved :)



  • Glad you got it working.



  • Srsly, thank you. You push me to think on this one.

    :)


Log in to reply