[squid-users] Elapsed time for HTTPS requests

From: Nitin Chandrachoodan <nchandra_at_gmail.com>
Date: Fri, 12 Aug 2011 18:56:26 +0530

Hello,

I am running squid-2.7.STABLE7 and we are experiencing poor
performance (very slow page loads, timeouts etc.). This is in a large
campus setting with a few thousand users. One observation is that the
elapsed time for HTTPS CONNECT operations looks like below. Are these
numbers normal, or too high? Over longer durations, I find many values
clustered around 60000, 120000, 240000 etc., which makes me suspect
timeouts. The elapsed times for GET and POST are better.

For example
$ sudo tail -f /var/log/squid/access.log | grep CONNECT
1313146579.775 215331 10.91.0.31 TCP_MISS/200 27133 CONNECT
s.yimg.com:443 - DIRECT/118.214.109.227 -
1313146579.775 215346 10.91.0.31 TCP_MISS/200 34679 CONNECT
s.yimg.com:443 - DIRECT/118.214.109.227 -
1313146579.983 173857 10.91.0.31 TCP_MISS/200 281027 CONNECT
fbcdn-sphotos-a.akamaihd.net:443 - DIRECT/204.2.171.153 -
1313146580.555   9250 10.91.0.34 TCP_MISS/200 2992 CONNECT
in.data.toolbar.yahoo.com:443 - DIRECT/98.137.53.23 -
1313146580.584 338494 10.91.0.31 TCP_MISS/200 9960 CONNECT
accounts.youtube.com:443 - DIRECT/74.125.236.43 -
1313146580.620 338530 10.91.0.31 TCP_MISS/200 2655 CONNECT
ssl.google-analytics.com:443 - DIRECT/74.125.236.62 -
1313146580.650   6867 10.91.0.34 TCP_MISS/200 7611 CONNECT
login.yahoo.com:443 - DIRECT/202.86.7.110 -
1313146580.806 208366 10.91.0.31 TCP_MISS/200 7532 CONNECT
ak1s.abmr.net:443 - DIRECT/173.222.9.8 -
1313146581.534   7853 10.91.0.33 TCP_MISS/200 5963 CONNECT
login.yahoo.com:443 - DIRECT/202.86.7.110 -
1313146581.626  11838 10.91.0.32 TCP_MISS/200 3552 CONNECT
in.data.toolbar.yahoo.com:443 - DIRECT/98.137.53.23 -
1313146581.855  14871 10.91.0.33 TCP_MISS/200 45503 CONNECT
www.facebook.com:443 - DIRECT/69.171.228.11 -
1313146581.892  12052 10.91.0.33 TCP_MISS/200 18001 CONNECT
fbcdn-photos-a.akamaihd.net:443 - DIRECT/69.31.33.49 -
1313146581.939  10247 10.91.0.33 TCP_MISS/200 17345 CONNECT
fbcdn-photos-a.akamaihd.net:443 - DIRECT/69.31.33.49 -
1313146582.177  13371 10.91.0.33 TCP_MISS/200 13324 CONNECT
fbcdn-photos-a.akamaihd.net:443 - DIRECT/69.31.33.49 -
1313146582.178  12442 10.91.0.33 TCP_MISS/200 13260 CONNECT
fbcdn-photos-a.akamaihd.net:443 - DIRECT/69.31.33.25 -

and the following commands:
$ sudo tail -n 100000 /var/log/squid/access.log | awk '/GET/ {total
+=$2; c += 1}END{print c, total/c }'
89789 3819.93
$ sudo tail -n 100000 /var/log/squid/access.log | awk '/POST/ {total+=
$2; c += 1}END{print c, total/c }'
5373 3318.82
$ sudo tail -n 100000 /var/log/squid/access.log | awk '/CONNECT/{total
+= $2; c += 1}END{print c, total/c }'
4640 81533.5

As you can see, the elapsed time for CONNECT (~81s average) is far
higher than the others (about 3-4s average). Is this just due to
connections being kept alive, or is there something else
likely wrong? Also, do the average numbers for the others look normal
or are they too high?

Thanks,

Nitin Chandrachoodan
Received on Fri Aug 12 2011 - 13:26:34 MDT

This archive was generated by hypermail 2.2.0 : Fri Aug 12 2011 - 12:00:01 MDT