Discussion:
[squid-users] Squid intermittently not sending host header to peer
Michael Thomas
2018-09-03 09:32:44 UTC
Permalink
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
Amos Jeffries
2018-09-03 13:22:01 UTC
Permalink
Post by 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!
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
Michael Thomas
2018-09-03 14:13:00 UTC
Permalink
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:
---------
GET http://redacted.com/messages/391/ HTTP/1.1
Host: redacted.com
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
Host: 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



*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
Host: 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


----------
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:
---------
GET http://redacted.com/messages/391/ HTTP/1.1
Host: redacted.com
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:
---------
GET http://redacted.com/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
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:
---------
GET http://redacted.com/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
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 <http://4.4.4.4/> 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
Host: redacted.com
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
Post by Amos Jeffries
Post by 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!
* 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
http://lists.squid-cache.org/listinfo/squid-users
Amos Jeffries
2018-09-04 13:35:43 UTC
Permalink
This post might be inappropriate. Click to display it.
Michael Thomas
2018-09-05 09:04:57 UTC
Permalink
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:
---------
GET http://redacted.com/messages/391/ HTTP/1.1
Host: redacted.com
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:
---------
GET http://redacted.com/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
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:
---------
GET http://redacted.com/messages/391/ HTTP/1.1
Host: redacted.com
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
Host: redacted.com
Via: 1.1 smtp01 (squid/4.2)
X-Forwarded-For: 3.3.3.3
Cache-Control: max-age=0
Connection: keep-alive

Loading...