On 7/03/2013 10:54 p.m., Amm wrote:
> ----- Original Message -----
>
>> From: Amos Jeffries <squid3_at_treenet.co.nz>
>> To: squid-users_at_squid-cache.org
>> Cc:
>> Sent: Thursday, 7 March 2013 1:11 PM
>> Subject: Re: [squid-users] Bypassing SSL Bump for dstdomain
>>
>> On 7/03/2013 7:22 p.m., Amm wrote:
>> <snip>
>
>>> For testing, URL was accessed with curl (curl -k https://www.google.com/)
>>>
>>> Here is debug output: (Google IP has changed but in same subnet, 1.2.3.4 is
>> my public IP replaced)
>>> 2013/03/07 11:40:46.326 kid1| client_side.cc(2325) parseHttpRequest: HTTP
>> Client local=173.194.36.18:443 remote=1.2.3.4:50145 FD 21 flags=33
>>> 2013/03/07 11:40:46.326 kid1| client_side.cc(2326) parseHttpRequest: HTTP
>> Client REQUEST:
>>> ---------
>>> GET / HTTP/1.1
>>> User-Agent: curl/7.21.7 (x86_64-redhat-linux-gnu) libcurl/7.21.7
>> NSS/3.13.5.0 zlib/1.2.5 libidn/1.22 libssh2/1.2.7
>>> Host: www.google.com
>>> Accept: */*
>>>
>>>
>>> ----------
>>> 2013/03/07 11:40:46.326 kid1| http.cc(2177) sendRequest: HTTP Server
>> local=1.2.3.4:50146 remote=173.194.36.18:443 FD 23 flags=1
>>> 2013/03/07 11:40:46.326 kid1| http.cc(2178) sendRequest: HTTP Server
>> REQUEST:
>>> ---------
>>> GET / HTTP/1.1
>>> User-Agent: curl/7.21.7 (x86_64-redhat-linux-gnu) libcurl/7.21.7
>> NSS/3.13.5.0 zlib/1.2.5 libidn/1.22 libssh2/1.2.7
>>> Host: www.google.com
>>> Accept: */*
>>> Via: 1.1 a.b.c (squid/3.3.2)
>>> X-Forwarded-For: 1.2.3.4
>>> Cache-Control: max-age=259200
>>> Connection: keep-alive
>>>
>>>
>>> HTTP server REQUEST shows 173.194.36.18, but access.logs show IPv6 address:
>>> 1362636646.416 90 1.2.3.4 TCP_MISS/302 1138 GET https://www.google.com/
>> - PINNED/2404:6800:4009:802::1011 text/html
>
>> This is a really *really* strange outcome. It is indeed looking like a
>> code bug somewhere.
>>
>> The cache.log showed the TCP level details being apparently correct. So
>> I think we can ignore everyting up to the point of logging.
>> Just to cofirm that can you add the server response trace from that
>> server request? It will be a short while later with identical local=
>> remote= and FD values.
>> If there is anything else on that FD 23 it would be useful to know as well.
>
> 2013/03/07 11:40:46.416 kid1| ctx: enter level 0: 'https://www.google.com/'
> 2013/03/07 11:40:46.416 kid1| http.cc(746) processReplyHeader: HTTP Server local=1.2.3.4:50146 remote=173.194.36.18:443 FD 23 flags=1
> 2013/03/07 11:40:46.416 kid1| http.cc(747) processReplyHeader: HTTP Server REPLY:
> ---------
> HTTP/1.1 302 Found
> Location: https://www.google.co.in/
> Cache-Control: private
> Content-Type: text/html; charset=UTF-8
> Set-Cookie: XXXXX
> Set-Cookie: XXXXX
> P3P: CP="This is not a P3P policy! See http://www.google.com/support/accounts/bin/answer.py?hl=en&answer=151657 for more info."
> Date: Thu, 07 Mar 2013 06:10:46 GMT
> Server: gws
> Content-Length: 222
> X-XSS-Protection: 1; mode=block
> X-Frame-Options: SAMEORIGIN
>
> <HTML><HEAD><meta http-equiv="content-type" content="text/html;charset=utf-8">
> <TITLE>302 Moved</TITLE></HEAD><BODY>
> <H1>302 Moved</H1>
> The document has moved
> here.
> </BODY></HTML>
> ----------
> 2013/03/07 11:40:46.416 kid1| ctx: exit level 0
> 2013/03/07 11:40:46.416 kid1| client_side.cc(1386) sendStartOfMessage: HTTP Client local=173.194.36.18:443 remote=1.2.3.4:50145 FD 21 flags=33
> 2013/03/07 11:40:46.416 kid1| client_side.cc(1387) sendStartOfMessage: HTTP Client REPLY:
> ---------
> HTTP/1.1 302 Moved Temporarily
> Location: https://www.google.co.in/
> Cache-Control: private
> Content-Type: text/html; charset=UTF-8
> Set-Cookie: XXXXX
> Set-Cookie: XXXXX
> P3P: CP="This is not a P3P policy! See http://www.google.com/support/accounts/bin/answer.py?hl=en&answer=151657 for more info."
> Date: Thu, 07 Mar 2013 06:10:46 GMT
> Server: gws
> Content-Length: 222
> X-XSS-Protection: 1; mode=block
> X-Frame-Options: SAMEORIGIN
> X-Cache: MISS from a.b.c
> X-Cache-Lookup: MISS from a.b.c:8080
> Via: 1.1 a.b.c (squid/3.3.2)
> Connection: keep-alive
>
>
>
>> If we assume there is someting terribly broken with where the access.log
>> data is being generate from.
>> Can you create a custom log format please which outputs:
>>
>> logformat test %>A/%>a:%>p -> %>la:%>lp (%la:%lp)
>> %<la:%<lp ->
>> %<A/%<a:%<p [%h{Host}]
>>
>> and use it for a secondary access_log line. Lets see what gets logged by
>> that.
> [%h{Host}] was giving error, so i changed it to [%{Host}>h]
>
> Here is output:
> ABCD.net.in/1.2.3.4:33307 -> 173.194.36.16:443 (-:8081) :::0 -> www.google.com/2404:6800:4009:802::1011:443 [www.google.com]
>
> Notice :::0 - somewhere it thinks its IPv6??
>
> If domain has just IPv4 address and no IPv6 address:
>
> ABCD.net.in/1.2.3.4:58347 -> 174.122.92.66:443 (-:8081) 0.0.0.0:0 -> www.bigrock.com/174.122.92.65:443 [www.bigrock.com]
>
>
> If i use dns_v4_first, it logs IPv4 address.
>
> ABCD.mtnl.net.in/1.2.3.4:33559
> -> 74.125.236.147:443 (-:8081) 0.0.0.0:0 ->
> www.google.com/74.125.236.146:443 [www.google.com]
>
> Notice the change in IP address though. But may be that is expected as squid does its own DNS lookup and picks other IP.
Okay that zero IP:port on the outbound confirmed my suspicion about what
the code was doing. When using a pinned connection it is not setting the
real connection details into the log.
>
>> If it is still logging the IPv6. I have an experimental patch here:
>> http://master.squid-cache.org/~amosjeffries/patches/pinning_hier_note.patch
>>
>> If you could apply that and see what the above log changes to it would
>> be great.
>>
>> Cheers
>> Amos
> Applying and trying patch will take about a day. Will let you know once I do.
Thanks.
The above log entry implies it should be the fix, but I will still need
confirmation of that.
Amos
Received on Thu Mar 07 2013 - 21:18:01 MST
This archive was generated by hypermail 2.2.0 : Fri Mar 08 2013 - 12:00:04 MST