Search squid archive

Squid cannot parse Content-Length header value and closes connection before sending body?

[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]

 

Dear squid-users mailing list,

Thank you for reading this message and for all your hard work on this great project.

I have inherited a Squid 3.5.2 install, with ecap, icap, and custom respmod and reqmod icap services.  I am upgrading to Squid 4, adding ssl-bump, and upgrading c-icap to 0.5.2.

When I run squid without icap (by editing it out of squid.conf), things work fine and my custom client can load http and https pages.  However, for http, when I turn on icap, squid shuts down the connection early, without returning the body of the response.  It seems it cannot read the content length header and that messes up both squid and icap.  Or is there some disconnect about the 206 code from icap?  

Does anyone know what I can do to further debug or fix this issue?  Debugging info below, (sanitized so you'll see dummy names like 'custom-info').  Let me know if there is anything else I can add.

Thank you again,
-Masha

------------------------------
------------------------------
squid.conf
------------------------------
------------------------------

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 81          # http
acl Safe_ports port 800         # http
acl Safe_ports port 8000        # http
acl Safe_ports port 8080        # 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 SSL method CONNECT
acl CONNECT method CONNECT

http_access allow manager to_localhost
http_access deny manager

http_access deny !Safe_ports

http_access deny to_localhost

icp_access deny all
htcp_access deny all

http_port 172.30.0.67:80 ssl-bump cert=/some/path/etc/ca.pem generate-host-certificates=on dynamic_cert_mem_cache_size=4MB
http_port 172.30.0.67:443 ssl-bump cert=/some/path/etc/ca.pem generate-host-certificates=on dynamic_cert_mem_cache_size=4MB
acl step1 at_step SslBump1
ssl_bump peek step1
ssl_bump bump all

sslproxy_cert_error allow all

logformat custom %>a %[ui %{custom-info}>h [%tl] "%rm %ru HTTP/%rv" %>Hs %<st

access_log stdio:/some/path/var/log/access.log custom
cache_store_log stdio:/some/path/var/log/store.log custom
log_mime_hdrs on

pid_filename /some/path/var/run/custom-squid.pid

coredump_dir /some/path/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

request_header_access Proxy-Authenticate deny all
request_header_access Proxy-Authentication-Info deny all
request_header_access Proxy-Authorization deny all
request_header_access Proxy-Connection deny all
request_header_access Proxy-support deny all
request_header_access custom-client-version deny all
request_header_access custom-watermark deny all
request_header_access custom-info deny all
request_header_access more-custom-info deny all
request_header_access Via deny all
request_header_access X-Cache deny all
request_header_access X-Cache-Lookup deny all
request_header_access X-Forwarded-For deny all
reply_header_access X-XSS-Protection deny all
request_header_access Other allow all

cache_mgr cache_mgr@xxxxxxxxxxxxx
mail_from custom-squid@xxxxxxxxxxxxx
icap_enable on
icap_preview_enable on
icap_preview_size 1024
icap_default_options_ttl 60
icap_persistent_connections on
icap_send_client_ip on
icap_send_client_username on
icap_client_username_header X-Client-Username
icap_client_username_encode off

ecap_enable on
loadable_modules /some/path/modules/libcustom_ecap.so
ecap_service custom_validate_req reqmod_precache ecap://somewhere.com/ecap/services/validate routing=on bypass=off
ecap_service custom_validate_resp respmod_precache ecap://somewhere.com/ecap/services/validate routing=on bypass=off

icap_service custom_req reqmod_precache routing=on icap://127.0.0.1:1344/custom_req
icap_service custom_resp respmod_precache routing=on icap://127.0.0.1:1344/custom_resp
forwarded_for delete

adaptation_service_set custom_req_set custom_validate_req custom_req
adaptation_service_set custom_resp_set custom_validate_resp custom_resp

adaptation_access custom_req_set allow all
adaptation_access custom_resp_set allow all

icap_service_failure_limit -1

debug_options ALL,3 44,0 23,0 40,0 73,0 93,3

------------------------------
------------------------------
Abridged cache.log
------------------------------
------------------------------

2017/04/28 08:11:46.958 kid1| 11,2| client_side.cc(1330) parseHttpRequest: HTTP Client local=172.30.0.67:80 remote=75.147.129.242:55706 FD 11 flags=1
2017/04/28 08:11:46.958 kid1| 11,2| client_side.cc(1334) parseHttpRequest: HTTP Client REQUEST:
---------
GET http://example.com/ HTTP/1.1
Host: example.com
Accept: text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8
Proxy-Connection: keep-alive
Accept-Language: en-us
custom-info: <snip>
Accept-Encoding: gzip, deflate
another-custom-info: true
more-custom-info: example.com
custom-client-version: iOS-1.0
User-Agent: Mozilla/5.0 (iPhone; CPU iPhone OS 10_3 like Mac OS X) AppleWebKit/603.1.30 (KHTML, like Gecko) Mobile/14E269 (140606214001632)
Upgrade-Insecure-Requests: 1
Connection: keep-alive


----------
2017/04/28 08:11:46.958 kid1| 33,3| client_side.cc(1366) parseHttpRequest: complete request received. prefix_sz = 546, request-line-size=34, mime-header-size=512, mime header block:
Host: example.com
Accept: text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8
Proxy-Connection: keep-alive
Accept-Language: en-us
custom-info: <snip>
Accept-Encoding: gzip, deflate
another-custom-info: true
more-custom-info: example.com
custom-client-version: iOS-1.0
User-Agent: Mozilla/5.0 (iPhone; CPU iPhone OS 10_3 like Mac OS X) AppleWebKit/603.1.30 (KHTML, like Gecko) Mobile/14E269 (140606214001632)
Upgrade-Insecure-Requests: 1
Connection: keep-alive


----------
2017/04/28 08:11:46.958 kid1| 87,3| clientStream.cc(140) clientStreamInsertHead: clientStreamInsertHead: Inserted node 0x230b5f8 with data 0x2309e58 after head
2017/04/28 08:11:46.958 kid1| 5,3| comm.cc(559) commSetConnTimeout: local=172.30.0.67:80 remote=75.147.129.242:55706 FD 11 flags=1 timeout 86400
2017/04/28 08:11:46.958 kid1| 33,3| Pipeline.cc(24) add: Pipeline 0x23032c0 add request 1 0x2308df0*4
2017/04/28 08:11:46.958 kid1| 14,3| Address.cc(389) lookupHostIP: Given Non-IP 'example.com': Name or service not known
2017/04/28 08:11:46.958 kid1| 33,3| client_side.cc(646) clientSetKeepaliveFlag: http_ver = HTTP/1.1
2017/04/28 08:11:46.958 kid1| 33,3| client_side.cc(647) clientSetKeepaliveFlag: method = GET
2017/04/28 08:11:46.958 kid1| 85,3| client_side_request.cc(142) ClientRequestContext: ClientRequestContext constructed, this=0x1e94968
2017/04/28 08:11:46.958 kid1| 83,3| client_side_request.cc(1693) doCallouts: Doing calloutContext->hostHeaderVerify()
2017/04/28 08:11:46.958 kid1| 85,3| client_side_request.cc(654) hostHeaderVerify: validate host=example.com, port=0, portStr=NULL
2017/04/28 08:11:46.958 kid1| 85,3| client_side_request.cc(668) hostHeaderVerify: validate skipped.
2017/04/28 08:11:46.958 kid1| 83,3| client_side_request.cc(1700) doCallouts: Doing calloutContext->clientAccessCheck()
2017/04/28 08:11:46.958 kid1| 28,3| Checklist.cc(70) preCheck: 0x2310918 checking slow rules

<snip>

2017/04/28 08:11:47.294 kid1| 50,3| comm.cc(350) comm_openex: comm_openex: Attempt open socket for: 0.0.0.0
2017/04/28 08:11:47.294 kid1| 50,3| comm.cc(393) comm_openex: comm_openex: Opened socket local=0.0.0.0 remote=[::] FD 15 flags=1 : family=2, type=1, protocol=6
2017/04/28 08:11:47.294 kid1| 51,3| fd.cc(199) fd_open: fd_open() FD 15 example.com
2017/04/28 08:11:47.294 kid1| 5,3| ConnOpener.cc(289) createFd: local=0.0.0.0 remote=93.184.216.34:80 flags=1 will timeout in 60
2017/04/28 08:11:47.295 kid1| 17,3| AsyncCall.cc(93) ScheduleCall: ConnOpener.cc(137) will call fwdConnectDoneWrapper(local=172.30.0.67:18160 remote=93.184.216.34:80 FD 15 flags=1, data="" [call127]
2017/04/28 08:11:47.295 kid1| 17,3| AsyncCallQueue.cc(55) fireNext: entering fwdConnectDoneWrapper(local=172.30.0.67:18160 remote=93.184.216.34:80 FD 15 flags=1, data="">
2017/04/28 08:11:47.295 kid1| 17,3| AsyncCall.cc(38) make: make call fwdConnectDoneWrapper [call127]
2017/04/28 08:11:47.295 kid1| 17,3| FwdState.cc(681) connectDone: local=172.30.0.67:18160 remote=93.184.216.34:80 FD 15 flags=1: 'http://example.com/'
2017/04/28 08:11:47.295 kid1| 17,3| FwdState.cc(929) dispatch: local=172.30.0.67:80 remote=75.147.129.242:55706 FD 11 flags=1: Fetching GET http://example.com/
2017/04/28 08:11:47.295 kid1| 11,3| http.cc(2330) httpStart: GET http://example.com/
2017/04/28 08:11:47.295 kid1| 20,3| store.cc(457) lock: Client locked key 3400000000000000132A000001000000 e:=p2DIWV/0x231f010*3
2017/04/28 08:11:47.295 kid1| 17,3| AsyncCallQueue.cc(57) fireNext: leaving fwdConnectDoneWrapper(local=172.30.0.67:18160 remote=93.184.216.34:80 FD 15 flags=1, data="">
2017/04/28 08:11:47.295 kid1| 5,3| comm.cc(559) commSetConnTimeout: local=172.30.0.67:18160 remote=93.184.216.34:80 FD 15 flags=1 timeout 86400
2017/04/28 08:11:47.295 kid1| 22,3| refresh.cc(646) getMaxAge: getMaxAge: 'http://example.com/'
2017/04/28 08:11:47.295 kid1| 28,3| Checklist.cc(70) preCheck: 0x7ffdcaef6840 checking fast rules
2017/04/28 08:11:47.295 kid1| 28,3| Ip.cc(540) match: aclIpMatchIp: '75.147.129.242:55706' found
2017/04/28 08:11:47.295 kid1| 28,3| Acl.cc(290) matches: checked: all = 1
2017/04/28 08:11:47.295 kid1| 28,3| Acl.cc(290) matches: checked: http_header_access custom-info#1 = 1
2017/04/28 08:11:47.295 kid1| 28,3| Acl.cc(290) matches: checked: http_header_access custom-info = 1
2017/04/28 08:11:47.295 kid1| 28,3| Checklist.cc(63) markFinished: 0x7ffdcaef6840 answer DENIED for match
2017/04/28 08:11:47.295 kid1| 28,3| Checklist.cc(70) preCheck: 0x7ffdcaef6840 checking fast rules
2017/04/28 08:11:47.295 kid1| 28,3| Ip.cc(540) match: aclIpMatchIp: '75.147.129.242:55706' found
2017/04/28 08:11:47.295 kid1| 28,3| Acl.cc(290) matches: checked: all = 1
2017/04/28 08:11:47.295 kid1| 28,3| Acl.cc(290) matches: checked: http_header_access Other#1 = 1
2017/04/28 08:11:47.295 kid1| 28,3| Acl.cc(290) matches: checked: http_header_access Other = 1
2017/04/28 08:11:47.295 kid1| 28,3| Checklist.cc(63) markFinished: 0x7ffdcaef6840 answer ALLOWED for match
2017/04/28 08:11:47.295 kid1| 28,3| Checklist.cc(70) preCheck: 0x7ffdcaef6840 checking fast rules
2017/04/28 08:11:47.295 kid1| 28,3| Ip.cc(540) match: aclIpMatchIp: '75.147.129.242:55706' found
2017/04/28 08:11:47.295 kid1| 28,3| Acl.cc(290) matches: checked: all = 1
2017/04/28 08:11:47.295 kid1| 28,3| Acl.cc(290) matches: checked: http_header_access more-custom-info#1 = 1
2017/04/28 08:11:47.295 kid1| 28,3| Acl.cc(290) matches: checked: http_header_access more-custom-info = 1
2017/04/28 08:11:47.295 kid1| 28,3| Checklist.cc(63) markFinished: 0x7ffdcaef6840 answer DENIED for match
2017/04/28 08:11:47.295 kid1| 28,3| Checklist.cc(70) preCheck: 0x7ffdcaef6840 checking fast rules
2017/04/28 08:11:47.295 kid1| 28,3| Ip.cc(540) match: aclIpMatchIp: '75.147.129.242:55706' found
2017/04/28 08:11:47.295 kid1| 28,3| Acl.cc(290) matches: checked: all = 1
2017/04/28 08:11:47.295 kid1| 28,3| Acl.cc(290) matches: checked: http_header_access custom-client-version#1 = 1
2017/04/28 08:11:47.295 kid1| 28,3| Acl.cc(290) matches: checked: http_header_access custom-client-version = 1
2017/04/28 08:11:47.295 kid1| 28,3| Checklist.cc(63) markFinished: 0x7ffdcaef6840 answer DENIED for match
2017/04/28 08:11:47.295 kid1| 28,3| Checklist.cc(70) preCheck: 0x7ffdcaef6840 checking fast rules
2017/04/28 08:11:47.295 kid1| 28,3| Ip.cc(540) match: aclIpMatchIp: '75.147.129.242:55706' found
2017/04/28 08:11:47.295 kid1| 28,3| Acl.cc(290) matches: checked: all = 1
2017/04/28 08:11:47.295 kid1| 28,3| Acl.cc(290) matches: checked: http_header_access Other#1 = 1
2017/04/28 08:11:47.295 kid1| 28,3| Acl.cc(290) matches: checked: http_header_access Other = 1
2017/04/28 08:11:47.295 kid1| 28,3| Checklist.cc(63) markFinished: 0x7ffdcaef6840 answer ALLOWED for match
2017/04/28 08:11:47.295 kid1| 28,3| Checklist.cc(70) preCheck: 0x7ffdcaef6840 checking fast rules
2017/04/28 08:11:47.295 kid1| 28,3| Ip.cc(540) match: aclIpMatchIp: '75.147.129.242:55706' found
2017/04/28 08:11:47.295 kid1| 28,3| Acl.cc(290) matches: checked: all = 1
2017/04/28 08:11:47.295 kid1| 28,3| Acl.cc(290) matches: checked: http_header_access Via#1 = 1
2017/04/28 08:11:47.295 kid1| 28,3| Acl.cc(290) matches: checked: http_header_access Via = 1
2017/04/28 08:11:47.295 kid1| 28,3| Checklist.cc(63) markFinished: 0x7ffdcaef6840 answer DENIED for match
2017/04/28 08:11:47.295 kid1| 11,2| http.cc(2286) sendRequest: HTTP Server local=172.30.0.67:18160 remote=93.184.216.34:80 FD 15 flags=1
2017/04/28 08:11:47.295 kid1| 11,2| http.cc(2287) sendRequest: HTTP Server REQUEST:
---------
GET / HTTP/1.1
Accept: text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8
Accept-Language: en-us
Accept-Encoding: gzip, deflate
another-custom-info: true
User-Agent: Mozilla/5.0 (iPhone; CPU iPhone OS 10_3 like Mac OS X) AppleWebKit/603.1.30 (KHTML, like Gecko) Mobile/14E269 (140606214001632)
Upgrade-Insecure-Requests: 1
Host: example.com
Cache-Control: max-age=259200
Connection: keep-alive


----------
2017/04/28 08:11:47.295 kid1| 5,3| IoCallback.cc(116) finish: called for local=172.30.0.67:18160 remote=93.184.216.34:80 FD 15 flags=1 (0, 0)
2017/04/28 08:11:47.295 kid1| 5,3| comm.cc(559) commSetConnTimeout: local=172.30.0.67:18160 remote=93.184.216.34:80 FD 15 flags=1 timeout 900
2017/04/28 08:11:47.297 kid1| 5,3| IoCallback.cc(116) finish: called for local=172.30.0.67:18160 remote=93.184.216.34:80 FD 15 flags=1 (0, 0)
2017/04/28 08:11:47.297 kid1| 5,3| Read.cc(92) ReadNow: local=172.30.0.67:18160 remote=93.184.216.34:80 FD 15 flags=1, size 65536, retval 956, errno 0
2017/04/28 08:11:47.297 kid1| ctx: enter level  0: 'http://example.com/'
2017/04/28 08:11:47.297 kid1| 11,3| http.cc(692) processReplyHeader: processReplyHeader: key '3400000000000000132A000001000000'
2017/04/28 08:11:47.297 kid1| 11,2| http.cc(743) processReplyHeader: HTTP Server local=172.30.0.67:18160 remote=93.184.216.34:80 FD 15 flags=1
2017/04/28 08:11:47.297 kid1| 11,2| http.cc(747) processReplyHeader: HTTP Server RESPONSE:
---------
HTTP/1.1 200 OK
Content-Encoding: gzip
Accept-Ranges: bytes
Cache-Control: max-age=604800
Content-Type: text/html
Date: Fri, 28 Apr 2017 08:09:01 GMT
Etag: "359670651+gzip"
Expires: Fri, 05 May 2017 08:09:01 GMT
Last-Modified: Fri, 09 Aug 2013 23:54:35 GMT
Server: ECS (iad/182A)
Vary: Accept-Encoding
X-Cache: HIT
Content-Length: 606

----------
2017/04/28 08:11:47.297 kid1| 55,2| HttpHeader.cc(1483) httpHeaderNoteParsedEntry: cannot parse hdr field: 'Content-Length: 606'
2017/04/28 08:11:47.297 kid1| 55,2| HttpHeader.cc(1483) httpHeaderNoteParsedEntry: cannot parse hdr field: 'Content-Length: 606'
2017/04/28 08:11:47.297 kid1| ctx: exit level  0
2017/04/28 08:11:47.297 kid1| 28,3| Checklist.cc(70) preCheck: 0x2310918 checking slow rules
2017/04/28 08:11:47.297 kid1| 28,3| Ip.cc(540) match: aclIpMatchIp: '75.147.129.242:55706' found
2017/04/28 08:11:47.297 kid1| 28,3| Acl.cc(290) matches: checked: all = 1
2017/04/28 08:11:47.297 kid1| 28,3| Acl.cc(290) matches: checked: adaptation_access#1 = 1
2017/04/28 08:11:47.297 kid1| 28,3| Acl.cc(290) matches: checked: adaptation_access = 1
2017/04/28 08:11:47.298 kid1| 28,3| Checklist.cc(63) markFinished: 0x2310918 answer ALLOWED for match
2017/04/28 08:11:47.298 kid1| 28,3| Checklist.cc(163) checkCallback: ACLChecklist::checkCallback: 0x2310918 answer=ALLOWED
2017/04/28 08:11:47.298 kid1| 93,3| AccessCheck.cc(196) callBack: 0x1e515e0*2
2017/04/28 08:11:47.298 kid1| 11,3| http.cc(1090) persistentConnStatus: local=172.30.0.67:18160 remote=93.184.216.34:80 FD 15 flags=1 eof=0
2017/04/28 08:11:47.298 kid1| 5,3| comm.cc(585) commUnsetConnTimeout: Remove timeout for local=172.30.0.67:18160 remote=93.184.216.34:80 FD 15 flags=1
2017/04/28 08:11:47.298 kid1| 5,3| comm.cc(559) commSetConnTimeout: local=172.30.0.67:18160 remote=93.184.216.34:80 FD 15 flags=1 timeout -1
2017/04/28 08:11:47.298 kid1| 17,3| FwdState.cc(455) unregister: http://example.com/
2017/04/28 08:11:47.298 kid1| 48,3| pconn.cc(425) push: new IdleConnList for {93.184.216.34:80/example.com}
2017/04/28 08:11:47.298 kid1| 5,3| comm.cc(559) commSetConnTimeout: local=172.30.0.67:18160 remote=93.184.216.34:80 FD 15 flags=1 timeout 60
2017/04/28 08:11:47.298 kid1| 48,3| pconn.cc(437) push: pushed local=172.30.0.67:18160 remote=93.184.216.34:80 FD 15 flags=1 for 93.184.216.34:80/example.com
2017/04/28 08:11:47.298 kid1| 93,3| Iterator.cc(193) handleAdaptationError: trying a replacement service
2017/04/28 08:11:47.298 kid1| 93,3| Xaction.cc(101) Xaction: Adaptation::Icap::ModXact constructed, this=0x231b938 [icapxjob22]
2017/04/28 08:11:47.298 kid1| 93,3| Xaction.cc(101) Xaction: Adaptation::Icap::OptXact constructed, this=0x231cf78 [icapxjob24]
2017/04/28 08:11:47.298 kid1| 93,3| ServiceRep.cc(140) getConnection: got connection:
2017/04/28 08:11:47.298 kid1| 93,3| Xaction.cc(188) openConnection: Adaptation::Icap::OptXact opens connection to 127.0.0.1:1344
2017/04/28 08:11:47.298 kid1| 93,3| AsyncCall.cc(26) AsyncCall: The AsyncCall Adaptation::Icap::Xaction::noteCommConnected constructed, this=0x232bd60 [call156]
2017/04/28 08:11:47.298 kid1| 50,3| comm.cc(350) comm_openex: comm_openex: Attempt open socket for: 0.0.0.0

<snip>

2017/04/28 08:11:47.576 kid1| 93,3| AsyncCall.cc(93) ScheduleCall: IoCallback.cc(135) will call Adaptation::Icap::Xaction::noteCommRead(local=127.0.0.1:16810 remote=127.0.0.1:1344 FD 17 flags=1, data="" [call196]
2017/04/28 08:11:47.576 kid1| 93,3| AsyncCallQueue.cc(55) fireNext: entering Adaptation::Icap::Xaction::noteCommRead(local=127.0.0.1:16810 remote=127.0.0.1:1344 FD 17 flags=1, data="">
2017/04/28 08:11:47.576 kid1| 93,3| AsyncCall.cc(38) make: make call Adaptation::Icap::Xaction::noteCommRead [call196]
2017/04/28 08:11:47.576 kid1| 93,3| AsyncJob.cc(123) callStart: Adaptation::Icap::ModXact status in: [FD 17r;RrBG/wP(ieof) job26]
2017/04/28 08:11:47.576 kid1| 5,3| Read.cc(92) ReadNow: local=127.0.0.1:16810 remote=127.0.0.1:1344 FD 17 flags=1, size 65535, retval 615, errno 0
2017/04/28 08:11:47.576 kid1| 5,3| comm.cc(585) commUnsetConnTimeout: Remove timeout for local=127.0.0.1:16810 remote=127.0.0.1:1344 FD 17 flags=1
2017/04/28 08:11:47.576 kid1| 5,3| comm.cc(559) commSetConnTimeout: local=127.0.0.1:16810 remote=127.0.0.1:1344 FD 17 flags=1 timeout -1
2017/04/28 08:11:47.576 kid1| 93,3| Xaction.cc(486) noteCommRead: read 615 bytes
2017/04/28 08:11:47.576 kid1| 55,2| HttpHeader.cc(1483) httpHeaderNoteParsedEntry: cannot parse hdr field: 'Content-Length: 606'
2017/04/28 08:11:47.576 kid1| 55,2| HttpHeader.cc(1483) httpHeaderNoteParsedEntry: cannot parse hdr field: 'Content-Length: 606'
2017/04/28 08:11:47.576 kid1| 91,2| BodyPipe.cc(489) ~BodyPipeCheckout: Warning: cannot undo BodyPipeCheckout
2017/04/28 08:11:47.576 kid1| 93,3| ../../../src/base/AsyncJobCalls.h(177) dial: Adaptation::Icap::Xaction::noteCommRead threw exception: garbage instead of CRLF line terminator
2017/04/28 08:11:47.576 kid1| 93,3| Xaction.cc(591) setOutcome: Warning: reseting outcome: from ICAP_MOD to ICAP_ERR_OTHER
2017/04/28 08:11:47.576 kid1| 93,2| AsyncJob.cc(129) callException: garbage instead of CRLF line terminator
2017/04/28 08:11:47.576 kid1| 93,3| ServiceRep.cc(155) putConnection: RST-closing  [FD 17;rp(2)6/RwP(ieof)S job26]
2017/04/28 08:11:47.576 kid1| 5,3| comm.cc(865) _comm_close: comm_close: start closing FD 17
2017/04/28 08:11:47.576 kid1| 5,3| comm.cc(546) commUnsetFdTimeout: Remove timeout for FD 17
2017/04/28 08:11:47.576 kid1| 93,3| Xaction.cc(112) ~Xaction: Adaptation::Icap::ModXact destructed, this=0x231b938 [icapxjob26]
2017/04/28 08:11:47.576 kid1| 93,3| AsyncCallQueue.cc(57) fireNext: leaving Adaptation::Icap::Xaction::noteCommRead(local=127.0.0.1:16810 remote=127.0.0.1:1344 flags=1, data="">
2017/04/28 08:11:47.576 kid1| 51,3| fd.cc(94) fd_close: fd_close FD 17 127.0.0.1
2017/04/28 08:11:47.576 kid1| 20,3| store.cc(1853) replaceHttpReply: StoreEntry::replaceHttpReply: http://example.com/
2017/04/28 08:11:47.576 kid1| ctx: enter level  0: 'http://example.com/'
2017/04/28 08:11:47.576 kid1| 11,3| http.cc(934) haveParsedReplyHeaders: HTTP CODE: 200
2017/04/28 08:11:47.576 kid1| 20,3| Controller.cc(306) find: 5C9109034C1D089FB6D92F7258B2F5C3

<snip>

2017/04/28 08:11:47.576 kid1| 20,3| store_key_md5.cc(133) storeKeyPublicByRequestMethod: updating public key by vary headers: accept-encoding="gzip,%20deflate" for: http://example.com/
2017/04/28 08:11:47.577 kid1| 20,3| store.cc(421) hashInsert: StoreEntry::hashInsert: Inserting Entry e:=p2DV/0x231f010*3 key '6E5F80FC98AEE5F58F47899D580B6430'
2017/04/28 08:11:47.577 kid1| ctx: exit level  0
2017/04/28 08:11:47.577 kid1| 90,3| store_client.cc(729) invokeHandlers: InvokeHandlers: 6E5F80FC98AEE5F58F47899D580B6430
2017/04/28 08:11:47.577 kid1| 90,3| store_client.cc(735) invokeHandlers: StoreEntry::InvokeHandlers: checking client #0
2017/04/28 08:11:47.577 kid1| 90,3| store_client.cc(295) storeClientCopy2: storeClientCopy2: 6E5F80FC98AEE5F58F47899D580B6430
2017/04/28 08:11:47.577 kid1| 90,3| store_client.cc(429) scheduleMemRead: store_client::doCopy: Copying normal from memory
2017/04/28 08:11:47.577 kid1| 55,2| HttpHeader.cc(1483) httpHeaderNoteParsedEntry: cannot parse hdr field: 'Content-Length: 606'
2017/04/28 08:11:47.577 kid1| 55,2| HttpHeader.cc(1483) httpHeaderNoteParsedEntry: cannot parse hdr field: 'Content-Length: 606'
2017/04/28 08:11:47.577 kid1| 88,2| client_side_reply.cc(2084) processReplyAccessResult: The reply for GET http://example.com/ is ALLOWED, because it matched all
2017/04/28 08:11:47.577 kid1| 20,3| store.cc(457) lock: ClientHttpRequest::loggingEntry locked key 6E5F80FC98AEE5F58F47899D580B6430 e:=p2DV/0x231f010*4
2017/04/28 08:11:47.577 kid1| 88,3| client_side_reply.cc(2122) processReplyAccessResult: clientReplyContext::sendMoreData: Appending 0 bytes after 440 bytes of headers
2017/04/28 08:11:47.577 kid1| 87,3| clientStream.cc(158) clientStreamCallback: clientStreamCallback: Calling 1 with cbdata 0x2309e58 from node 0x2307b28
2017/04/28 08:11:47.577 kid1| 33,3| Pipeline.cc(35) front: Pipeline 0x23032c0 front 0x2308df0*3
2017/04/28 08:11:47.577 kid1| 33,3| Pipeline.cc(35) front: Pipeline 0x23032c0 front 0x2308df0*3
2017/04/28 08:11:47.577 kid1| 11,2| Stream.cc(266) sendStartOfMessage: HTTP Client local=172.30.0.67:80 remote=75.147.129.242:55706 FD 11 flags=1
2017/04/28 08:11:47.577 kid1| 11,2| Stream.cc(267) sendStartOfMessage: HTTP Client REPLY:
---------
HTTP/1.1 200 OK
Content-Encoding: gzip
Accept-Ranges: bytes
Cache-Control: max-age=604800
Content-Type: text/html
Date: Fri, 28 Apr 2017 08:09:01 GMT
ETag: "359670651+gzip"
Expires: Fri, 05 May 2017 08:09:01 GMT
Last-Modified: Fri, 09 Aug 2013 23:54:35 GMT
Server: ECS (iad/182A)
Vary: Accept-Encoding
X-Cache: HIT
Content-Length: 606
still-more-custom-info: ignore-value
X-Cache: MISS from ip-172-30-0-67.ec2.internal
X-Cache-Lookup: MISS from ip-172-30-0-67.ec2.internal:80
Via: ICAP/1.0 localhost (C-ICAP/0.5.2 Custom Response Module ), 1.1 ip-172-30-0-67.ec2.internal (squid/4.0.17)
Connection: keep-alive


----------
2017/04/28 08:11:47.577 kid1| 20,3| store.cc(1081) lengthWentBad: because body adaptation aborted: e:=p2DV/0x231f010*4
2017/04/28 08:11:47.577 kid1| 20,3| store.cc(472) setReleaseFlag: StoreEntry::setReleaseFlag: '6E5F80FC98AEE5F58F47899D580B6430'
2017/04/28 08:11:47.577 kid1| 20,3| store.cc(421) hashInsert: StoreEntry::hashInsert: Inserting Entry e:=p2XDIVL/0x231f010*4 key '3600000000000000132A000001000000'
2017/04/28 08:11:47.577 kid1| 17,3| FwdState.cc(481) complete: http://example.com/
status 200
2017/04/28 08:11:47.577 kid1| 17,3| FwdState.cc(1067) reforward: http://example.com/?
2017/04/28 08:11:47.577 kid1| 17,3| FwdState.cc(1070) reforward: No, ENTRY_FWD_HDR_WAIT isn't set
2017/04/28 08:11:47.577 kid1| 17,3| FwdState.cc(505) complete: server (FD closed) not re-forwarding status 200
2017/04/28 08:11:47.577 kid1| 20,3| store.cc(1089) complete: storeComplete: '3600000000000000132A000001000000'
2017/04/28 08:11:47.577 kid1| 20,2| store.cc(990) checkCachable: StoreEntry::checkCachable: NO: not cachable
2017/04/28 08:11:47.577 kid1| 90,3| store_client.cc(729) invokeHandlers: InvokeHandlers: 3600000000000000132A000001000000
2017/04/28 08:11:47.577 kid1| 90,3| store_client.cc(735) invokeHandlers: StoreEntry::InvokeHandlers: checking client #0
2017/04/28 08:11:47.577 kid1| 90,3| store_client.cc(755) storePendingNClients: storePendingNClients: returning 1
2017/04/28 08:11:47.577 kid1| 20,3| store.cc(494) unlock: Client unlocking key 3600000000000000132A000001000000 e:=sp2XDIVL/0x231f010*4
2017/04/28 08:11:47.577 kid1| 17,3| FwdState.cc(274) ~FwdState: FwdState destructor start
2017/04/28 08:11:47.577 kid1| 20,3| store.cc(494) unlock: FwdState unlocking key 3600000000000000132A000001000000 e:=sp2XDIVL/0x231f010*3
2017/04/28 08:11:47.577 kid1| 17,3| AsyncCall.cc(56) cancel: will not call fwdConnectDoneWrapper [call127] because FwdState destructed
2017/04/28 08:11:47.577 kid1| 17,3| FwdState.cc(301) ~FwdState: FwdState destructed, this=0x231bfb8
2017/04/28 08:11:47.577 kid1| 5,3| IoCallback.cc(116) finish: called for local=172.30.0.67:80 remote=75.147.129.242:55706 FD 11 flags=1 (0, 0)
2017/04/28 08:11:47.577 kid1| 33,3| Pipeline.cc(35) front: Pipeline 0x23032c0 front 0x2308df0*2
2017/04/28 08:11:47.577 kid1| 88,3| client_side_reply.cc(1172) storeOKTransferDone: storeOKTransferDone  out.offset=0 objectLen()=440 headers_sz=440
2017/04/28 08:11:47.577 kid1| 5,3| comm.cc(865) _comm_close: comm_close: start closing FD 11
_______________________________________________
squid-users mailing list
squid-users@xxxxxxxxxxxxxxxxxxxxx
http://lists.squid-cache.org/listinfo/squid-users
[Index of Archives]     [Linux Audio Users]     [Samba]     [Big List of Linux Books]     [Linux USB]     [Yosemite News]

  Powered by Linux