On 06/06/11 20:44, Alex Crow wrote:
On 06/06/11 19:19, Alex Crow wrote:
http_access deny CONNECT !SSL_ports
Apologies, I mispasted.
SSL does not work at all unless I add before this above line
http_access allow CONNECT
Cheers
Alex
Further to my original post, I've found that NTLM auth does not work
with CONNECT requests from clients in 3.2. I use a similar config to
that I'm using in production in 2.7.
I have disabled ssl-bump and dynamic SSL until I can resolve this.
I do *not* have to "add http_access allow CONNECT" before "http_access
deny CONNECT !SSL_ports " in my production config, which seems correct
as otherwise unauthorised users could use CONNECT.
Here is the config I am testing, which works fine for plain HTTP traffic:
auth_param ntlm program /usr/bin/ntlm_auth
--helper-protocol=squid-2.5-ntlmssp
auth_param ntlm children 30
auth_param basic program /usr/bin/ntlm_auth
--helper-protocol=squid-2.5-basic
auth_param basic children 30
auth_param basic realm Squid proxy-caching web server
auth_param basic credentialsttl 2 hours
external_acl_type nt_group ttl=20 children=40 %LOGIN
/usr/lib/squid3/ext_wbinfo_group_acl
acl manager proto cache_object
acl localhost src 127.0.0.1/32 ::1
acl to_localhost dst 127.0.0.0/8 0.0.0.0/32 ::1
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 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
acl AuthorizedUsers proxy_auth REQUIRED
always_direct allow all
http_access allow manager localhost
http_access deny manager
http_access deny !Safe_ports
http_access allow AuthorizedUsers
http_access deny CONNECT !SSL_ports
http_access allow localhost
http_access allow all AuthorizedUsers
http_access deny all
http_port 3128
hierarchy_stoplist cgi-bin ?
cache_mem 2048 MB
memory_replacement_policy heap GDSF
cache_replacement_policy heap LFUDA
cache_dir diskd /var/spool/squid3 360000 64 512
debug_options ALL,3
coredump_dir /var/cache
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
dns_defnames on
However CONNECT requests do not work, the client sits forever waiting
for data while squid does not match against "AuthorizedUsers" and
attempts to return an error page:
Logs are available here:
http;//www.nanogherkin.com/nonssl_cache.log.gz
http;//www.nanogherkin.com/ssl_cache.log.gz
Any help much appreciated.
Regards
Alex
You deleted an attachment from this message. The original MIME headers for the attachment were:
Content-Type: text/x-log;
name="nonssl_cache.log"
Content-Transfer-Encoding: base64
Content-Disposition: attachment;
filename="nonssl_cache.log"
2011/06/07 11:12:03.674 kid1| UFSSwapDir::maintain: /var/spool/squid3 removed 0/80 f=1.0000 max_scan=500
2011/06/07 11:12:04.677 kid1| storeMaintainSwapSpace: f=1.00, max_scan=500, max_remove=80
2011/06/07 11:12:04.677 kid1| UFSSwapDir::maintain: /var/spool/squid3 removed 0/80 f=1.0000 max_scan=500
2011/06/07 11:12:05.293 kid1| storeDirClean: Cleaning directory /var/spool/squid3/22/F6
2011/06/07 11:12:05.677 kid1| storeMaintainSwapSpace: f=1.00, max_scan=500, max_remove=80
2011/06/07 11:12:05.677 kid1| UFSSwapDir::maintain: /var/spool/squid3 removed 0/80 f=1.0000 max_scan=500
2011/06/07 11:12:06.677 kid1| storeMaintainSwapSpace: f=1.00, max_scan=500, max_remove=80
2011/06/07 11:12:06.677 kid1| UFSSwapDir::maintain: /var/spool/squid3 removed 0/80 f=1.0000 max_scan=500
2011/06/07 11:12:07.677 kid1| storeMaintainSwapSpace: f=1.00, max_scan=500, max_remove=80
2011/06/07 11:12:07.677 kid1| UFSSwapDir::maintain: /var/spool/squid3 removed 0/80 f=1.0000 max_scan=500
2011/06/07 11:12:08.677 kid1| storeMaintainSwapSpace: f=1.00, max_scan=500, max_remove=80
2011/06/07 11:12:08.677 kid1| UFSSwapDir::maintain: /var/spool/squid3 removed 0/80 f=1.0000 max_scan=500
2011/06/07 11:12:09.678 kid1| storeMaintainSwapSpace: f=1.00, max_scan=500, max_remove=80
2011/06/07 11:12:09.678 kid1| UFSSwapDir::maintain: /var/spool/squid3 removed 0/80 f=1.0000 max_scan=500
2011/06/07 11:12:10.681 kid1| storeMaintainSwapSpace: f=1.00, max_scan=500, max_remove=80
2011/06/07 11:12:10.681 kid1| UFSSwapDir::maintain: /var/spool/squid3 removed 0/80 f=1.0000 max_scan=500
2011/06/07 11:12:11.681 kid1| storeMaintainSwapSpace: f=1.00, max_scan=500, max_remove=80
2011/06/07 11:12:11.681 kid1| UFSSwapDir::maintain: /var/spool/squid3 removed 0/80 f=1.0000 max_scan=500
2011/06/07 11:12:12.681 kid1| storeMaintainSwapSpace: f=1.00, max_scan=500, max_remove=80
2011/06/07 11:12:12.681 kid1| UFSSwapDir::maintain: /var/spool/squid3 removed 0/80 f=1.0000 max_scan=500
2011/06/07 11:12:13.681 kid1| storeMaintainSwapSpace: f=1.00, max_scan=500, max_remove=80
2011/06/07 11:12:13.681 kid1| UFSSwapDir::maintain: /var/spool/squid3 removed 0/80 f=1.0000 max_scan=500
2011/06/07 11:12:14.681 kid1| storeMaintainSwapSpace: f=1.00, max_scan=500, max_remove=80
2011/06/07 11:12:14.681 kid1| UFSSwapDir::maintain: /var/spool/squid3 removed 0/80 f=1.0000 max_scan=500
2011/06/07 11:12:15.681 kid1| storeMaintainSwapSpace: f=1.00, max_scan=500, max_remove=80
2011/06/07 11:12:15.681 kid1| UFSSwapDir::maintain: /var/spool/squid3 removed 0/80 f=1.0000 max_scan=500
2011/06/07 11:12:16.681 kid1| storeMaintainSwapSpace: f=1.00, max_scan=500, max_remove=80
2011/06/07 11:12:16.722 kid1| UFSSwapDir::maintain: /var/spool/squid3 removed 0/80 f=1.0000 max_scan=500
2011/06/07 11:12:17.726 kid1| storeMaintainSwapSpace: f=1.00, max_scan=500, max_remove=80
2011/06/07 11:12:17.726 kid1| UFSSwapDir::maintain: /var/spool/squid3 removed 0/80 f=1.0000 max_scan=500
2011/06/07 11:12:18.374 kid1| TcpAcceptor.cc(185) doAccept: New connection on FD 39
2011/06/07 11:12:18.374 kid1| TcpAcceptor.cc(261) acceptNext: connection on FD 39
2011/06/07 11:12:18.374 kid1| fd_open() FD 43 HTTP Request
2011/06/07 11:12:18.374 kid1| comm.cc(1127) commSetTimeout: FD 43 timeout 900
2011/06/07 11:12:18.374 kid1| ACLChecklist::preCheck: 0x7fff41f2e060 checking 'ident_lookup_access deny all'
2011/06/07 11:12:18.374 kid1| ACLList::matches: checking all
2011/06/07 11:12:18.374 kid1| ACL::checklistMatches: checking 'all'
2011/06/07 11:12:18.374 kid1| aclIpMatchIp: '192.168.20.65:1458' found
2011/06/07 11:12:18.374 kid1| ACL::ChecklistMatches: result for 'all' is 1
2011/06/07 11:12:18.374 kid1| aclmatchAclList: 0x7fff41f2e060 returning true (AND list satisfied)
2011/06/07 11:12:18.374 kid1| ACLChecklist::markFinished: 0x7fff41f2e060 checklist processing finished
2011/06/07 11:12:18.375 kid1| comm_read_try: FD 43, size 4095, retval 205, errno 0
2011/06/07 11:12:18.375 kid1| IoCallback.cc(102) finish: called for FD 43 (0, 0)
2011/06/07 11:12:18.375 kid1| parseHttpRequest: req_hdr = {User-Agent: Mozilla/5.0 (Windows; U; Windows NT 5.1; en-GB; rv:1.9.2.13) Gecko/20101203 Firefox/3.6.13
Proxy-Connection: keep-alive
Host: bugzilla.redhat.com
}
2011/06/07 11:12:18.375 kid1| parseHttpRequest: end = {
}
2011/06/07 11:12:18.375 kid1| parseHttpRequest: prefix_sz = 205, req_line_sz = 42
2011/06/07 11:12:18.375 kid1| clientStreamInsertHead: Inserted node 0x25d5b48 with data 0x2980438 after head
2011/06/07 11:12:18.375 kid1| comm.cc(1116) commSetTimeout: FD 43 timeout 86400
2011/06/07 11:12:18.375 kid1| comm.cc(1127) commSetTimeout: FD 43 timeout 86400
2011/06/07 11:12:18.375 kid1| urlParse: Split URL 'bugzilla.redhat.com:443' into proto='', host='bugzilla.redhat.com', port='443', path=''
2011/06/07 11:12:18.375 kid1| Address.cc(399) LookupHostIP: Given Non-IP 'bugzilla.redhat.com': Name or service not known
2011/06/07 11:12:18.375 kid1| clientSetKeepaliveFlag: http_ver = 1.1
2011/06/07 11:12:18.375 kid1| clientSetKeepaliveFlag: method = CONNECT
2011/06/07 11:12:18.375 kid1| client_side.h(82) mayUseConnection: This 0x297f3c8 marked 1
2011/06/07 11:12:18.375 kid1| client_side_request.cc(149) ClientRequestContext: 0x296efb8 ClientRequestContext constructed
2011/06/07 11:12:18.376 kid1| client_side_request.cc(1336) doCallouts: Doing calloutContext->clientAccessCheck()
2011/06/07 11:12:18.376 kid1| ACLChecklist::preCheck: 0x297aba8 checking 'http_access allow manager localhost'
2011/06/07 11:12:18.376 kid1| ACLList::matches: checking manager
2011/06/07 11:12:18.376 kid1| ACL::checklistMatches: checking 'manager'
2011/06/07 11:12:18.376 kid1| ACL::ChecklistMatches: result for 'manager' is 0
2011/06/07 11:12:18.376 kid1| aclmatchAclList: 0x297aba8 returning false (AND list entry failed to match)
2011/06/07 11:12:18.376 kid1| aclmatchAclList: async=0 nodeMatched=0 async_in_progress=0 lastACLResult() = 0 finished() = 0
2011/06/07 11:12:18.376 kid1| ACLChecklist::preCheck: 0x297aba8 checking 'http_access deny manager'
2011/06/07 11:12:18.376 kid1| ACLList::matches: checking manager
2011/06/07 11:12:18.376 kid1| ACL::checklistMatches: checking 'manager'
2011/06/07 11:12:18.376 kid1| ACL::ChecklistMatches: result for 'manager' is 0
2011/06/07 11:12:18.376 kid1| aclmatchAclList: 0x297aba8 returning false (AND list entry failed to match)
2011/06/07 11:12:18.376 kid1| aclmatchAclList: async=0 nodeMatched=0 async_in_progress=0 lastACLResult() = 0 finished() = 0
2011/06/07 11:12:18.376 kid1| ACLChecklist::preCheck: 0x297aba8 checking 'http_access deny !Safe_ports'
2011/06/07 11:12:18.376 kid1| ACLList::matches: checking !Safe_ports
2011/06/07 11:12:18.376 kid1| ACL::checklistMatches: checking 'Safe_ports'
2011/06/07 11:12:18.376 kid1| ACL::ChecklistMatches: result for 'Safe_ports' is 1
2011/06/07 11:12:18.376 kid1| aclmatchAclList: 0x297aba8 returning false (AND list entry failed to match)
2011/06/07 11:12:18.376 kid1| aclmatchAclList: async=0 nodeMatched=0 async_in_progress=0 lastACLResult() = 0 finished() = 0
2011/06/07 11:12:18.376 kid1| ACLChecklist::preCheck: 0x297aba8 checking 'http_access deny CONNECT !SSL_ports'
2011/06/07 11:12:18.376 kid1| ACLList::matches: checking CONNECT
2011/06/07 11:12:18.376 kid1| ACL::checklistMatches: checking 'CONNECT'
2011/06/07 11:12:18.376 kid1| ACL::ChecklistMatches: result for 'CONNECT' is 1
2011/06/07 11:12:18.376 kid1| ACLList::matches: checking !SSL_ports
2011/06/07 11:12:18.376 kid1| ACL::checklistMatches: checking 'SSL_ports'
2011/06/07 11:12:18.376 kid1| ACL::ChecklistMatches: result for 'SSL_ports' is 1
2011/06/07 11:12:18.376 kid1| aclmatchAclList: 0x297aba8 returning false (AND list entry failed to match)
2011/06/07 11:12:18.376 kid1| aclmatchAclList: async=0 nodeMatched=0 async_in_progress=0 lastACLResult() = 0 finished() = 0
2011/06/07 11:12:18.376 kid1| ACLChecklist::preCheck: 0x297aba8 checking 'http_access allow localhost'
2011/06/07 11:12:18.376 kid1| ACLList::matches: checking localhost
2011/06/07 11:12:18.376 kid1| ACL::checklistMatches: checking 'localhost'
2011/06/07 11:12:18.376 kid1| aclIpMatchIp: '192.168.20.65:1458' NOT found
2011/06/07 11:12:18.376 kid1| ACL::ChecklistMatches: result for 'localhost' is 0
2011/06/07 11:12:18.376 kid1| aclmatchAclList: 0x297aba8 returning false (AND list entry failed to match)
2011/06/07 11:12:18.376 kid1| aclmatchAclList: async=0 nodeMatched=0 async_in_progress=0 lastACLResult() = 0 finished() = 0
2011/06/07 11:12:18.376 kid1| ACLChecklist::preCheck: 0x297aba8 checking 'http_access allow all AuthorizedUsers'
2011/06/07 11:12:18.376 kid1| ACLList::matches: checking all
2011/06/07 11:12:18.377 kid1| ACL::checklistMatches: checking 'all'
2011/06/07 11:12:18.377 kid1| aclIpMatchIp: '192.168.20.65:1458' found
2011/06/07 11:12:18.377 kid1| ACL::ChecklistMatches: result for 'all' is 1
2011/06/07 11:12:18.377 kid1| ACLList::matches: checking AuthorizedUsers
2011/06/07 11:12:18.377 kid1| ACL::checklistMatches: checking 'AuthorizedUsers'
2011/06/07 11:12:18.377 kid1| ACL::ChecklistMatches: result for 'AuthorizedUsers' is 0
2011/06/07 11:12:18.377 kid1| aclmatchAclList: 0x297aba8 returning false (AND list entry failed to match)
2011/06/07 11:12:18.377 kid1| ACLChecklist::markFinished: 0x297aba8 checklist processing finished
2011/06/07 11:12:18.377 kid1| aclmatchAclList: async=1 nodeMatched=0 async_in_progress=0 lastACLResult() = 0 finished() = 1
2011/06/07 11:12:18.377 kid1| ACLChecklist::check: 0x297aba8 match found, calling back with 2
2011/06/07 11:12:18.377 kid1| ACLChecklist::checkCallback: 0x297aba8 answer=2
2011/06/07 11:12:18.377 kid1| The request CONNECT bugzilla.redhat.com:443 is DENIED, because it matched 'AuthorizedUsers'
2011/06/07 11:12:18.377 kid1| storeCreateEntry: 'bugzilla.redhat.com:443'
2011/06/07 11:12:18.377 kid1| store.cc(368) StoreEntry: new StoreEntry 0x29f3f40
2011/06/07 11:12:18.377 kid1| MemObject.cc(76) MemObject: new MemObject 0x29f3c80
2011/06/07 11:12:18.377 kid1| storeKeyPrivate: CONNECT bugzilla.redhat.com:443
2011/06/07 11:12:18.377 kid1| StoreEntry::hashInsert: Inserting Entry 0x29f3f40 key 'E43AA60603673EF2773D77F1E85E7283'
2011/06/07 11:12:18.377 kid1| StoreEntry::setReleaseFlag: 'E43AA60603673EF2773D77F1E85E7283'
2011/06/07 11:12:18.377 kid1| StoreEntry::lock: key 'E43AA60603673EF2773D77F1E85E7283' count=2
2011/06/07 11:12:18.377 kid1| errorpage.cc(1190) BuildContent: No existing error page language negotiated for ERR_CACHE_ACCESS_DENIED. Using default error file.
2011/06/07 11:12:18.377 kid1| errorConvert: %%l --> '/*
Stylesheet for Squid Error pages
Adapted from design by Free CSS Templates
http://www.freecsstemplates.org
Released for free under a Creative Commons Attribution 2.5 License
*/
/* Page basics */
* {
font-family: verdana, sans-serif;
}
html body {
margin: 0;
padding: 0;
background: #efefef;
font-size: 12px;
color: #1e1e1e;
}
/* Page displayed title area */
#titles {
margin-left: 15px;
padding: 10px;
padding-left: 100px;
background: url('http://www.squid-cache.org/Artwork/SN.png') no-repeat left;
}
/* initial title */
#titles h1 {
color: #000000;
}
#titles h2 {
color: #000000;
}
/* special event: FTP success page titles */
#titles ftpsuccess {
background-color:#00ff00;
width:100%;
}
/* Page displayed body content area */
#content {
padding: 10px;
background: #ffffff;
}
/* General text */
p {
}
/* error brief description */
#error p {
}
/* some data which may have caused the problem */
#data {
}
/* the error message received from the system or other software */
#sysmsg {
}
pre {
font-family:sans-serif;
}
/* special event: FTP / Gopher directory listing */
#dirmsg {
font-family: courier;
color: black;
font-size: 10pt;
}
#dirlisting {
margin-left: 2%;
margin-right: 2%;
}
#dirlisting tr.entry td.icon,td.filename,td.size,td.date {
border-bottom: groove;
}
#dirlisting td.size {
width: 50px;
text-align: right;
padding-right: 5px;
}
/* horizontal lines */
hr {
margin: 0;
}
/* page displayed footer area */
#footer {
font-size: 9px;
padding-left: 10px;
}
'
2011/06/07 11:12:18.377 kid1| errorConvert: %%; --> '%;'
2011/06/07 11:12:18.377 kid1| errorConvert: %%c --> 'ERR_CACHE_ACCESS_DENIED'
2011/06/07 11:12:18.378 kid1| errorConvert: %%U --> 'https://bugzilla.redhat.com/*'
2011/06/07 11:12:18.378 kid1| errorConvert: %%U --> 'https://bugzilla.redhat.com/*'
2011/06/07 11:12:18.378 kid1| errorConvert: %%U --> 'https://bugzilla.redhat.com/*'
2011/06/07 11:12:18.378 kid1| errorConvert: %%w --> 'webmaster'
2011/06/07 11:12:18.378 kid1| errorConvert: %%W --> '?subject=CacheErrorInfo%20-%20ERR_CACHE_ACCESS_DENIED&body=CacheHost%3A%20squidcache-3%0D%0AErrPage%3A%20ERR_CACHE_ACCESS_DENIED%0D%0AErr%3A%20%5Bnone%5D%0D%0ATimeStamp%3A%20Tue,%2007%20Jun%202011%2010%3A12%3A18%20GMT%0D%0A%0D%0AClientIP%3A%20192.168.20.65%0D%0A%0D%0AHTTP%20Request%3A%0D%0ACONNECT%20%2F%20HTTP%2F1.1%0AUser-Agent%3A%20Mozilla%2F5.0%20(Windows%3B%20U%3B%20Windows%20NT%205.1%3B%20en-GB%3B%20rv%3A1.9.2.13)%20Gecko%2F20101203%20Firefox%2F3.6.13%0D%0AProxy-Connection%3A%20keep-alive%0D%0AHost%3A%20bugzilla.redhat.com%0D%0A%0D%0A%0D%0A'
2011/06/07 11:12:18.378 kid1| errorConvert: %%h --> 'squidcache-3'
2011/06/07 11:12:18.378 kid1| errorConvert: %%T --> 'Tue, 07 Jun 2011 10:12:18 GMT'
2011/06/07 11:12:18.378 kid1| errorConvert: %%h --> 'squidcache-3'
2011/06/07 11:12:18.378 kid1| errorConvert: %%s --> 'squid/3.2.0.8'
2011/06/07 11:12:18.378 kid1| errorConvert: %%c --> 'ERR_CACHE_ACCESS_DENIED'
2011/06/07 11:12:18.378 kid1| StoreEntry::replaceHttpReply: bugzilla.redhat.com:443
2011/06/07 11:12:18.378 kid1| InvokeHandlers: E43AA60603673EF2773D77F1E85E7283
2011/06/07 11:12:18.378 kid1| StoreEntry::InvokeHandlers: checking client #0
2011/06/07 11:12:18.378 kid1| storeComplete: 'E43AA60603673EF2773D77F1E85E7283'
2011/06/07 11:12:18.378 kid1| storeEntryValidLength: Checking 'E43AA60603673EF2773D77F1E85E7283'
2011/06/07 11:12:18.378 kid1| InvokeHandlers: E43AA60603673EF2773D77F1E85E7283
2011/06/07 11:12:18.378 kid1| StoreEntry::InvokeHandlers: checking client #0
2011/06/07 11:12:18.378 kid1| StoreEntry::unlock: key 'E43AA60603673EF2773D77F1E85E7283' count=1
2011/06/07 11:12:18.378 kid1| clientStreamRead: Calling 1 with cbdata 0x2981520 from node 0x25d5b48
2011/06/07 11:12:18.378 kid1| store_client::copy: E43AA60603673EF2773D77F1E85E7283, from 0, for length 4096, cb 1, cbdata 0x2980468
2011/06/07 11:12:18.378 kid1| storeClientCopy2: E43AA60603673EF2773D77F1E85E7283
2011/06/07 11:12:18.378 kid1| store_client::doCopy: Copying normal from memory
2011/06/07 11:12:18.378 kid1| The reply for CONNECT bugzilla.redhat.com:443 is ALLOWED, because it matched 'AuthorizedUsers'
2011/06/07 11:12:18.378 kid1| StoreEntry::lock: key 'E43AA60603673EF2773D77F1E85E7283' count=2
2011/06/07 11:12:18.379 kid1| clientReplyContext::sendMoreData: Appending 3399 bytes after 259 bytes of headers
2011/06/07 11:12:18.379 kid1| clientStreamCallback: Calling 1 with cbdata 0x2980438 from node 0x2952988
2011/06/07 11:12:18.379 kid1| client_side.cc(2758) clientParseRequests: Not parsing new requests, as this request may need the connection
2011/06/07 11:12:18.379 kid1| IoCallback.cc(102) finish: called for FD 43 (0, 0)
2011/06/07 11:12:18.379 kid1| client_side_reply.cc(1049) storeOKTransferDone: storeOKTransferDone out.offset=3399 objectLen()=3658 headers_sz=259
2011/06/07 11:12:18.379 kid1| ClientSocketContext::keepaliveNextRequest: FD 43
2011/06/07 11:12:18.379 kid1| clientStreamDetach: Detaching node 0x25d5b48
2011/06/07 11:12:18.379 kid1| Freeing clientStreamNode 0x25d5b48
2011/06/07 11:12:18.379 kid1| httpRequestFree: bugzilla.redhat.com:443
2011/06/07 11:12:18.379 kid1| logfile_mod_daemon_append: daemon:/var/log/squid3/access.log: appending 1 bytes
2011/06/07 11:12:18.379 kid1| logfile_mod_daemon_append: current buffer has 0 of 32768 bytes before append
2011/06/07 11:12:18.379 kid1| logfile_mod_daemon_append: daemon:/var/log/squid3/access.log: appending 112 bytes
2011/06/07 11:12:18.379 kid1| logfile_mod_daemon_append: current buffer has 1 of 32768 bytes before append
2011/06/07 11:12:18.379 kid1| logfile_mod_daemon_append: daemon:/var/log/squid3/access.log: appending 2 bytes
2011/06/07 11:12:18.379 kid1| logfile_mod_daemon_append: current buffer has 113 of 32768 bytes before append
2011/06/07 11:12:18.379 kid1| StoreEntry::unlock: key 'E43AA60603673EF2773D77F1E85E7283' count=1
2011/06/07 11:12:18.379 kid1| clientStreamAbort: Aborting stream with tail 0x2952988
2011/06/07 11:12:18.380 kid1| clientStreamDetach: Detaching node 0x2952988
2011/06/07 11:12:18.380 kid1| client_side_request.cc(137) ~ClientRequestContext: 0x296efb8 ClientRequestContext destructed
2011/06/07 11:12:18.380 kid1| clientStreamDetach: Calling 1 with cbdata 0x2981520
2011/06/07 11:12:18.380 kid1| Freeing clientStreamNode 0x2952988
2011/06/07 11:12:18.380 kid1| storeUnregister: called for 'E43AA60603673EF2773D77F1E85E7283'
2011/06/07 11:12:18.380 kid1| storePendingNClients: returning 0
2011/06/07 11:12:18.380 kid1| StoreEntry::unlock: key 'E43AA60603673EF2773D77F1E85E7283' count=0
2011/06/07 11:12:18.380 kid1| storePendingNClients: returning 0
2011/06/07 11:12:18.380 kid1| storeRelease: Releasing: 'E43AA60603673EF2773D77F1E85E7283'
2011/06/07 11:12:18.380 kid1| store.cc(390) destroyStoreEntry: destroyStoreEntry: destroying 0x29f3f48
2011/06/07 11:12:18.380 kid1| store.cc(380) destroyMemObject: destroyMemObject 0x29f3c80
2011/06/07 11:12:18.380 kid1| MemObject.cc(97) ~MemObject: del MemObject 0x29f3c80
2011/06/07 11:12:18.380 kid1| client_side.cc(1573) keepaliveNextRequest: abandoning FD 43
2011/06/07 11:12:18.380 kid1| logfileHandleWrite: daemon:/var/log/squid3/access.log: write returned 115
2011/06/07 11:12:18.729 kid1| storeMaintainSwapSpace: f=1.00, max_scan=500, max_remove=80
2011/06/07 11:12:18.729 kid1| UFSSwapDir::maintain: /var/spool/squid3 removed 0/80 f=1.0000 max_scan=500
2011/06/07 11:12:19.729 kid1| storeMaintainSwapSpace: f=1.00, max_scan=500, max_remove=80
2011/06/07 11:12:19.729 kid1| UFSSwapDir::maintain: /var/spool/squid3 removed 0/80 f=1.0000 max_scan=500
2011/06/07 11:12:20.281 kid1| statHistCopy: Dest=0xa553e8, Orig=0xaa4168
2011/06/07 11:12:20.281 kid1| statHistCopy: capacity 300 300
2011/06/07 11:12:20.281 kid1| statHistCopy: min 0.00 0.00
2011/06/07 11:12:20.281 kid1| statHistCopy: max 10800000.00 10800000.00
2011/06/07 11:12:20.281 kid1| statHistCopy: scale 18.52 18.52
2011/06/07 11:12:20.281 kid1| statHistCopy: copying 1200 bytes to 0x296fd70 from 0x27504f0
2011/06/07 11:12:20.281 kid1| statHistCopy: Dest=0xa55308, Orig=0xaa4088
2011/06/07 11:12:20.281 kid1| statHistCopy: capacity 300 300
2011/06/07 11:12:20.281 kid1| statHistCopy: min 0.00 0.00
2011/06/07 11:12:20.281 kid1| statHistCopy: max 10800000.00 10800000.00
2011/06/07 11:12:20.281 kid1| statHistCopy: scale 18.52 18.52
2011/06/07 11:12:20.281 kid1| statHistCopy: copying 1200 bytes to 0x29fc280 from 0x27509b0
2011/06/07 11:12:20.281 kid1| statHistCopy: Dest=0xa55340, Orig=0xaa40c0
2011/06/07 11:12:20.281 kid1| statHistCopy: capacity 300 300
2011/06/07 11:12:20.281 kid1| statHistCopy: min 0.00 0.00
2011/06/07 11:12:20.281 kid1| statHistCopy: max 10800000.00 10800000.00
2011/06/07 11:12:20.282 kid1| statHistCopy: scale 18.52 18.52
2011/06/07 11:12:20.282 kid1| statHistCopy: copying 1200 bytes to 0x29fc740 from 0x2750e70
2011/06/07 11:12:20.282 kid1| statHistCopy: Dest=0xa55378, Orig=0xaa40f8
2011/06/07 11:12:20.282 kid1| statHistCopy: capacity 300 300
2011/06/07 11:12:20.282 kid1| statHistCopy: min 0.00 0.00
2011/06/07 11:12:20.282 kid1| statHistCopy: max 10800000.00 10800000.00
2011/06/07 11:12:20.282 kid1| statHistCopy: scale 18.52 18.52
2011/06/07 11:12:20.282 kid1| statHistCopy: copying 1200 bytes to 0x29fcc00 from 0x2751330
2011/06/07 11:12:20.282 kid1| statHistCopy: Dest=0xa553b0, Orig=0xaa4130
2011/06/07 11:12:20.282 kid1| statHistCopy: capacity 300 300
2011/06/07 11:12:20.282 kid1| statHistCopy: min 0.00 0.00
2011/06/07 11:12:20.282 kid1| statHistCopy: max 10800000.00 10800000.00
2011/06/07 11:12:20.282 kid1| statHistCopy: scale 18.52 18.52
2011/06/07 11:12:20.282 kid1| statHistCopy: copying 1200 bytes to 0x2680c50 from 0x27517f0
2011/06/07 11:12:20.282 kid1| statHistCopy: Dest=0xa55548, Orig=0xaa42c8
2011/06/07 11:12:20.282 kid1| statHistCopy: capacity 300 300
2011/06/07 11:12:20.282 kid1| statHistCopy: min 0.00 0.00
2011/06/07 11:12:20.282 kid1| statHistCopy: max 60000000.00 60000000.00
2011/06/07 11:12:20.282 kid1| statHistCopy: scale 16.75 16.75
2011/06/07 11:12:20.282 kid1| statHistCopy: copying 1200 bytes to 0x2681110 from 0x2751cb0
2011/06/07 11:12:20.282 kid1| statHistCopy: Dest=0xa55580, Orig=0xaa4300
2011/06/07 11:12:20.282 kid1| statHistCopy: capacity 300 300
2011/06/07 11:12:20.282 kid1| statHistCopy: min 0.00 0.00
2011/06/07 11:12:20.282 kid1| statHistCopy: max 60000000.00 60000000.00
2011/06/07 11:12:20.282 kid1| statHistCopy: scale 16.75 16.75
2011/06/07 11:12:20.282 kid1| statHistCopy: copying 1200 bytes to 0x26815d0 from 0x2752170
2011/06/07 11:12:20.282 kid1| statHistCopy: Dest=0xa555d0, Orig=0xaa4350
2011/06/07 11:12:20.282 kid1| statHistCopy: capacity 300 300
2011/06/07 11:12:20.282 kid1| statHistCopy: min 0.00 0.00
2011/06/07 11:12:20.282 kid1| statHistCopy: max 600000.00 600000.00
2011/06/07 11:12:20.282 kid1| statHistCopy: scale 22.55 22.55
2011/06/07 11:12:20.282 kid1| statHistCopy: copying 1200 bytes to 0x2681a90 from 0x2752630
2011/06/07 11:12:20.282 kid1| statHistCopy: Dest=0xa55660, Orig=0xaa43e0
2011/06/07 11:12:20.282 kid1| statHistCopy: capacity 7 7
2011/06/07 11:12:20.282 kid1| statHistCopy: min -1.00 -1.00
2011/06/07 11:12:20.283 kid1| statHistCopy: max 6.00 6.00
2011/06/07 11:12:20.283 kid1| statHistCopy: scale 1.00 1.00
2011/06/07 11:12:20.283 kid1| statHistCopy: copying 28 bytes to 0x29f3d80 from 0x2752af0
2011/06/07 11:12:20.283 kid1| statHistCopy: Dest=0xa556d0, Orig=0xaa4450
2011/06/07 11:12:20.283 kid1| statHistCopy: capacity 18 18
2011/06/07 11:12:20.283 kid1| statHistCopy: min -1.00 -1.00
2011/06/07 11:12:20.283 kid1| statHistCopy: max 17.00 17.00
2011/06/07 11:12:20.283 kid1| statHistCopy: scale 1.00 1.00
2011/06/07 11:12:20.283 kid1| statHistCopy: copying 72 bytes to 0x29f1b80 from 0x2752b20
2011/06/07 11:12:20.283 kid1| statHistCopy: Dest=0xa55740, Orig=0xaa44c0
2011/06/07 11:12:20.283 kid1| statHistCopy: capacity 13 13
2011/06/07 11:12:20.283 kid1| statHistCopy: min -1.00 -1.00
2011/06/07 11:12:20.283 kid1| statHistCopy: max 12.00 12.00
2011/06/07 11:12:20.283 kid1| statHistCopy: scale 1.00 1.00
2011/06/07 11:12:20.283 kid1| statHistCopy: copying 52 bytes to 0x29db8c0 from 0x2752bc0
2011/06/07 11:12:20.283 kid1| statHistCopy: Dest=0xa55778, Orig=0xaa44f8
2011/06/07 11:12:20.283 kid1| statHistCopy: capacity 256 256
2011/06/07 11:12:20.283 kid1| statHistCopy: min 0.00 0.00
2011/06/07 11:12:20.283 kid1| statHistCopy: max 255.00 255.00
2011/06/07 11:12:20.283 kid1| statHistCopy: scale 1.00 1.00
2011/06/07 11:12:20.283 kid1| statHistCopy: copying 1024 bytes to 0x2681f50 from 0x2752c00
2011/06/07 11:12:20.296 kid1| storeDirClean: Cleaning directory /var/spool/squid3/23/F6
2011/06/07 11:12:20.729 kid1| storeMaintainSwapSpace: f=1.00, max_scan=500, max_remove=80
2011/06/07 11:12:20.729 kid1| UFSSwapDir::maintain: /var/spool/squid3 removed 0/80 f=1.0000 max_scan=500
2011/06/07 11:12:21.729 kid1| storeMaintainSwapSpace: f=1.00, max_scan=500, max_remove=80
2011/06/07 11:12:21.729 kid1| UFSSwapDir::maintain: /var/spool/squid3 removed 0/80 f=1.0000 max_scan=500
2011/06/07 11:12:22.729 kid1| storeMaintainSwapSpace: f=1.00, max_scan=500, max_remove=80
2011/06/07 11:12:22.729 kid1| UFSSwapDir::maintain: /var/spool/squid3 removed 0/80 f=1.0000 max_scan=500
2011/06/07 11:12:23.729 kid1| storeMaintainSwapSpace: f=1.00, max_scan=500, max_remove=80
2011/06/07 11:12:23.729 kid1| UFSSwapDir::maintain: /var/spool/squid3 removed 0/80 f=1.0000 max_scan=500
2011/06/07 11:12:24.729 kid1| storeMaintainSwapSpace: f=1.00, max_scan=500, max_remove=80
2011/06/07 11:12:24.730 kid1| UFSSwapDir::maintain: /var/spool/squid3 removed 0/80 f=1.0000 max_scan=500
2011/06/07 11:12:25.733 kid1| storeMaintainSwapSpace: f=1.00, max_scan=500, max_remove=80
2011/06/07 11:12:25.733 kid1| UFSSwapDir::maintain: /var/spool/squid3 removed 0/80 f=1.0000 max_scan=500
2011/06/07 11:12:26.733 kid1| storeMaintainSwapSpace: f=1.00, max_scan=500, max_remove=80
2011/06/07 11:12:26.733 kid1| UFSSwapDir::maintain: /var/spool/squid3 removed 0/80 f=1.0000 max_scan=500
2011/06/07 11:12:27.733 kid1| storeMaintainSwapSpace: f=1.00, max_scan=500, max_remove=80
2011/06/07 11:12:27.733 kid1| UFSSwapDir::maintain: /var/spool/squid3 removed 0/80 f=1.0000 max_scan=500
2011/06/07 11:12:28.733 kid1| storeMaintainSwapSpace: f=1.00, max_scan=500, max_remove=80
2011/06/07 11:12:28.733 kid1| UFSSwapDir::maintain: /var/spool/squid3 removed 0/80 f=1.0000 max_scan=500
2011/06/07 11:12:29.733 kid1| storeMaintainSwapSpace: f=1.00, max_scan=500, max_remove=80
2011/06/07 11:12:29.733 kid1| UFSSwapDir::maintain: /var/spool/squid3 removed 0/80 f=1.0000 max_scan=500
2011/06/07 11:12:30.733 kid1| storeMaintainSwapSpace: f=1.00, max_scan=500, max_remove=80
2011/06/07 11:12:30.733 kid1| UFSSwapDir::maintain: /var/spool/squid3 removed 0/80 f=1.0000 max_scan=500
2011/06/07 11:12:31.733 kid1| storeMaintainSwapSpace: f=1.00, max_scan=500, max_remove=80
2011/06/07 11:12:31.765 kid1| UFSSwapDir::maintain: /var/spool/squid3 removed 0/80 f=1.0000 max_scan=500
2011/06/07 11:12:32.765 kid1| storeMaintainSwapSpace: f=1.00, max_scan=500, max_remove=80
2011/06/07 11:12:32.765 kid1| UFSSwapDir::maintain: /var/spool/squid3 removed 0/80 f=1.0000 max_scan=500
