Squid intermittently not sending host header to peer

classic Classic list List threaded Threaded
5 messages Options
Reply | Threaded
Open this post in threaded view
|

Squid intermittently not sending host header to peer

Michael Thomas
I'm trying to figure out this weird intermittent issue.

I have two squid servers running, non-caching, non-transparent.

Client -> Squid1 -> Squid2 -> Internet

All HTTPS requests work as expected, but randomly, about 50% of the time, HTTP requests fail.

The reason for the failure is that the first squid server (Squid1) is not correctly forwarding the request to the second. It is stripping away the hostname, and obviously the second squid server has no clue what to do with it then!

Refreshing either create or resolves the issue, again, seemingly at random.

The following is a copy of the access logs for two successful requests, followed by a failure:

Squid1:
1535965629.452     81 3.3.3.3 TCP_MISS/200 5766 GET http://redacted.com/messages/391/ - FIRSTUP_PARENT/2.2.2.2 text/html
1535965634.678     71 3.3.3.3 TCP_MISS/200 5759 GET http://redacted.com/messages/391/ - FIRSTUP_PARENT/2.2.2.2 text/html
1535965636.673      1 3.3.3.3 TCP_MISS/400 4009 GET http://redacted.com/messages/391/ - FIRSTUP_PARENT/2.2.2.2 text/html

Squid2:
1535965629.447     79 1.1.1.1 TCP_MISS/200 5673 GET http://redacted.com/messages/391/ connect HIER_DIRECT/4.4.4.4 text/html
1535965634.673     68 1.1.1.1 TCP_MISS/200 5671 GET http://redacted.com/messages/391/ connect HIER_DIRECT/4.4.4.4 text/html
1535965636.668      0 1.1.1.1 TAG_NONE/400 3916 GET /messages/391/ - HIER_NONE/- text/html

squid.conf from Squid1:
http_port 3128 name=port_3128
http_access allow all
nonhierarchical_direct off

acl port_3128_acl myportname port_3128

always_direct deny port_3128_acl

never_direct allow port_3128_acl

# 3128
cache_peer 2.2.2.2 parent 3128 0 no-query proxy-only default  name=proxy3128
cache_peer_access proxy3128 allow port_3128_acl
cache_peer_access proxy3128 deny all

squid.conf from Squid2:
http_access allow all
http_port 3128

Where:
1.1.1.1: Squid1
2.2.2.2: Squid2
3.3.3.3: client
4.4.4.4: Web Server

I can't see any obvious error in my configuration, and the intermittent nature of it makes me think it might be some sort of bug. I'd love to hear if anyone else has run into this.

Kind Regards,
Michael Thomas

_______________________________________________
squid-users mailing list
[hidden email]
http://lists.squid-cache.org/listinfo/squid-users
Reply | Threaded
Open this post in threaded view
|

Re: Squid intermittently not sending host header to peer

Amos Jeffries
Administrator
On 3/09/18 9:32 PM, Michael Thomas wrote:

> I'm trying to figure out this weird intermittent issue.
>
> I have two squid servers running, non-caching, non-transparent.
>
> Client -> Squid1 -> Squid2 -> Internet
>
> All HTTPS requests work as expected, but randomly, about 50% of the
> time, HTTP requests fail.
>
> The reason for the failure is that the first squid server (Squid1) is
> not correctly forwarding the request to the second. It is stripping away
> the hostname, and obviously the second squid server has no clue what to
> do with it then!

Can you please provide:

* details of your Squid version(s), the output of "squid -v" contains that.

* a copy of the HTTP message actually received by Squid2.

* a copy of the same HTTP message as it is leaving Squid1.

"debug_options 11,2" can provide that in your cache.log.


Also, is there any sign of CONNECT messages requesting tunnels to Squid2
being received at Squid1 ?


Your logs contain signs of authentication being performed, and you
mention HTTPS being handled by these proxies. Yet the config showed no
signs of either having been configured. Can you please provide the
actual config where you are seeing this behaviour and generating the
logs from.
 A minimal is fine, but it does need to be generating the logs, etc for
the info to correlate correctly.


Amos
_______________________________________________
squid-users mailing list
[hidden email]
http://lists.squid-cache.org/listinfo/squid-users
Reply | Threaded
Open this post in threaded view
|

Re: Squid intermittently not sending host header to peer

Michael Thomas
HI Amos,

Thank you for responding.

To clarify, when I referred to HTTPS requests, I was referring to CONNECT requests - I should have been more clear, my apologies. No authentication is being performed by either server, so I'm not sure what you're seeing in the logs that relates to that.

CONNECT requests are logged correctly on both squid servers and appear to operate correctly for every request.

Interestingly, I was mistaken before. It's not the host header that's missing - that's still present. It's the full URI within the GET request.

As requested, here is all the information:

Squid1 version and build information:
Squid Cache: Version 3.5.12
Service Name: squid
Ubuntu linux
configure options:  '--build=x86_64-linux-gnu' '--prefix=/usr' '--includedir=${prefix}/include' '--mandir=${prefix}/share/man' '--infodir=${prefix}/share/info' '--sysconfdir=/etc' '--localstatedir=/var' '--libexecdir=${prefix}/lib/squid3' '--srcdir=.' '--disable-maintainer-mode' '--disable-dependency-tracking' '--disable-silent-rules' 'BUILDCXXFLAGS=-g -O2 -fPIE -fstack-protector-strong -Wformat -Werror=format-security -Wl,-Bsymbolic-functions -fPIE -pie -Wl,-z,relro -Wl,-z,now' '--datadir=/usr/share/squid' '--sysconfdir=/etc/squid' '--libexecdir=/usr/lib/squid' '--mandir=/usr/share/man' '--enable-inline' '--disable-arch-native' '--enable-async-io=8' '--enable-storeio=ufs,aufs,diskd,rock' '--enable-removal-policies=lru,heap' '--enable-delay-pools' '--enable-cache-digests' '--enable-icap-client' '--enable-follow-x-forwarded-for' '--enable-auth-basic=DB,fake,getpwnam,LDAP,NCSA,NIS,PAM,POP3,RADIUS,SASL,SMB' '--enable-auth-digest=file,LDAP' '--enable-auth-negotiate=kerberos,wrapper' '--enable-auth-ntlm=fake,smb_lm' '--enable-external-acl-helpers=file_userip,kerberos_ldap_group,LDAP_group,session,SQL_session,unix_group,wbinfo_group' '--enable-url-rewrite-helpers=fake' '--enable-eui' '--enable-esi' '--enable-icmp' '--enable-zph-qos' '--enable-ecap' '--disable-translation' '--with-swapdir=/var/spool/squid' '--with-logdir=/var/log/squid' '--with-pidfile=/var/run/squid.pid' '--with-filedescriptors=65536' '--with-large-files' '--with-default-user=proxy' '--enable-build-info=Ubuntu linux' '--enable-linux-netfilter' 'build_alias=x86_64-linux-gnu' 'CFLAGS=-g -O2 -fPIE -fstack-protector-strong -Wformat -Werror=format-security -Wall' 'LDFLAGS=-Wl,-Bsymbolic-functions -fPIE -pie -Wl,-z,relro -Wl,-z,now' 'CPPFLAGS=-Wdate-time -D_FORTIFY_SOURCE=2' 'CXXFLAGS=-g -O2 -fPIE -fstack-protector-strong -Wformat -Werror=format-security'

Squid2 version and build information:
Squid Cache: Version 3.5.27
Service Name: squid
Ubuntu linux

This binary uses OpenSSL 1.0.2g  1 Mar 2016. For legal restrictions on distribution see https://www.openssl.org/source/license.html

configure options:  '--build=x86_64-linux-gnu' '--prefix=/usr' '--includedir=${prefix}/include' '--mandir=${prefix}/share/man' '--infodir=${prefix}/share/info' '--sysconfdir=/etc' '--localstatedir=/var' '--libexecdir=${prefix}/lib/squid3' '--srcdir=.' '--disable-maintainer-mode' '--disable-dependency-tracking' '--disable-silent-rules' 'BUILDCXXFLAGS=-g -O2 -fPIE -fstack-protector-strong -Wformat -Werror=format-security -Wdate-time -D_FORTIFY_SOURCE=2 -Wl,-Bsymbolic-functions -fPIE -pie -Wl,-z,relro -Wl,-z,now -Wl,--as-needed' 'CXX=g++' 'CC=gcc' '--datadir=/usr/share/squid' '--sysconfdir=/etc/squid' '--libexecdir=/usr/lib/squid' '--mandir=/usr/share/man' '--enable-inline' '--disable-arch-native' '--enable-async-io=8' '--enable-storeio=ufs,aufs,diskd,rock' '--enable-removal-policies=lru,heap' '--enable-delay-pools' '--enable-cache-digests' '--enable-icap-client' '--enable-follow-x-forwarded-for' '--enable-auth-basic=DB,fake,getpwnam,LDAP,NCSA,NIS,PAM,POP3,RADIUS,SASL,SMB' '--enable-auth-digest=file,LDAP' '--enable-auth-negotiate=kerberos,wrapper' '--enable-auth-ntlm=fake,smb_lm' '--enable-external-acl-helpers=file_userip,kerberos_ldap_group,LDAP_group,session,SQL_session,time_quota,unix_group,wbinfo_group' '--enable-url-rewrite-helpers=fake' '--enable-eui' '--enable-esi' '--enable-icmp' '--enable-zph-qos' '--enable-ecap' '--disable-translation' '--with-swapdir=/var/spool/squid' '--with-logdir=/var/log/squid' '--with-pidfile=/var/run/squid.pid' '--with-filedescriptors=65536' '--with-large-files' '--with-default-user=proxy' '--with-openssl' '--enable-ssl' '--enable-ssl-crtd' '--enable-build-info=Ubuntu linux' '--enable-linux-netfilter' 'build_alias=x86_64-linux-gnu' 'CFLAGS=-g -O2 -fPIE -fstack-protector-strong -Wformat -Werror=format-security -Wall' 'LDFLAGS=-Wl,-Bsymbolic-functions -fPIE -pie -Wl,-z,relro -Wl,-z,now -Wl,--as-needed' 'CPPFLAGS=-Wdate-time -D_FORTIFY_SOURCE=2' 'CXXFLAGS=-g -O2 -fPIE -fstack-protector-strong -Wformat -Werror=format-security'



Here is a verbatim copy of both squid.conf files, with sensitive information replaced:

Squid1:
http_port 3128 name=port_3128
http_access allow all
nonhierarchical_direct off

acl port_3128_acl myportname port_3128
always_direct deny port_3128_acl
never_direct allow port_3128_acl

# 3128
cache_peer 2.2.2.2 parent 3128 0 no-query proxy-only default  name=proxy3128
cache_peer_access proxy3128 allow port_3128_acl
cache_peer_access proxy3128 deny all
debug_options 11,2


Squid2:
http_access allow all
http_port 3128
debug_options 11,2


And here is a copy of the cache.log for a failed request:

Squid1:
----------
2018/09/03 13:36:43| pinger: Initialising ICMP pinger ...
2018/09/03 13:36:45.088 kid1| 11,2| client_side.cc(2346) parseHttpRequest: HTTP Client local=1.1.1.1:3128 remote=3.3.3.3:52250 FD 8 flags=1
2018/09/03 13:36:45.088 kid1| 11,2| client_side.cc(2347) parseHttpRequest: HTTP Client REQUEST:
---------
Proxy-Connection: keep-alive
Cache-Control: max-age=0
Upgrade-Insecure-Requests: 1
User-Agent: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/68.0.3440.106 Safari/537.36
Accept: text/html,application/xhtml+xml,application/xml;q=0.9,image/webp,image/apng,*/*;q=0.8
Accept-Encoding: gzip, deflate
Accept-Language: en-US,en;q=0.9,en-GB;q=0.8
Cookie: __cfduid=redacted; csrftoken=redacted; sessionid=redacted; _ga=redacted
AlexaToolbar-ALX_NS_PH: AlexaToolbar/alx-4.0.3


----------
2018/09/03 13:36:45.088 kid1| 11,2| http.cc(2234) sendRequest: HTTP Server local=1.1.1.1:55718 remote=2.2.2.2:3128 FD 14 flags=1
2018/09/03 13:36:45.089 kid1| 11,2| http.cc(2235) sendRequest: HTTP Server REQUEST:
---------
GET /messages/391/ HTTP/1.1
Upgrade-Insecure-Requests: 1
User-Agent: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/68.0.3440.106 Safari/537.36
Accept: text/html,application/xhtml+xml,application/xml;q=0.9,image/webp,image/apng,*/*;q=0.8
Accept-Encoding: gzip, deflate
Accept-Language: en-US,en;q=0.9,en-GB;q=0.8
Cookie: __cfduid=redacted; csrftoken=redacted; sessionid=redacted; _ga=redacted
AlexaToolbar-ALX_NS_PH: AlexaToolbar/alx-4.0.3
Via: 1.1 Squid1 (squid/3.5.12)
X-Forwarded-For: 3.3.3.3
Cache-Control: max-age=0
Connection: keep-alive



Squid2:
2018/09/03 13:36:45.089 kid1| 11,2| client_side.cc(2372) parseHttpRequest: HTTP Client local=2.2.2.2:3128 remote=1.1.1.1:55718 FD 15 flags=1
2018/09/03 13:36:45.089 kid1| 11,2| client_side.cc(2373) parseHttpRequest: HTTP Client REQUEST:
---------
GET /messages/391/ HTTP/1.1
Upgrade-Insecure-Requests: 1
User-Agent: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/68.0.3440.106 Safari/537.36
Accept: text/html,application/xhtml+xml,application/xml;q=0.9,image/webp,image/apng,*/*;q=0.8
Accept-Encoding: gzip, deflate
Accept-Language: en-US,en;q=0.9,en-GB;q=0.8
Cookie: __cfduid=redacted; csrftoken=redacted; sessionid=redacted; _ga=redacted
AlexaToolbar-ALX_NS_PH: AlexaToolbar/alx-4.0.3
Via: 1.1 Squid1 (squid/3.5.12)
X-Forwarded-For: 3.3.3.3
Cache-Control: max-age=0
Connection: keep-alive


----------
2018/09/03 13:36:45.089 kid1| 11,2| client_side.cc(1409) sendStartOfMessage: HTTP Client local=2.2.2.2:3128 remote=1.1.1.1:55718 FD 15 flags=1
2018/09/03 13:36:45.089 kid1| 11,2| client_side.cc(1410) sendStartOfMessage: HTTP Client REPLY:
---------
HTTP/1.1 400 Bad Request
Server: squid/3.5.27
Mime-Version: 1.0
Date: Mon, 03 Sep 2018 13:36:45 GMT
Content-Type: text/html;charset=utf-8
Content-Length: 3556
X-Squid-Error: ERR_INVALID_URL 0
Vary: Accept-Language
Content-Language: en
X-Cache: MISS from Squid2
X-Cache-Lookup: NONE from Squid2:3128
Via: 1.1 Squid2 (squid/3.5.27)
Connection: close



And the same again for a successful request:

Squid1:
2018/09/03 13:46:22.850 kid1| 11,2| client_side.cc(2346) parseHttpRequest: HTTP Client local=1.1.1.1:3128 remote=3.3.3.3:53182 FD 8 flags=1
2018/09/03 13:46:22.850 kid1| 11,2| client_side.cc(2347) parseHttpRequest: HTTP Client REQUEST:
---------
Proxy-Connection: keep-alive
Cache-Control: max-age=0
Upgrade-Insecure-Requests: 1
User-Agent: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/68.0.3440.106 Safari/537.36
Accept: text/html,application/xhtml+xml,application/xml;q=0.9,image/webp,image/apng,*/*;q=0.8
Accept-Encoding: gzip, deflate
Accept-Language: en-US,en;q=0.9,en-GB;q=0.8
Cookie: __cfduid=redacted; csrftoken=redacted; sessionid=redacted; _ga=redacted
AlexaToolbar-ALX_NS_PH: AlexaToolbar/alx-4.0.3


----------
2018/09/03 13:46:22.852 kid1| 11,2| http.cc(2234) sendRequest: HTTP Server local=1.1.1.1:55798 remote=2.2.2.2:3128 FD 12 flags=1
2018/09/03 13:46:22.852 kid1| 11,2| http.cc(2235) sendRequest: HTTP Server REQUEST:
---------
Upgrade-Insecure-Requests: 1
User-Agent: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/68.0.3440.106 Safari/537.36
Accept: text/html,application/xhtml+xml,application/xml;q=0.9,image/webp,image/apng,*/*;q=0.8
Accept-Encoding: gzip, deflate
Accept-Language: en-US,en;q=0.9,en-GB;q=0.8
Cookie: __cfduid=redacted; csrftoken=redacted; sessionid=redacted; _ga=redacted
AlexaToolbar-ALX_NS_PH: AlexaToolbar/alx-4.0.3
Via: 1.1 Squid1 (squid/3.5.12)
X-Forwarded-For: 3.3.3.3
Cache-Control: max-age=0
Connection: keep-alive


Squid2:
2018/09/03 13:46:22.853 kid1| 11,2| client_side.cc(2372) parseHttpRequest: HTTP Client local=2.2.2.2:3128 remote=1.1.1.1:55798 FD 12 flags=1
2018/09/03 13:46:22.853 kid1| 11,2| client_side.cc(2373) parseHttpRequest: HTTP Client REQUEST:
---------
Upgrade-Insecure-Requests: 1
User-Agent: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/68.0.3440.106 Safari/537.36
Accept: text/html,application/xhtml+xml,application/xml;q=0.9,image/webp,image/apng,*/*;q=0.8
Accept-Encoding: gzip, deflate
Accept-Language: en-US,en;q=0.9,en-GB;q=0.8
Cookie: __cfduid=redacted; csrftoken=redacted; sessionid=redacted; _ga=redacted
AlexaToolbar-ALX_NS_PH: AlexaToolbar/alx-4.0.3
Via: 1.1 Squid1 (squid/3.5.12)
X-Forwarded-For: 3.3.3.3
Cache-Control: max-age=0
Connection: keep-alive


----------
2018/09/03 13:46:22.859 kid1| 11,2| http.cc(2229) sendRequest: HTTP Server local=2.2.2.2:58376 remote=4.4.4.4:80 FD 10 flags=1
2018/09/03 13:46:22.859 kid1| 11,2| http.cc(2230) sendRequest: HTTP Server REQUEST:
---------
GET /messages/391/ HTTP/1.1
Upgrade-Insecure-Requests: 1
User-Agent: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/68.0.3440.106 Safari/537.36
Accept: text/html,application/xhtml+xml,application/xml;q=0.9,image/webp,image/apng,*/*;q=0.8
Accept-Encoding: gzip, deflate
Accept-Language: en-US,en;q=0.9,en-GB;q=0.8
Cookie: __cfduid=redacted; csrftoken=redacted; sessionid=redacted; _ga=redacted
AlexaToolbar-ALX_NS_PH: AlexaToolbar/alx-4.0.3
Via: 1.1 Squid1 (squid/3.5.12), 1.1 Squid2 (squid/3.5.27)
X-Forwarded-For: 3.3.3.3, 1.1.1.1
Cache-Control: max-age=0
Connection: keep-alive

On Mon, Sep 3, 2018 at 5:22 PM Amos Jeffries <[hidden email]> wrote:
On 3/09/18 9:32 PM, Michael Thomas wrote:
> I'm trying to figure out this weird intermittent issue.
>
> I have two squid servers running, non-caching, non-transparent.
>
> Client -> Squid1 -> Squid2 -> Internet
>
> All HTTPS requests work as expected, but randomly, about 50% of the
> time, HTTP requests fail.
>
> The reason for the failure is that the first squid server (Squid1) is
> not correctly forwarding the request to the second. It is stripping away
> the hostname, and obviously the second squid server has no clue what to
> do with it then!

Can you please provide:

* details of your Squid version(s), the output of "squid -v" contains that.

* a copy of the HTTP message actually received by Squid2.

* a copy of the same HTTP message as it is leaving Squid1.

"debug_options 11,2" can provide that in your cache.log.


Also, is there any sign of CONNECT messages requesting tunnels to Squid2
being received at Squid1 ?


Your logs contain signs of authentication being performed, and you
mention HTTPS being handled by these proxies. Yet the config showed no
signs of either having been configured. Can you please provide the
actual config where you are seeing this behaviour and generating the
logs from.
 A minimal is fine, but it does need to be generating the logs, etc for
the info to correlate correctly.


Amos
_______________________________________________
squid-users mailing list
[hidden email]
http://lists.squid-cache.org/listinfo/squid-users

_______________________________________________
squid-users mailing list
[hidden email]
http://lists.squid-cache.org/listinfo/squid-users
Reply | Threaded
Open this post in threaded view
|

Re: Squid intermittently not sending host header to peer

Amos Jeffries
Administrator
On 4/09/18 2:13 AM, Michael Thomas wrote:
> HI Amos,
>
> Thank you for responding.
>
> To clarify, when I referred to HTTPS requests, I was referring to
> CONNECT requests - I should have been more clear, my apologies. No
> authentication is being performed by either server, so I'm not sure what
> you're seeing in the logs that relates to that.

The log format looks like Squid native format. On all the 200 status
transactions there is "connect" instead of "-" where that format prints
username.


>
> CONNECT requests are logged correctly on both squid servers and appear
> to operate correctly for every request.
>
> Interestingly, I was mistaken before. It's not the host header that's
> missing - that's still present. It's the full URI within the GET request.
>

Nod. Squid2 is receiving an origin-form request. Such as a client would
send *inside* a CONNECT tunnel, or Squid would send on DIRECT traffic.

The former was what I suspected at first, but the message does say Via:
with Squid1 details. So somehow Squid1 must think this connection is a
DIRECT (origin) connection.


> As requested, here is all the information:
>
> *Squid1 version and build information:*
> Squid Cache: Version 3.5.12
> Service Name: squid
> Ubuntu linux

Please upgrade his machine if you can. All this may turn out to be a
side effect of one of the many bugs fixed already.


>
> Here is a verbatim copy of both squid.conf files, with sensitive
> information replaced:
>
> *Squid1:*
> http_port 3128 name=port_3128
> http_access allow all
> nonhierarchical_direct off
>
> acl port_3128_acl myportname port_3128
> always_direct deny port_3128_acl
> never_direct allow port_3128_acl

If this is our actual config there is no need for these ACLs. This Squid
already accepts *everything* it is handed which has even vague
resemblance of HTTP syntax. All they are doing is making a false
illusion of some control existing.

It should be sufficient to use:
  never_direct allow all
  cache_peer_access proxy3128 allow all


Really you should leave the security checks we put into the default
config. They are there to prevent things like Squid being instructed to
send spam email, or worse DoS'ing your internal network.


>
> # 3128
> cache_peer 2.2.2.2 parent 3128 0 no-query proxy-only default  name=proxy3128
> cache_peer_access proxy3128 allow port_3128_acl
> cache_peer_access proxy3128 deny all
> debug_options 11,2
>
>
> *Squid2:*
> http_access allow all
> http_port 3128
> debug_options 11,2
>
>
> And here is a copy of the cache.log for a failed request:
>
> *Squid1:*
...

> ----------
> 2018/09/03 13:36:45.088 kid1| 11,2| http.cc(2234) sendRequest: HTTP
> Server local=1.1.1.1:55718 <http://1.1.1.1:55718/> remote=2.2.2.2:3128
> <http://2.2.2.2:3128/> FD 14 flags=1
> 2018/09/03 13:36:45.089 kid1| 11,2| http.cc(2235) sendRequest: HTTP
> Server REQUEST:
> ---------
> GET /messages/391/ HTTP/1.1
> Upgrade-Insecure-Requests: 1
> User-Agent: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36
> (KHTML, like Gecko) Chrome/68.0.3440.106 Safari/537.36
> Accept:
> text/html,application/xhtml+xml,application/xml;q=0.9,image/webp,image/apng,*/*;q=0.8
> Accept-Encoding: gzip, deflate
> Accept-Language: en-US,en;q=0.9,en-GB;q=0.8
> Cookie: __cfduid=redacted; csrftoken=redacted; sessionid=redacted;
> _ga=redacted
> AlexaToolbar-ALX_NS_PH: AlexaToolbar/alx-4.0.3
> Host: redacted.com <http://redacted.com/>
> Via: 1.1 Squid1 (squid/3.5.12)
> X-Forwarded-For: 3.3.3.3
> Cache-Control: max-age=0
> Connection: keep-alive
>


Okay. Next thing to do is identify what Squid1 thinks type of connection
this FD is used for. Please add debug level "44,3 51,3" to the Squid1
config and repeat the test.



Amos
_______________________________________________
squid-users mailing list
[hidden email]
http://lists.squid-cache.org/listinfo/squid-users
Reply | Threaded
Open this post in threaded view
|

Re: Squid intermittently not sending host header to peer

Michael Thomas
Thanks Amos,

I updated both servers to Squid 4.2 and the issue persisted. I understand what you're saying about the configuration and lack of security - in production, this will be in place. I was removed to try and resolve the issue we encountered.

After adding the additional configuration to debug_options, I noticed that the issue occurs when the same socket is re-used for a second request.

I believe what's happening is that Squid is 'forgetting' that it's not connecting to the origin when a persistent connection is in use. Setting server_persistent_connections off resolves the issue, albeit in a way that will likely harm performance.

Here is an excerpt from cache.log on Squid1

Successful Request:
2018/09/05 08:20:19.401 kid1| 11,2| client_side.cc(1274) parseHttpRequest: HTTP Client local=1.1.1.1:3128 remote=3.3.3.3:52210 FD 14 flags=1
2018/09/05 08:20:19.401 kid1| 11,2| client_side.cc(1278) parseHttpRequest: HTTP Client REQUEST:
---------
Proxy-Connection: keep-alive
Cache-Control: max-age=0
Upgrade-Insecure-Requests: 1
User-Agent: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/68.0.3440.106 Safari/537.36
Accept: text/html,application/xhtml+xml,application/xml;q=0.9,image/webp,image/apng,*/*;q=0.8
Accept-Encoding: gzip, deflate
Accept-Language: en-US,en;q=0.9,en-GB;q=0.8
Cookie: __cfduid=redacted; csrftoken=redacted; sessionid=redacted; _ga=redacted
AlexaToolbar-ALX_NS_PH: AlexaToolbar/alx-4.0.3


----------
2018/09/05 08:20:19.401 kid1| 44,3| peer_select.cc(161) peerSelect: e:=IV/0x21f7e50*2 http://redacted.com/messages/391/
2018/09/05 08:20:19.401 kid1| 44,3| peer_select.cc(458) peerSelectFoo: GET redacted.com
2018/09/05 08:20:19.401 kid1| 44,3| peer_select.cc(463) peerSelectFoo: peerSelectFoo: direct = DIRECT_UNKNOWN (always_direct to be checked)
2018/09/05 08:20:19.401 kid1| 44,3| peer_select.cc(218) peerCheckAlwaysDirectDone: peerCheckAlwaysDirectDone: DENIED
2018/09/05 08:20:19.401 kid1| 44,3| peer_select.cc(458) peerSelectFoo: GET redacted.com
2018/09/05 08:20:19.401 kid1| 44,3| peer_select.cc(471) peerSelectFoo: peerSelectFoo: direct = DIRECT_UNKNOWN (never_direct to be checked)
2018/09/05 08:20:19.401 kid1| 44,3| peer_select.cc(195) peerCheckNeverDirectDone: peerCheckNeverDirectDone: ALLOWED
2018/09/05 08:20:19.401 kid1| 44,3| peer_select.cc(201) peerCheckNeverDirectDone: direct = DIRECT_NO (never_direct allow)
2018/09/05 08:20:19.401 kid1| 44,3| peer_select.cc(458) peerSelectFoo: GET redacted.com
2018/09/05 08:20:19.401 kid1| 44,3| peer_select.cc(134) peerSelectIcpPing: peerSelectIcpPing: http://redacted.com/messages/391/
2018/09/05 08:20:19.401 kid1| 44,3| peer_select.cc(145) peerSelectIcpPing: peerSelectIcpPing: counted 0 neighbors
2018/09/05 08:20:19.401 kid1| 44,3| peer_select.cc(698) peerGetSomeParent: GET redacted.com
2018/09/05 08:20:19.401 kid1| 44,3| peer_select.cc(964) peerAddFwdServer: adding FIRSTUP_PARENT/2.2.2.2
2018/09/05 08:20:19.401 kid1| 44,3| peer_select.cc(958) peerAddFwdServer: skipping ANY_OLD_PARENT/2.2.2.2; have FIRSTUP_PARENT/2.2.2.2
2018/09/05 08:20:19.401 kid1| 44,3| peer_select.cc(958) peerAddFwdServer: skipping DEFAULT_PARENT/2.2.2.2; have FIRSTUP_PARENT/2.2.2.2
2018/09/05 08:20:19.401 kid1| 44,2| peer_select.cc(281) peerSelectDnsPaths: Find IP destination for: http://redacted.com/messages/391/' via 2.2.2.2
2018/09/05 08:20:19.401 kid1| 44,2| peer_select.cc(302) peerSelectDnsPaths: Found sources for 'http://redacted.com/messages/391/'
2018/09/05 08:20:19.401 kid1| 44,2| peer_select.cc(303) peerSelectDnsPaths:   always_direct = DENIED
2018/09/05 08:20:19.401 kid1| 44,2| peer_select.cc(304) peerSelectDnsPaths:    never_direct = ALLOWED
2018/09/05 08:20:19.401 kid1| 44,2| peer_select.cc(314) peerSelectDnsPaths:      cache_peer = local=0.0.0.0 remote=2.2.2.2:3128 flags=1
2018/09/05 08:20:19.401 kid1| 44,2| peer_select.cc(317) peerSelectDnsPaths:        timedout = 0
2018/09/05 08:20:19.401 kid1| 44,3| peer_select.cc(103) ~ps_state: http://redacted.com/messages/391/
2018/09/05 08:20:19.401 kid1| 51,3| fd.cc(198) fd_open: fd_open() FD 9
2018/09/05 08:20:19.402 kid1| 11,2| http.cc(2260) sendRequest: HTTP Server local=1.1.1.1:45688 remote=2.2.2.2:3128 FD 9 flags=1
2018/09/05 08:20:19.402 kid1| 11,2| http.cc(2261) sendRequest: HTTP Server REQUEST:
---------
Upgrade-Insecure-Requests: 1
User-Agent: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/68.0.3440.106 Safari/537.36
Accept: text/html,application/xhtml+xml,application/xml;q=0.9,image/webp,image/apng,*/*;q=0.8
Accept-Encoding: gzip, deflate
Accept-Language: en-US,en;q=0.9,en-GB;q=0.8
Cookie: __cfduid=redacted; csrftoken=redacted; sessionid=redacted; _ga=redacted
AlexaToolbar-ALX_NS_PH: AlexaToolbar/alx-4.0.3
Via: 1.1 smtp01 (squid/4.2)
X-Forwarded-For: 3.3.3.3
Cache-Control: max-age=0
Connection: keep-alive


Failed Request, note: FD 9 is not closed/opened between these requests:
2018/09/05 08:20:22.124 kid1| 11,2| client_side.cc(1274) parseHttpRequest: HTTP Client local=1.1.1.1:3128 remote=3.3.3.3:52219 FD 15 flags=1
2018/09/05 08:20:22.124 kid1| 11,2| client_side.cc(1278) parseHttpRequest: HTTP Client REQUEST:
---------
Proxy-Connection: keep-alive
Cache-Control: max-age=0
Upgrade-Insecure-Requests: 1
User-Agent: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/68.0.3440.106 Safari/537.36
Accept: text/html,application/xhtml+xml,application/xml;q=0.9,image/webp,image/apng,*/*;q=0.8
Accept-Encoding: gzip, deflate
Accept-Language: en-US,en;q=0.9,en-GB;q=0.8
Cookie: __cfduid=redacted; csrftoken=redacted; sessionid=redacted; _ga=redacted
AlexaToolbar-ALX_NS_PH: AlexaToolbar/alx-4.0.3


----------
2018/09/05 08:20:22.124 kid1| 44,3| peer_select.cc(161) peerSelect: e:=IV/0x21f7e50*2 http://redacted.com/messages/391/
2018/09/05 08:20:22.124 kid1| 44,3| peer_select.cc(458) peerSelectFoo: GET redacted.com
2018/09/05 08:20:22.124 kid1| 44,3| peer_select.cc(463) peerSelectFoo: peerSelectFoo: direct = DIRECT_UNKNOWN (always_direct to be checked)
2018/09/05 08:20:22.124 kid1| 44,3| peer_select.cc(218) peerCheckAlwaysDirectDone: peerCheckAlwaysDirectDone: DENIED
2018/09/05 08:20:22.124 kid1| 44,3| peer_select.cc(458) peerSelectFoo: GET redacted.com
2018/09/05 08:20:22.124 kid1| 44,3| peer_select.cc(471) peerSelectFoo: peerSelectFoo: direct = DIRECT_UNKNOWN (never_direct to be checked)
2018/09/05 08:20:22.124 kid1| 44,3| peer_select.cc(195) peerCheckNeverDirectDone: peerCheckNeverDirectDone: ALLOWED
2018/09/05 08:20:22.124 kid1| 44,3| peer_select.cc(201) peerCheckNeverDirectDone: direct = DIRECT_NO (never_direct allow)
2018/09/05 08:20:22.124 kid1| 44,3| peer_select.cc(458) peerSelectFoo: GET redacted.com
2018/09/05 08:20:22.124 kid1| 44,3| peer_select.cc(134) peerSelectIcpPing: peerSelectIcpPing: http://redacted.com/messages/391/
2018/09/05 08:20:22.124 kid1| 44,3| peer_select.cc(145) peerSelectIcpPing: peerSelectIcpPing: counted 0 neighbors
2018/09/05 08:20:22.124 kid1| 44,3| peer_select.cc(698) peerGetSomeParent: GET redacted.com
2018/09/05 08:20:22.124 kid1| 44,3| peer_select.cc(964) peerAddFwdServer: adding FIRSTUP_PARENT/2.2.2.2
2018/09/05 08:20:22.124 kid1| 44,3| peer_select.cc(958) peerAddFwdServer: skipping ANY_OLD_PARENT/2.2.2.2; have FIRSTUP_PARENT/2.2.2.2
2018/09/05 08:20:22.124 kid1| 44,3| peer_select.cc(958) peerAddFwdServer: skipping DEFAULT_PARENT/2.2.2.2; have FIRSTUP_PARENT/2.2.2.2
2018/09/05 08:20:22.124 kid1| 44,2| peer_select.cc(281) peerSelectDnsPaths: Find IP destination for: http://redacted.com/messages/391/' via 2.2.2.2
2018/09/05 08:20:22.124 kid1| 44,2| peer_select.cc(302) peerSelectDnsPaths: Found sources for 'http://redacted.com/messages/391/'
2018/09/05 08:20:22.124 kid1| 44,2| peer_select.cc(303) peerSelectDnsPaths:   always_direct = DENIED
2018/09/05 08:20:22.124 kid1| 44,2| peer_select.cc(304) peerSelectDnsPaths:    never_direct = ALLOWED
2018/09/05 08:20:22.124 kid1| 44,2| peer_select.cc(314) peerSelectDnsPaths:      cache_peer = local=0.0.0.0 remote=2.2.2.2:3128 flags=1
2018/09/05 08:20:22.124 kid1| 44,2| peer_select.cc(317) peerSelectDnsPaths:        timedout = 0
2018/09/05 08:20:22.125 kid1| 44,3| peer_select.cc(103) ~ps_state: http://redacted.com/messages/391/
2018/09/05 08:20:22.125 kid1| 11,2| http.cc(2260) sendRequest: HTTP Server local=1.1.1.1:45688 remote=2.2.2.2:3128 FD 9 flags=1
2018/09/05 08:20:22.125 kid1| 11,2| http.cc(2261) sendRequest: HTTP Server REQUEST:
---------
GET /messages/391/ HTTP/1.1
Upgrade-Insecure-Requests: 1
User-Agent: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/68.0.3440.106 Safari/537.36
Accept: text/html,application/xhtml+xml,application/xml;q=0.9,image/webp,image/apng,*/*;q=0.8
Accept-Encoding: gzip, deflate
Accept-Language: en-US,en;q=0.9,en-GB;q=0.8
Cookie: __cfduid=redacted; csrftoken=redacted; sessionid=redacted; _ga=redacted
AlexaToolbar-ALX_NS_PH: AlexaToolbar/alx-4.0.3
Via: 1.1 smtp01 (squid/4.2)
X-Forwarded-For: 3.3.3.3
Cache-Control: max-age=0
Connection: keep-alive


_______________________________________________
squid-users mailing list
[hidden email]
http://lists.squid-cache.org/listinfo/squid-users