[squid-users] ssl bump and url_rewrite_program (like squidguard)
Marcus Kool
marcus.kool at urlfilterdb.com
Thu Nov 12 12:28:13 UTC 2015
I cannot make much of the logs and expect that information is missing.
But using just logic, it seems that Squid has a problem with the redirect to a CONNECT.
I suggest to set debug all,9 and to look closely at what happens with the redirection.
Marcus
On 11/12/2015 10:02 AM, Edouard Gaulué wrote:
> Hi Marcus and all,
>
> I have option_debug ALL,2 61,9.
>
> Logs don't tell me a lot, the squidguard answer is exactly the same with or without ssl.
>
> =======================
>
> 2015/11/12 11:51:13.320 kid1| 11,2| client_side.cc(2345) parseHttpRequest: HTTP Client local=192.168.0.233:3128 remote=192.168.0.74:52719 FD 32 flags=1
> 2015/11/12 11:51:13.320 kid1| 11,2| client_side.cc(2346) parseHttpRequest: HTTP Client REQUEST:
> ---------
> GET
> http://ad.doubleclick.net/N4061/adi/com.ythome/_default;sz=970x250;tile=1;ssl=1;dc_yt=1;kbsg=HPFR151111;kga=-1;kgg=-1;klg=fr;kmyd=ad_creative_1;ytexp=9405824,9415555,9416484,9416674,9417703,9418199,9419444,9420772,9421341,9421522,9421931,9421945,9422479,9423231,9423294,9423347,9423510,9423789;ord=5269238259430125?
> HTTP/1.1
> Host: ad.doubleclick.net
> User-Agent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10.10; rv:42.0) Gecko/20100101 Firefox/42.0
> Accept: text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8
> Accept-Language: fr,fr-FR;q=0.8,en-US;q=0.5,en;q=0.3
> Accept-Encoding: gzip, deflate
> Cookie: id=22444c07d901000f||t=1399896339|et=730|cs=002213fd48651016fb03856b79; IDE=AHWqTUlZo9sH_j9svI23Ge8QFYiXp8lJDU2dwdeEJthW3WouVnYC__mRag
> Connection: keep-alive
>
>
> ----------
> 2015/11/12 11:51:13.361 kid1| 85,2| client_side_request.cc(741) clientAccessCheckDone: The request GET
> http://ad.doubleclick.net/N4061/adi/com.ythome/_default;sz=970x250;tile=1;ssl=1;dc_yt=1;kbsg=HPFR151111;kga=-1;kgg=-1;klg=fr;kmyd=ad_creative_1;ytexp=9405824,9415555,9416484,9416674,9417703,9418199,9419444,9420772,9421341,9421522,9421931,9421945,9422479,9423231,9423294,9423347,9423510,9423789;ord=5269238259430125?
> is ALLOWED; last ACL checked: localnet
> 2015/11/12 11:51:13.362 kid1| 23,2| url.cc(393) urlParse: urlParse: URI has whitespace: {icap://127.0.0.1:1344/squidclamav ICAP/1.0
> }
> 2015/11/12 11:51:13.363 kid1| 61,5| redirect.cc(292) redirectStart: redirectStart:
> 'http://ad.doubleclick.net/N4061/adi/com.ythome/_default;sz=970x250;tile=1;ssl=1;dc_yt=1;kbsg=HPFR151111;kga=-1;kgg=-1;klg=fr;kmyd=ad_creative_1;ytexp=9405824,9415555,9416484,9416674,9417703,9418199,9419444,9420772,9421341,9421522,9421931,9421945,9422479,9423231,9423294,9423347,9423510,9423789;ord=5269238259430125?'
>
> 2015/11/12 11:51:13.363 kid1| 61,6| redirect.cc(281) constructHelperQuery: sending
> 'http://ad.doubleclick.net/N4061/adi/com.ythome/_default;sz=970x250;tile=1;ssl=1;dc_yt=1;kbsg=HPFR151111;kga=-1;kgg=-1;klg=fr;kmyd=ad_creative_1;ytexp=9405824,9415555,9416484,9416674,9417703,9418199,9419444,9420772,9421341,9421522,9421931,9421945,9422479,9423231,9423294,9423347,9423510,9423789;ord=5269238259430125?
> 192.168.0.74/192.168.0.74 - GET myip=192.168.0.233 myport=3128
> ' to the redirector helper
> 2015/11/12 11:51:13.363 kid1| 61,5| redirect.cc(82) redirectHandleReply: reply={result=OK, notes={status: 302; url:
> https://proxyweb.echoppe.lan/cgi-bin/squidGuard-simple.cgi?clientaddr=192.168.0.74pipo&clientname=192.168.0.74&clientuser=&clientgroup=marine&targetgroup=adv; }}
> 2015/11/12 11:51:13.363 kid1| 85,2| client_side_request.cc(717) clientAccessCheck2: No adapted_http_access configuration. default: ALLOW
> 2015/11/12 11:51:13.363 kid1| 85,2| client_side_request.cc(741) clientAccessCheckDone: The request GET
> http://ad.doubleclick.net/N4061/adi/com.ythome/_default;sz=970x250;tile=1;ssl=1;dc_yt=1;kbsg=HPFR151111;kga=-1;kgg=-1;klg=fr;kmyd=ad_creative_1;ytexp=9405824,9415555,9416484,9416674,9417703,9418199,9419444,9420772,9421341,9421522,9421931,9421945,9422479,9423231,9423294,9423347,9423510,9423789;ord=5269238259430125?
> is ALLOWED; last ACL checked: all
> 2015/11/12 11:51:13.363 kid1| 20,2| store.cc(936) checkCachable: StoreEntry::checkCachable: NO: not cachable
> 2015/11/12 11:51:13.363 kid1| 20,2| store.cc(936) checkCachable: StoreEntry::checkCachable: NO: not cachable
> 2015/11/12 11:51:13.363 kid1| 88,2| client_side_reply.cc(2001) processReplyAccessResult: The reply for GET
> http://ad.doubleclick.net/N4061/adi/com.ythome/_default;sz=970x250;tile=1;ssl=1;dc_yt=1;kbsg=HPFR151111;kga=-1;kgg=-1;klg=fr;kmyd=ad_creative_1;ytexp=9405824,9415555,9416484,9416674,9417703,9418199,9419444,9420772,9421341,9421522,9421931,9421945,9422479,9423231,9423294,9423347,9423510,9423789;ord=5269238259430125?
> is ALLOWED, because it matched all
> 2015/11/12 11:51:13.363 kid1| 11,2| client_side.cc(1391) sendStartOfMessage: HTTP Client local=192.168.0.233:3128 remote=192.168.0.74:52719 FD 32 flags=1
> 2015/11/12 11:51:13.363 kid1| 11,2| client_side.cc(1392) sendStartOfMessage: HTTP Client REPLY:
> ---------
> HTTP/1.1 302 Found
> Server: squid/3.5.10
> Date: Thu, 12 Nov 2015 10:51:13 GMT
> Content-Length: 0
> Location: https://proxyweb.echoppe.lan/cgi-bin/squidGuard-simple.cgi?clientaddr=192.168.0.74pipo&clientname=192.168.0.74&clientuser=&clientgroup=marine&targetgroup=adv
> X-Cache: MISS from squid
> X-Cache-Lookup: MISS from squid:3128
> Via: 1.1 squid (squid/3.5.10)
> Connection: keep-alive
>
>
> ----------
> 2015/11/12 11:51:13.363 kid1| 20,2| store.cc(936) checkCachable: StoreEntry::checkCachable: NO: not cachable
> 2015/11/12 11:51:13.363 kid1| 20,2| store.cc(936) checkCachable: StoreEntry::checkCachable: NO: not cachable
> 2015/11/12 11:51:14.849 kid1| 5,2| TcpAcceptor.cc(222) doAccept: New connection on FD 46
> 2015/11/12 11:51:14.849 kid1| 5,2| TcpAcceptor.cc(297) acceptNext: connection on local=[::]:3128 remote=[::] FD 46 flags=9
> 2015/11/12 11:51:14.849 kid1| 11,2| client_side.cc(2345) parseHttpRequest: HTTP Client local=192.168.0.233:3128 remote=192.168.0.74:52721 FD 48 flags=1
> 2015/11/12 11:51:14.849 kid1| 11,2| client_side.cc(2346) parseHttpRequest: HTTP Client REQUEST:
> ---------
> CONNECT ad.doubleclick.net:443 HTTP/1.1
> User-Agent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10.10; rv:42.0) Gecko/20100101 Firefox/42.0
> Proxy-Connection: keep-alive
> Connection: keep-alive
> Host: ad.doubleclick.net:443
>
>
> ----------
> 2015/11/12 11:51:14.850 kid1| 85,2| client_side_request.cc(741) clientAccessCheckDone: The request CONNECT ad.doubleclick.net:443 is ALLOWED; last ACL checked: localnet
> 2015/11/12 11:51:14.850 kid1| 23,2| url.cc(393) urlParse: urlParse: URI has whitespace: {icap://127.0.0.1:1344/squidclamav ICAP/1.0
> }
> 2015/11/12 11:51:14.851 kid1| 61,5| redirect.cc(292) redirectStart: redirectStart: 'ad.doubleclick.net:443'
> 2015/11/12 11:51:14.851 kid1| 61,6| redirect.cc(281) constructHelperQuery: sending 'ad.doubleclick.net:443 192.168.0.74/192.168.0.74 - CONNECT myip=192.168.0.233 myport=3128
> ' to the redirector helper
> 2015/11/12 11:51:14.851 kid1| 61,5| redirect.cc(82) redirectHandleReply: reply={result=OK, notes={status: 302; url:
> https://proxyweb.echoppe.lan/cgi-bin/squidGuard-simple.cgi?clientaddr=192.168.0.74pipo&clientname=192.168.0.74&clientuser=&clientgroup=marine&targetgroup=adv; }}
> 2015/11/12 11:51:14.851 kid1| 85,2| client_side_request.cc(717) clientAccessCheck2: No adapted_http_access configuration. default: ALLOW
> 2015/11/12 11:51:14.851 kid1| 85,2| client_side_request.cc(741) clientAccessCheckDone: The request CONNECT ad.doubleclick.net:443 is ALLOWED; last ACL checked: all
> 2015/11/12 11:51:14.851 kid1| 20,2| store.cc(936) checkCachable: StoreEntry::checkCachable: NO: not cachable
> 2015/11/12 11:51:14.851 kid1| 20,2| store.cc(936) checkCachable: StoreEntry::checkCachable: NO: not cachable
> 2015/11/12 11:51:14.851 kid1| 88,2| client_side_reply.cc(2001) processReplyAccessResult: The reply for CONNECT ad.doubleclick.net:443 is ALLOWED, because it matched all
> 2015/11/12 11:51:14.851 kid1| 11,2| client_side.cc(1391) sendStartOfMessage: HTTP Client local=192.168.0.233:3128 remote=192.168.0.74:52721 FD 48 flags=1
> 2015/11/12 11:51:14.851 kid1| 11,2| client_side.cc(1392) sendStartOfMessage: HTTP Client REPLY:
> ---------
> HTTP/1.1 302 Found
> Server: squid/3.5.10
> Date: Thu, 12 Nov 2015 10:51:14 GMT
> Content-Length: 0
> Location: https://proxyweb.echoppe.lan/cgi-bin/squidGuard-simple.cgi?clientaddr=192.168.0.74pipo&clientname=192.168.0.74&clientuser=&clientgroup=marine&targetgroup=adv
> X-Cache: MISS from squid
> X-Cache-Lookup: MISS from squid:3128
> Via: 1.1 squid (squid/3.5.10)
> Connection: keep-alive
>
>
> ----------
> 2015/11/12 11:51:14.851 kid1| 20,2| store.cc(936) checkCachable: StoreEntry::checkCachable: NO: not cachable
> 2015/11/12 11:51:14.851 kid1| 20,2| store.cc(936) checkCachable: StoreEntry::checkCachable: NO: not cachable
> 2015/11/12 11:51:14.851 kid1| abandoning local=192.168.0.233:3128 remote=192.168.0.74:52721 FD 48 flags=1
>
> ========================
>
> On the wireshark side:
>
> In the http case I observe 2 streams:
> * One with the proxy
> GET
> http://ad.doubleclick.net/N4061/adi/com.ythome/_default;sz=970x250;tile=1;ssl=1;dc_yt=1;kbsg=HPFR151111;kga=-1;kgg=-1;klg=fr;kmyd=ad_creative_1;ytexp=9405824,9415555,9416484,9416674,9417703,9418199,9419444,9420772,9421341,9421522,9421931,9421945,9422479,9423231,9423294,9423347,9423510,9423789;ord=5269238259430125?
> HTTP/1.1
> Host: ad.doubleclick.net
> User-Agent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10.10; rv:42.0) Gecko/20100101 Firefox/42.0
> Accept: text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8
> Accept-Language: fr,fr-FR;q=0.8,en-US;q=0.5,en;q=0.3
> Accept-Encoding: gzip, deflate
> Cookie: id=22444c07d901000f||t=1399896339|et=730|cs=002213fd48651016fb03856b79; IDE=AHWqTUlZo9sH_j9svI23Ge8QFYiXp8lJDU2dwdeEJthW3WouVnYC__mRag
> Connection: keep-alive
>
> HTTP/1.1 302 Found
> Server: squid/3.5.10
> Date: Thu, 12 Nov 2015 10:35:50 GMT
> Content-Length: 0
> Location: https://proxyweb.echoppe.lan/cgi-bin/squidGuard-simple.cgi?clientaddr=192.168.0.74pipo&clientname=192.168.0.74&clientuser=&clientgroup=marine&targetgroup=adv
> X-Cache: MISS from squid
> X-Cache-Lookup: MISS from squid:3128
> Via: 1.1 squid (squid/3.5.10)
> Connection: keep-alive
>
> * Then one with proxyweb SSL encoded
>
> That sounds logical to me.
>
>
> In the https case I observe just 1 stream:
> CONNECT ad.doubleclick.net:443 HTTP/1.1
> User-Agent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10.10; rv:42.0) Gecko/20100101 Firefox/42.0
> Proxy-Connection: keep-alive
> Connection: keep-alive
> Host: ad.doubleclick.net:443
>
> HTTP/1.1 302 Found
> Server: squid/3.5.10
> Date: Thu, 12 Nov 2015 10:35:57 GMT
> Content-Length: 0
> Location: https://proxyweb.echoppe.lan/cgi-bin/squidGuard-simple.cgi?clientaddr=192.168.0.74pipo&clientname=192.168.0.74&clientuser=&clientgroup=marine&targetgroup=adv
> X-Cache: MISS from squid
> X-Cache-Lookup: MISS from squid:3128
> Via: 1.1 squid (squid/3.5.10)
> Connection: keep-alive
>
> CONNECT ad.doubleclick.net:443 HTTP/1.1
> User-Agent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10.10; rv:42.0) Gecko/20100101 Firefox/42.0
> Proxy-Connection: keep-alive
> Connection: keep-alive
> Host: ad.doubleclick.net:443
>
>
> All this is between my client and proxy server.
>
> Why is the browser not taking account of the redirect?
> Why is it redoing the same connect?
> Why is there no trace at all in the proxy logs of this second CONNECT?
>
> Regards, EG
> _______________________________________________
> squid-users mailing list
> squid-users at lists.squid-cache.org
> http://lists.squid-cache.org/listinfo/squid-users
More information about the squid-users
mailing list