[squid-users] alot of "vary object loop" logs in squid 3.3.9 and slow performance

From: Dr.x <ahmed.zaeem_at_netstream.ps>
Date: Tue, 5 Nov 2013 00:49:10 -0800 (PST)

hi ,

Im trying to use smp on 4 cores of server of 8 g ram
4 workers and no disk caching
Only depending on hot mem caching

Don’t know why there is log if cache.log about "vary object loop"
Here is sample of logs:

==============================
2013/11/04 14:04:56 kid3| clientProcessHit: Vary object loop!
2013/11/04 14:05:01 kid3| varyEvaluateMatch: Oops. Not a Vary object on
second attempt,
'http://50.143.6.74/admin/assets/css/mstyle_autogen_1373008461.css?load_version=2.11.0.4.1381416216'
'accept-encoding="gzip,%20deflate"'
2013/11/04 14:05:01 kid3| clientProcessHit: Vary object loop!
2013/11/04 14:05:02 kid1| varyEvaluateMatch: Oops. Not a Vary object on
second attempt,
'http://50.143.6.74/admin/assets/js/pbxlib.js?load_version=2.11.0.4.1381416216'
'accept-encoding="gzip,%20deflate"'
2013/11/04 14:05:02 kid1| clientProcessHit: Vary object loop!
2013/11/04 14:05:04 kid3| varyEvaluateMatch: Oops. Not a Vary object on
second attempt, 'http://weatherblink.wdgserv.com/weatherblink/lookup/10001'
'accept-encoding="gzip,%20deflate"'
2013/11/04 14:05:04 kid3| clientProcessHit: Vary object loop!
2013/11/04 14:05:04 kid3| varyEvaluateMatch: Oops. Not a Vary object on
second attempt, 'http://r2---sn-25auxa-b15e.c.youtube.com/crossdomain.xml'
'accept-encoding="gzip,%20deflate"'
2013/11/04 14:05:04 kid3| clientProcessHit: Vary object loop!
2013/11/04 14:05:04 kid1| varyEvaluateMatch: Oops. Not a Vary object on
second attempt, 'http://platform.twitter.com/widgets.js'
'accept-encoding="gzip,deflate"'
2013/11/04 14:05:04 kid1| clientProcessHit: Vary object loop!
2013/11/04 14:05:05 kid4| varyEvaluateMatch: Oops. Not a Vary object on
second attempt, 'http://platform.twitter.com/widgets/hub.html'
'accept-encoding="gzip,%20deflate"'
2013/11/04 14:05:05 kid4| clientProcessHit: Vary object loop!
2013/11/04 14:05:06 kid3| varyEvaluateMatch: Oops. Not a Vary object on
second attempt,
'http://api.aljazeera.net/custom/ar/feeds/aja_uselection_2012.xml' 'none'
2013/11/04 14:05:06 kid3| clientProcessHit: Vary object loop!
2013/11/04 14:05:07 kid1| varyEvaluateMatch: Oops. Not a Vary object on
second attempt,
'http://ajax.cloudflare.com/cdn-cgi/nexp/abv=616370820/cloudflare.min.js'
'accept-encoding="gzip,%20deflate"'
2013/11/04 14:05:07 kid1| clientProcessHit: Vary object loop!
2013/11/04 14:05:09 kid3| varyEvaluateMatch: Oops. Not a Vary object on
second attempt,
'http://platform.twitter.com/widgets/tweet_button.1383343979.html'
'accept-encoding="gzip,%20deflate"'
2013/11/04 14:05:09 kid3| clientProcessHit: Vary object loop!
2013/11/04 14:05:12 kid3| varyEvaluateMatch: Oops. Not a Vary object on
second attempt, 'http://r2---sn-25auxa-b15e.c.youtube.com/crossdomain.xml'
'accept-encoding="gzip,deflate,sdch"'
2013/11/04 14:05:12 kid3| clientProcessHit: Vary object loop!
2013/11/04 14:05:13 kid1| varyEvaluateMatch: Oops. Not a Vary object on
second attempt, 'http://www.delta-homes.com/static/js/base.js'
'accept-encoding="gzip,%20deflate"'
2013/11/04 14:05:13 kid1| clientProcessHit: Vary object loop!
2013/11/04 14:05:15 kid1| varyEvaluateMatch: Oops. Not a Vary object on
second attempt, 'http://r1---sn-25auxa-b15e.c.youtube.com/crossdomain.xml'
'accept-encoding="gzip,%20deflate"'
2013/11/04 14:05:15 kid1| clientProcessHit: Vary object loop!
2013/11/04 14:05:18 kid3| varyEvaluateMatch: Oops. Not a Vary object on
second attempt, 'http://wac.edgecastcdn.net/800952/a1003/app/inline.js'
'accept-encoding="gzip,%20deflate"'
2013/11/04 14:05:18 kid3| clientProcessHit: Vary object loop!
2013/11/04 14:05:18 kid4| varyEvaluateMatch: Oops. Not a Vary object on
second attempt, 'http://c.ztstatic.com/bas/www.youtube.com'
'accept-encoding="gzip,%20deflate"'
2013/11/04 14:05:18 kid4| clientProcessHit: Vary object loop!
2013/11/04 14:05:24 kid3| varyEvaluateMatch: Oops. Not a Vary object on
second attempt,
'http://ajax.googleapis.com/ajax/libs/swfobject/2/swfobject.js'
'accept-encoding="gzip,%20deflate"'
2013/11/04 14:05:24 kid3| clientProcessHit: Vary object loop!
2013/11/04 14:05:24 kid1| ctx: enter level 0:
'http://forum.aldwly.com/mwaextraedit2/gradient.js'
2013/11/04 14:05:24 kid1| WARNING: unparseable HTTP header field {cloud}
2013/11/04 14:05:25 kid3| ctx: enter level 0:
'http://forum.aldwly.com/mwaextraedit2/mwaextraedit2settings.js'
2013/11/04 14:05:25 kid3| WARNING: unparseable HTTP header field {cloud}
2013/11/04 14:05:26 kid3| ctx: exit level 0
2013/11/04 14:05:26 kid3| ctx: enter level 0:
'http://forum.aldwly.com/clientscript/vbulletin_global.js?v=384'
2013/11/04 14:05:26 kid3| WARNING: unparseable HTTP header field {cloud}
2013/11/04 14:05:26 kid3| ctx: exit level 0
2013/11/04 14:05:26 kid3| ctx: enter level 0:
'http://forum.aldwly.com/clientscript/vbulletin_important.css?v=384'
2013/11/04 14:05:26 kid3| WARNING: unparseable HTTP header field {cloud}
2013/11/04 14:05:27 kid4| ctx: enter level 0:
'http://forum.aldwly.com/clientscript/vbulletin_css/style-9aac6a24-00062.css'
2013/11/04 14:05:27 kid4| WARNING: unparseable HTTP header field {cloud}
2013/11/04 14:05:29 kid2| varyEvaluateMatch: Oops. Not a Vary object on
second attempt, 'http://r2---sn-25auxa-b15e.c.youtube.com/crossdomain.xml'
'accept-encoding="gzip,%20deflate"'
2013/11/04 14:05:29 kid2| clientProcessHit: Vary object loop!
2013/11/04 14:05:29 kid3| ctx: exit level 0
2013/11/04 14:05:29 kid3| varyEvaluateMatch: Oops. Not a Vary object on
second attempt,
'http://cdn-wac.emaratalyoum.com/res/js/jquery/jquery.validate.min.js'
'accept-encoding="gzip,deflate,sdch"'
2013/11/04 14:05:29 kid3| clientProcessHit: Vary object loop!
2013/11/04 14:05:30 kid4| ctx: exit level 0
2013/11/04 14:05:30 kid4| varyEvaluateMatch: Oops. Not a Vary object on
second attempt,
'http://cdn-wac.emaratalyoum.com/res/js/jquery/jquery.validate.min.js'
'accept-encoding="gzip,deflate,sdch"'
2013/11/04 14:05:30 kid4| clientProcessHit: Vary object loop!
2013/11/04 14:05:30 kid4| clientProcessHit: Vary object loop!
2013/11/04 14:05:30 kid2| varyEvaluateMatch: Oops. Not a Vary object on
second attempt, 'http://wac.edgecastcdn.net/800952/static/js/showads_p.js'
'accept-encoding="gzip,%20deflate"'
2013/11/04 14:05:30 kid2| clientProcessHit: Vary object loop!
2013/11/04 14:05:32 kid2| varyEvaluateMatch: Oops. Not a Vary object on
second attempt,
'http://bits.wikimedia.org/ar.wikipedia.org/load.php?debug=false&lang=ar&modules=site&only=styles&skin=vector&*'
'accept-encoding="gzip,deflate,sdch"'
2013/11/04 14:05:32 kid2| clientProcessHit: Vary object loop!
2013/11/04 14:05:35 kid3| varyEvaluateMatch: Oops. Not a Vary object on
second attempt, 'http://r1---sn-25auxa-b15e.googlevideo.com/crossdomain.xml'
'accept-encoding="gzip,%20deflate"'
2013/11/04 14:05:35 kid3| clientProcessHit: Vary object loop!
2013/11/04 14:05:35 kid4| ctx: enter level 0:
'http://up.aldwly.com/uploads/13772399462.gif'
2013/11/04 14:05:35 kid4| WARNING: unparseable HTTP header field {cloud}
2013/11/04 14:05:36 kid4| ctx: exit level 0
2013/11/04 14:05:36 kid4| varyEvaluateMatch: Oops. Not a Vary object on
second attempt, 'http://platform.twitter.com/widgets.js'
'accept-encoding="gzip,deflate,sdch"'
2013/11/04 14:05:36 kid4| clientProcessHit: Vary object loop!
2013/11/04 14:05:36 kid4| clientProcessHit: Vary object loop!
2013/11/04 14:05:38 kid3| varyEvaluateMatch: Oops. Not a Vary object on
second attempt, 'http://platform.twitter.com/widgets.js'
'accept-encoding="gzip,%20deflate"'
2013/11/04 14:05:38 kid3| clientProcessHit: Vary object loop!
2013/11/04 14:05:40 kid4| ctx: enter level 0:
'http://up.aldwly.com/uploads/13772399475.gif'
2013/11/04 14:05:40 kid4| WARNING: unparseable HTTP header field {cloud}
2013/11/04 14:05:41 kid3| ctx: enter level 0:
'http://forum.aldwly.com/clientscript/vbulletin_lightbox.js?v=384'
2013/11/04 14:05:41 kid3| WARNING: unparseable HTTP header field {cloud}
2013/11/04 14:05:41 kid2| ctx: enter level 0:
'http://forum.aldwly.com/external.php?forumids=150,-1&type=js'
2013/11/04 14:05:41 kid2| WARNING: unparseable HTTP header field {cloud}
2013/11/04 14:05:47 kid2| ctx: exit level 0
2013/11/04 14:05:47 kid2| varyEvaluateMatch: Oops. Not a Vary object on
second attempt,
'http://wac.edgecastcdn.net/800952/4598a519-865b-4bba-a806-de14b5682123-api/gcrs?v=1'
'accept-encoding="gzip,%20deflate"'
2013/11/04 14:05:47 kid2| clientProcessHit: Vary object loop!
2013/11/04 14:05:47 kid2| varyEvaluateMatch: Oops. Not a Vary object on
second attempt, 'http://fxfeeds.mozilla.com/firefox/headlines.xml'
'accept-encoding="gzip,%20deflate"'
2013/11/04 14:05:47 kid2| clientProcessHit: Vary object loop!
2013/11/04 14:05:48 kid3| ctx: exit level 0
2013/11/04 14:05:48 kid3| ctx: enter level 0:
'http://up.aldwly.com/uploads/13805124261.jpg'
2013/11/04 14:05:48 kid3| WARNING: unparseable HTTP header field {cloud}
2013/11/04 14:05:48 kid3| ctx: exit level 0
2013/11/04 14:05:48 kid3| varyEvaluateMatch: Oops. Not a Vary object on
second attempt, 'http://c.ztstatic.com/bas/www.youtube.com'
'accept-encoding="gzip,%20deflate"'
2013/11/04 14:05:48 kid3| clientProcessHit: Vary object loop!
2013/11/04 14:05:48 kid3| varyEvaluateMatch: Oops. Not a Vary object on
second attempt, 'http://wac.edgecastcdn.net/800952/a1003/app/inline.js'
'accept-encoding="gzip,%20deflate"'
2013/11/04 14:05:48 kid3| clientProcessHit: Vary object loop!
2013/11/04 14:05:49 kid2| varyEvaluateMatch: Oops. Not a Vary object on
second attempt,
'http://ajax.googleapis.com/ajax/libs/swfobject/2/swfobject.js'
'accept-encoding="gzip,%20deflate"'
2013/11/04 14:05:49 kid2| clientProcessHit: Vary object loop!
2013/11/04 14:05:50 kid4| ctx: exit level 0
2013/11/04 14:05:50 kid4| ctx: enter level 0:
'http://forum.aldwly.com/aldwle2_hexll/images/hexll_03.jpg'
2013/11/04 14:05:50 kid4| WARNING: unparseable HTTP header field {cloud}
2013/11/04 14:05:50 kid4| ctx: exit level 0
2013/11/04 14:05:50 kid4| varyEvaluateMatch: Oops. Not a Vary object on
second attempt, 'http://r1---sn-25auxa-b15e.googlevideo.com/crossdomain.xml'
'accept-encoding="gzip,%20deflate"'
2013/11/04 14:05:50 kid4| clientProcessHit: Vary object loop!
2013/11/04 14:05:50 kid2| varyEvaluateMatch: Oops. Not a Vary object on
second attempt, 'http://wac.edgecastcdn.net/800952/static/js/showads_p.js'
'accept-encoding="gzip,%20deflate"'
2013/11/04 14:05:50 kid2| clientProcessHit: Vary object loop!
2013/11/04 14:05:50 kid1| ctx: exit level 0
2013/11/04 14:05:50 kid1| varyEvaluateMatch: Oops. Not a Vary object on
second attempt, 'http://xml.weather.yahoo.com/forecastrss?p=ISXX0026&u=f'
'accept-encoding'
2013/11/04 14:05:50 kid1| clientProcessHit: Vary object loop!
===================================================================================
My squid.conf :
[root_at_squid ~]# cat /etc/squid/squid.conf #########################
dns_nameservers x.x.x.x 8.8.8.8
#####################
# Example rule allowing access from your local networks.
# Adapt to list your (internal) IP networks from where browsing # should be
allowed
acl localnet src 10.0.0.0/8 # RFC1918 possible internal network
acl localnet src 172.16.0.0/12 # RFC1918 possible internal network acl
localnet src 192.168.0.0/16 # RFC1918 possible internal network
acl localnet src fc00::/7 # RFC 4193 local private network range
acl localnet src fe80::/10 # RFC 4291 link-local (directly plugged)
machines
acl localnet src x.x.x.x
acl SSL_ports port 443
acl Safe_ports port 80 # http
acl Safe_ports port 21 # ftp
acl Safe_ports port 443 # https
acl Safe_ports port 70 # gopher
acl Safe_ports port 210 # wais
acl Safe_ports port 1025-65535 # unregistered ports
acl Safe_ports port 280 # http-mgmt
acl Safe_ports port 488 # gss-http
acl Safe_ports port 591 # filemaker
acl Safe_ports port 777 # multiling http
acl CONNECT method CONNECT

#
# Recommended minimum Access Permission configuration:
#
# Deny requests to certain unsafe ports
http_access deny !Safe_ports
#########################################################3
# 3 workers, using worker #1 as the frontend is important workers 4
cpu_affinity_map process_numbers=1,2,3,4 cores=2,4,6,8 include
/etc/squid/frontend.conf include /etc/squid/backend.conf
http_access deny all
##############################
refresh_pattern ^ftp: 1440 20% 10080
refresh_pattern ^gopher: 1440 0% 1440
refresh_pattern -i (/cgi-bin/|\?) 0 0% 0
refresh_pattern . 0 20% 4320
####################################################
max_filedescriptors 131072
max_open_disk_fds 131072
[root_at_squid ~]# cat /etc/squid/backend.conf
http_port 127.0.0.1:400${process_number}
visible_hostname backend.example.com
#################################################
cache_log /var/log/squid/backend.cache.log
access_log stdio:/var/log/squid/backend.access.log
###############################################
 [root_at_squid ~]# cat /etc/squid/frontend.conf
##############################################################################################
http_port x.x.x.x:65000
http_port x.x.x.x:3129 tproxy
acl mysubnet src x.x.x.x
http_access allow mysubnet
############################################################################################
cache_mgr zizo
cachemgr_passwd e44tr all
# add user authentication and similar options here http_access allow manager
localhost http_access allow manager mysubnet http_access allow mysubnet
manager http_access deny manager
#######################################################################
cache_mem 6000 MB
#################################################
maximum_object_size_in_memory 100 MB
minimum_object_size 0 KB
maximum_object_size 100 MB
##################################################
# the frontend requires a different name to the backend(s) visible_hostname
frontend.example.com
#######################################################################
cache_swap_low 95
cache_swap_high 99
###########################################################
server_persistent_connections off
client_persistent_connections off
quick_abort_min 0 KB
quick_abort_max 0 KB
quick_abort_pct 95
fqdncache_size 65535
ipcache_size 65535
ipcache_low 98
ipcache_high 99
#####################################################
########### WCCP2 Config#############
wccp2_router x.x.x.x
wccp_version 2
wccp2_rebuild_wait off
wccp2_forwarding_method 2
wccp2_return_method 2
wccp2_assignment_method 2
wccp2_service dynamic 92
wccp2_service_info 92 protocol=tcp flags=src_ip_hash priority=250 ports=80
wccp2_service dynamic 93 wccp2_service_info 93 protocol=tcp
flags=dst_ip_hash,ports_source priority=250 ports=80
###################################################################
cache_effective_user squid
cache_effective_group squid
#######################################################
memory_replacement_policy heap GDSF
cache_replacement_policy heap LFUDA
#######################################################

Is that natural logs or harmfull logs ???

==========================================================================
Im compile squid 3.3.9 with options :
Squid Cache: Version 3.3.9
configure options: '--build=i486-linux-gnu' '--prefix=/usr'
'--includedir=/include' '--mandir=/share/man' '--infodir=/share/info'
'--sysconfdir=/etc' '--enable-cachemgr-hostname=drx' '--localstatedir=/var'
'--libexecdir=/lib/squid' '--disable-maintainer-mode'
'--disable-dependency-tracking' '--disable-silent-rules' '--srcdir=.'
'--datadir=/usr/share/squid' '--sysconfdir=/etc/squid'
'--mandir=/usr/share/man' '--enable-inline' '--enable-async-io=8'
'--enable-storeio=ufs,aufs,diskd,rock' '--enable-removal-policies=lru,heap'
'--enable-delay-pools' '--enable-cache-digests' '--enable-underscores'
'--enable-icap-client' '--enable-follow-x-forwarded-for' '--enable-auth'
'--enable-basic-auth-helpers=LDAP,MSNT,NCSA,PAM,SASL,SMB,YP,DB,POP3,getpwnam,squid_radius_auth,multi-domain-NTLM'
'--enable-ntlm-auth-helpers=smb_lm'
'--enable-digest-auth-helpers=ldap,password'
'--enable-negotiate-auth-helpers=squid_kerb_auth'
'--enable-external-acl-helpers=ip_user,ldap_group,session,unix_group,wbinfo_group'
'--enable-arp-acl' '--enable-esi' '--disable-translation'
'--with-logdir=/var/log/squid' '--with-pidfile=/var/run/squid.pid'
'--with-filedescriptors=131072' '--with-large-files'
'--with-default-user=squid' '--enable-linux-netfilter'
'build_alias=i486-linux-gnu' 'CFLAGS=-g -O2 -g -Wall -O2' 'LDFLAGS='
'CPPFLAGS=' 'CXXFLAGS=-g -O2 -g -Wall -O2' --enable-ltdl-convenience

==================================================

with config above,
ive pumped only 500 users and i have slow browsing and youtube
interrupting ,
i tested without squid , i found that performnace is better and no youtube
interrupt

with to know wts wrong , andf wish to fix this issue and start pumping more
users to squid

regards

-----
Dr.x

--
View this message in context: http://squid-web-proxy-cache.1019090.n4.nabble.com/alot-of-vary-object-loop-logs-in-squid-3-3-9-and-slow-performance-tp4663137.html
Sent from the Squid - Users mailing list archive at Nabble.com.
Received on Tue Nov 05 2013 - 09:07:53 MST

This archive was generated by hypermail 2.2.0 : Sat Nov 09 2013 - 12:00:05 MST