Squid stopped writing the log files... just for a while.

Previous Topic Next Topic
 
classic Classic list List threaded Threaded
6 messages Options
Reply | Threaded
Open this post in threaded view
|

Squid stopped writing the log files... just for a while.

Verónica Ovando

Hi all.

Squid has a strange behavior: suddenly, it stops writing the log files (access.log and cache.log) for about 30 seconds clients cannot access the cache. Because my proxy is using AD auth, I checked the link between them and is OK. During the time squid "is down", the number of ext_wbinfo_group_acl processes starts growing until Squid operates normally. My squid box has 4GB of RAM and enough disk space to store the cache.

Here is my squid.conf:

http_port 3128
############################################################################
# Administrative Parameters
############################################################################
visible_hostname Proxy-cache
cache_mgr [hidden email]
cache_effective_user proxy
error_directory /usr/share/squid3/errors/es
err_page_stylesheet /etc/squid3/style.css
############################################################################
#******************************Ports*************************************#
############################################################################
#acl manager proto cache_object
#acl all src 0.0.0.0/0.0.0.0
#acl localhost src 127.0.0.1/32
acl SSL_ports port 443
acl Safe_ports port 80
acl Safe_ports port 21
acl Safe_ports port 443
acl Safe_ports port 70 #prot gopher
acl Safe_ports port 210 #whais
acl Safe_ports port 280 #http-mgmt
acl Safe_ports port 488 #gss-http
acl Safe_ports port 591 #filemaker
acl Safe_ports port 8080
acl Safe_ports port 2481
acl Safe_ports port 20010
acl Safe_ports port 777 #multi http
#acl purge method PURGE
acl CONNECT method CONNECT
acl_uses_indirect_client on
delay_pool_uses_indirect_client on
log_uses_indirect_client on
http_access allow manager all
http_access deny manager

############################################################################
#*******************HELPERS AD**************************#
############################################################################
auth_param ntlm program /usr/bin/ntlm_auth --helper-protocol=squid-2.5-ntlmssp --DOMAIN=DOMAIN
auth_param ntlm children 300 startup=100 idle=50
auth_param ntlm keep_alive off
auth_param basic program /usr/bin/ntlm_auth --helper-protocol=squid-2.5-basic
auth_param basic children 50 startup=20 idle=10
auth_param basic realm proxy
auth_param basic credentialsttl 2 hours

###########################################################################
#****************************ACL******************************************#
###########################################################################
external_acl_type Grupos_AD ttl=10 children-max=300 children-startup=100 children-idle=150 ipv4 %LOGIN /usr/lib/squid3/ext_wbinfo_group_acl
acl proxy external Grupos_AD Users_proxy

############################################################################
#*****************************Rules***************************************#
############################################################################
acl auth proxy_auth REQUIRED
http_access deny !auth
http_access allow proxy all

http_access deny !Safe_ports
http_access deny CONNECT !SSL_PORTS
#http_access allow redlocal
http_access deny all

############################################################################
#*************************Log********************************#
############################################################################
logformat squid %ts.%03tu %6tr %>a %Ss/%03>Hs %<st %rm %ru %un %Sh/%<A %mt
cache_access_log /var/log/squid3/access.log
cache_log /var/log/squid3/cache.log
logfile_rotate 0
buffered_logs off

############################################################################
#******************Cache and memory***************************#
############################################################################
cache_dir aufs /var/spool/squid3 30000 16 256
cache_mem 1536 MB
cache_swap_low 80
cache_swap_high 95
maximum_object_size_in_memory 1024 KB
memory_cache_mode always
maximum_object_size 200 MB
minimum_object_size 0 KB
cache_replacement_policy heap GDSF
memory_replacement_policy heap GDSF
cache_store_log none
log_icp_queries off
redirect_rewrites_host_header off
fqdncache_size 51200

############################################################################
# Refresh Pattern Options
############################################################################
refresh_pattern ^ftp:       1440    20% 10080
refresh_pattern ^gopher:    1440    0%  1440
refresh_pattern -i (/cgi-bin/|\?) 0 0%  0
refresh_pattern -i \.(iso|avi|wav|mp3|mp4|mpeg|swf|flv|x-flv)$ 43200 90% 432000
refresh_pattern -i \.(gif|png|jpg|jpeg|ico)$ 43200 90% 43200
refresh_pattern -i \.(html|htm|css|js|xhtml)$ 9440 90% 43200
refresh_pattern -i \.index.(html|htm)$ 0 40% 10080
refresh_pattern -i \.(xml|flow)$ 0 90% 100000
refresh_pattern -i \.(json)$ 1440 90% 5760
refresh_pattern -i \.(bin|deb|rpm|drpm|exe|zip|tar|tgz|bz2|ipa|bz|ram|rar|bin|uxx|gz|crl|dll|hz|apk|wtex|hz|tiff)$ 43200 90% 43200
refresh_pattern -i \.(swf|js|wav|css|class|dat|zsci|do|ver|advcs|woff|eps|ttf|svg|svgz|ps|acsm|wm(a|v))$ 43200 90% 43200
#facebook
refresh_pattern ^https://*.facebook.com/* 14400 100% 4320
refresh_pattern -i \.fbcdn.net.*\.(jpg|gif|png|swf|mp3) 14400 80% 10800
refresh_pattern ^http:\/\/profile\.ak\.fbcdn.net*\.(jpg|gif|png) 14400 80% 10800
refresh_pattern fbcdn\.net.*\.(jpg|jpeg|gif|png|ico|mp3|flv) 14400 80% 20080
refresh_pattern static\.ak\.fbcdn\.net.*\.(jpg|jpeg|gif|png|ico|mp3|flv) 14400 80% 20080
#otros
refresh_pattern ^https://*.yahoo.*/.* 720 100% 4320
refresh_pattern ^https://*.gmail.*/.* 720 100% 4320
refresh_pattern ^https://*.google.*/.* 720 100% 4320
refresh_pattern ^https://*.googlesyndication.*/.* 720 100% 4320
refresh_pattern ^http://*.mercadolibre.*/.* 720 100% 4320
refresh_pattern youtube.*videoplay 14400 90% 24400
refresh_pattern youtube.*get_video 14400 90% 24400
refresh_pattern google.*videoplay  14400 90% 24400
refresh_pattern googlevideo.*get_video 14400 90% 24400
refresh_pattern -i ^https?:\/\/.*(gstatic\.com.*).* 1440 99% 14400
refresh_pattern -i ^https:\/\/.*googleapis\.com\/.*\.*\/v2\/code\.google\.com\/.*\.* 10080 80% 43200
refresh_pattern ^.*safebrowsing.*google 10080 80% 10080
refresh_pattern -i gstatic.*/.* 14400 80% 10080
refresh_pattern ytimg\.com\/.*\.(jpg|jpeg|gif|png|ico|mp3|flv|mp4) 14400 90% 24400
refresh_pattern (mt|kh|pap).*\.google\.com  14400 90% 24400
refresh_pattern (mt|kh|pap).*\.googleapis\.com 14400 90% 24400
refresh_pattern s\d+\.dotua\.org\/fsua_items.*\.(jpg|jpeg|gif|png|ico|mp3|flv|mp4) 14400 90% 24400
refresh_pattern .*static\.video\.yandex\.ru\/swf\/.*&r=.*  14400 90% 24400
refresh_pattern vec.*\.maps\.yandex\.net\/tiles\? 14400 90% 20080
refresh_pattern static.*\.maps\.yandex\. 14400 90% 20080
refresh_pattern pvec.*\.maps\.yandex\.net 14400 90% 20080
refresh_pattern lrs\.maps\.yandex\.net\/tiles\? 14400 90% 20080
refresh_pattern yandex\.st\/.*(jpg|jpeg|gif|png|ico|mp3|flv|mp4) 14400 90% 20080
refresh_pattern static\.video\.yandex\.net\/.*(jpg|jpeg|gif|png|ico|mp3|flv|mp4).* 14400 90% 20080

refresh_pattern -i \.*(.*(maps)).* 1440 99% 14400
#refresh_pattern -i (yimg|twimg)\.com\.* 1440 100%
#refresh_pattern -i (ytimg|ggpht)\.com\.* 1440 80% 129600
refresh_pattern -i (photobucket|pbsrc|flickr|yimg|ytimg|twimg|gravatar|ggpht)\.com.*\.(jp(e?g|e|2)|gif|png|tiff?|bmp|swf|mp(4|3)) 14400 99% 14400
refresh_pattern \.(ico|video-stats) 1440 99% 14400
refresh_pattern vid\.akm\.dailymotion\.com.*\.on2\? 1440 99% 14400
refresh_pattern -i \.disquscdn.\* 14400 90% 20080
#cache microsoft and adobe and other documents
refresh_pattern -i \.(ppt|pptx|doc|docx|docm|docb|dot|pdf|pub|ps)$ 100000 90% 200000 refresh-ims
refresh_pattern -i \.(xls|xlsx|xlt|xlm|xlsm|xltm|xlw|csv|txt)$ 100000 90% 200000 refresh-ims
#refresh_pattern -i windowsupdate.com/.*\.(cab|exe|msi|msu|msf|asf|wma|wmv)|dat|zip)$ 4320 80% 43200
refresh_pattern -i (.+\.||)microsoft.com/.*\.(cab|exe|dll|ms[i|u|f]|asf|wm[v|a]|dat|zip|iso|psf) 10080 100% 172800 refresh-ims
refresh_pattern -i (.+\.||)windowsupdate.com/.*\.(cab|exe|dll|ms[i|u|f]|asf|wm[v|a]|dat|zip|iso|psf) 10080 100% 172800 refresh-ims
#refresh_pattern ([^.]+.)?(download|(windows)?update).(microsoft.)?com/.*.(cab|exe|msi|msp|psf|wma|wmv|msu|msf|dat|zip) 10080 100% 43200 refresh-ims
refresh_pattern . 0 40% 40320

###########################################################################
# Other Options
###########################################################################
quick_abort_min 1024 KB
quick_abort_max 2048 KB
quick_abort_pct 90
memory_pools off
memory_pools_limit 0
ignore_unknown_nameservers on
#negative_ttl 10
request_body_max_size 0 KB
forward_timeout 4 minutes
forwarded_for off
request_header_access X-Forwarded-For deny all
read_timeout 2 minutes
request_timeout 2 minutes
client_lifetime 1 day
half_closed_clients off
shutdown_lifetime 2 second
ipcache_size 51200
ipcache_low 90
ipcache_high 95
icp_port 0
htcp_port 0
icp_access deny all
htcp_access deny all
visible_hostname proxy
client_db on
pinger_enable off
strip_query_terms on
debug_options ALL,1 33,2 28,9
coredump_dir /var/spool/squid3
read_ahead_gap 1 MB
forward_max_tries 25
###########################################################################
# DNS and FTP options
###########################################################################
ftp_passive on
ftp_sanitycheck off
ftp_telnet_protocol off
positive_dns_ttl 6 hours
dns_v4_first on
dns_timeout 2 minutes
negative_dns_ttl 300 seconds

Thanks!


--
@verovan

_______________________________________________
squid-users mailing list
[hidden email]
http://lists.squid-cache.org/listinfo/squid-users
Reply | Threaded
Open this post in threaded view
|

Re: Squid stopped writing the log files... just for a while.

Antony Stone
On Tuesday 22 August 2017 at 13:19:51, Verónica Ovando wrote:

> Hi all.
>
> Squid has a strange behavior: suddenly, it stops writing the log files
> (access.log and cache.log) for about 30 seconds clients cannot access the
> cache. Because my proxy is using AD auth, I checked the link between them
> and is OK. During the time squid "is down", the number of
> ext_wbinfo_group_acl processes starts growing until Squid operates
> normally. My squid box has 4GB of RAM and enough disk space to store the
> cache.

1. Which version of Squid?

2. What operating system / version is it running under?

3. How many clients access this proxy?

4. How many requests per {second|minute|hour} are you processing?

5. When you say "enough disk space to store the cache", what are the details?

6. 4Gbytes is not a great deal these days - how much is being used, and do you
have any swap (and is any of that being used)?

7. How often does the above behaviour occur?

8. Does it manifest itself immediately after starting Squid, or is there a
longer period where it works normally before this starts happening?

9. Does it seem to occur after any specific requests have gone through, or when
a specific request gets made?

10. What does access_log tell you about the requests immediately before, and
during, the 30 second holdup?


Antony.

--
It is also possible that putting the birds in a laboratory setting
inadvertently renders them relatively incompetent.

 - Daniel C Dennett

                                                   Please reply to the list;
                                                         please *don't* CC me.
_______________________________________________
squid-users mailing list
[hidden email]
http://lists.squid-cache.org/listinfo/squid-users
Reply | Threaded
Open this post in threaded view
|

Re: Squid stopped writing the log files... just for a while.

Verónica Ovando
>> Hi all.
>> 
>> Squid has a strange behavior: suddenly, it stops writing the log files
>> (access.log and cache.log) for about 30 seconds clients cannot access the
>> cache. Because my proxy is using AD auth, I checked the link between them
>> and is OK. During the time squid "is down", the number of
>> ext_wbinfo_group_acl processes starts growing until Squid operates
>> normally. My squid box has 4GB of RAM and enough disk space to store the
>> cache.

>1. Which version of Squid?
Squid 3.4.8

> 2. What operating system / version is it running under?
Debian Jessie 8.7

> 3. How many clients access this proxy?
About 100

> 4. How many requests per {second|minute|hour} are you processing?


> 5. When you say "enough disk space to store the cache", what are the details?
50GB

> 6. 4Gbytes is not a great deal these days - how much is being used, and do you 
have any swap (and is any of that being used)?
Squid uses about 50% of the physical memory. 8GB of swap. 

> 7. How often does the above behaviour occur?
It happens randomly. Maybe twice, three times or maybe nothing happens.

> 8. Does it manifest itself immediately after starting Squid, or is there a 
longer period where it works normally before this starts happening?
No. It happens randomly.

> 9. Does it seem to occur after any specific requests have gone through, or when 
a specific request gets made?
No. It happens randomly. I couldn't find nothing relevant about the requests. 

> 10. What does access_log tell you about the requests immediately before, and 
during, the 30 second holdup?
Nothing. Squid continues responding all the requests normally.

This is the last request until it holdups:
1503416750.346    386 192.168.0.2 TCP_REFRESH_UNMODIFIED/304 235 GET http://www.mysite.com user HIER_DIRECT/www.mysite.com -
This is the next request:
1503416781.864 141376 192.168.0.2 TCP_MISS/200 5599 CONNECT play.google.com:443 user HIER_DIRECT/play.google.com -
--
@verovan

_______________________________________________
squid-users mailing list
[hidden email]
http://lists.squid-cache.org/listinfo/squid-users
Reply | Threaded
Open this post in threaded view
|

Re: Squid stopped writing the log files... just for a while.

Antony Stone
On Wednesday 23 August 2017 at 15:26:53, Verónica Ovando wrote:

> >> Hi all.
> >>
> >> Squid has a strange behavior: suddenly, it stops writing the log files
> >> (access.log and cache.log) for about 30 seconds clients cannot access
> >> the cache.

> > 10. What does access_log tell you about the requests immediately before,
> > and during, the 30 second holdup?
>
> Nothing. Squid continues responding all the requests normally.

I'm puzzled by the two statements:

"it stops writing the log files for about 30 seconds [and] clients cannot
access the cache" and
"Squid continues responding [to] all the requests normally".

So, are you saying that Squid is processing requests and returning content
quite normally, without the users noticing any problem, and it's just that the
log files are not being written for 30 seconds or so?

Are you saying that all requests get fetched directly from the origin servers,
and the cache is not being used, for these 30 seconds?

Maybe you could clarify?

> This is the last request until it holdups:
> 1503416750.346    386 192.168.0.2 TCP_REFRESH_UNMODIFIED/304 235 GET
> http://www.mysite.com user HIER_DIRECT/www.mysite.com - This is the next
> request:
> 1503416781.864 141376 192.168.0.2 TCP_MISS/200 5599 CONNECT
> play.google.com:443 user HIER_DIRECT/play.google.com -

Okay, so I see there's a 36 second gap between those two requests; were
clients sending requests during that time?

Have you tried doing a packet capture on the Squid box's interfaces to see
whether client requests are coming in, but Squid is not sending the proxied
requests out, or whether it's sending the requests, egtting the response, but
not sending that back to the client?


Antony.

--
"In fact I wanted to be John Cleese and it took me some time to realise that
the job was already taken."

 - Douglas Adams

                                                   Please reply to the list;
                                                         please *don't* CC me.
_______________________________________________
squid-users mailing list
[hidden email]
http://lists.squid-cache.org/listinfo/squid-users
Reply | Threaded
Open this post in threaded view
|

Re: Squid stopped writing the log files... just for a while.

Amos Jeffries
Administrator
On 24/08/17 01:42, Antony Stone wrote:

> On Wednesday 23 August 2017 at 15:26:53, Verónica Ovando wrote:
>
>> This is the last request until it holdups:
>> 1503416750.346    386 192.168.0.2 TCP_REFRESH_UNMODIFIED/304 235 GET
>> http://www.mysite.com user HIER_DIRECT/www.mysite.com - This is the next
>> request:
>> 1503416781.864 141376 192.168.0.2 TCP_MISS/200 5599 CONNECT
>> play.google.com:443 user HIER_DIRECT/play.google.com -
>
> Okay, so I see there's a 36 second gap between those two requests; were
> clients sending requests during that time?
>

Ah, the second log entry is for a CONNECT tunnel that was started 111.5s
before the first request and took 140 seconds to deliver all its 5KB of
tunneled traffic.

The time it was open and not doing anything useful might be related to
the delays, but not an indicator of anything specifically related. It
could just be a client holding an HTTPS connection with keep-alive until
the TCP layer or Squids timeouts kill it.
  (The available FD slots running out temporarily, or bursts of socket
FDs going through TCP *_WAIT states could be the reason for pausing).

Amos
_______________________________________________
squid-users mailing list
[hidden email]
http://lists.squid-cache.org/listinfo/squid-users
Reply | Threaded
Open this post in threaded view
|

Re: Squid stopped writing the log files... just for a while.

Eliezer Croitoru
About the FD limit, it's pretty safe to use a big number of FD limit such as 65k(65535) for a period of time and if it works fine then leave it as is.
Is Jessie using a systemd unit file?
If it's using a system unit try to add into the service file under the service section:
[Service]
LimitNOFILE=65535

And restart the service.
Unless you will update squid it should stay there for a long time.
Then after you will identify if it works for you or not you can copy the systemd unit service file into:
/etc/systemd/system

And add save this change in it.
Then it should override the default:
/usr/lib/systemd/system/<servicename>.service
(as far as I remember)

Let us know if it works for you,
Eliezer

----
Eliezer Croitoru
Linux System Administrator
Mobile: +972-5-28704261
Email: [hidden email]



-----Original Message-----
From: squid-users [mailto:[hidden email]] On Behalf Of Amos Jeffries
Sent: Wednesday, August 23, 2017 22:58
To: [hidden email]
Subject: Re: [squid-users] Squid stopped writing the log files... just for a while.

On 24/08/17 01:42, Antony Stone wrote:

> On Wednesday 23 August 2017 at 15:26:53, Verónica Ovando wrote:
>
>> This is the last request until it holdups:
>> 1503416750.346    386 192.168.0.2 TCP_REFRESH_UNMODIFIED/304 235 GET
>> http://www.mysite.com user HIER_DIRECT/www.mysite.com - This is the next
>> request:
>> 1503416781.864 141376 192.168.0.2 TCP_MISS/200 5599 CONNECT
>> play.google.com:443 user HIER_DIRECT/play.google.com -
>
> Okay, so I see there's a 36 second gap between those two requests; were
> clients sending requests during that time?
>

Ah, the second log entry is for a CONNECT tunnel that was started 111.5s
before the first request and took 140 seconds to deliver all its 5KB of
tunneled traffic.

The time it was open and not doing anything useful might be related to
the delays, but not an indicator of anything specifically related. It
could just be a client holding an HTTPS connection with keep-alive until
the TCP layer or Squids timeouts kill it.
  (The available FD slots running out temporarily, or bursts of socket
FDs going through TCP *_WAIT states could be the reason for pausing).

Amos
_______________________________________________
squid-users mailing list
[hidden email]
http://lists.squid-cache.org/listinfo/squid-users

_______________________________________________
squid-users mailing list
[hidden email]
http://lists.squid-cache.org/listinfo/squid-users