Discussion:
[squid-users] https: fails with CONNECT error:invalid-request
(too old to reply)
Brand, Thomas R.
2006-09-20 21:37:18 UTC
Permalink
Hi,

Squid newbie here with a problem regarding squid and HTTPS.
HTTP URLS work as desired. I've spent the past two days googling
and reading the archives, but still don't understand how to
build/configure Squid to do what I want.

Any pointers/help would be greatly appreciated.

Setup :

Remote office user ->
Remote office Squid (squid-2.6.STABLE2) -> Company WAN ->
HQ ISA2004 proxy server ->
External Sites

User (remote office) connects to an URL https://www.aaa.com
Browser is configured to use proxy server (Squid 2.6 STABLE 2, UnixWare
7.1.3)
Proxy server is at the remote office.

Squid forwards request to ISA2004 proxy server at main office
"cache_peer 10.6.10.20 parent 8080 0 no-query default
no-digest"
ISA proxy server passes request on to the outside world.
User receives " The connection to www.aaa.com was interrupted while the
page was loading."

SQUID logs show " CONNECT error:invalid-request"

Squid was configured with:
./configure -q \
--enable-delay-pools \
--enable-cache-digests \
--enable-poll \
--disable-ident-lookups \
--enable-truncate \
--enable-agent-log \
--enable-referer-log \
--enable-default-err-language=English \
--enable-err-languages=English


access.log:1158787213.443 0 10.31.129.28 TCP_DENIED/400 1381
CONNECT error:invalid-request - NONE/- text/html

cache.log:2006/09/20 17:20:13| storeKeyPrivate: CONNECT
error:invalid-request
cache.log:2006/09/20 17:20:13| errorConvert: %R --> 'CONNECT
www.ipledgeprogram.com:443 HTTP/1.1
cache.log:2006/09/20 17:20:13| The reply for CONNECT
error:invalid-request is ALLOWED, because it matched 'all'

store.log:1158787213.443 RELEASE -1 FFFFFFFF
637E356A235E6902243378ABCC05146A 400 1158787213 0 1158787213
text/html 1381/1381 CONNECT error:invalid-request
cvs9058[logs]


Tom Brand
Henrik Nordstrom
2006-09-20 22:05:00 UTC
Permalink
Post by Brand, Thomas R.
access.log:1158787213.443 0 10.31.129.28 TCP_DENIED/400 1381
CONNECT error:invalid-request - NONE/- text/html
Looks like your Squid didn't like the request at all.

What does cache.log say?

Regards
Henrik
Brand, Thomas R.
2006-09-21 16:03:27 UTC
Permalink
-----Original Message-----
Post by Henrik Nordstrom
Looks like your Squid didn't like the request at all.
What does cache.log say?
The cache log is as follows, see end of page for access.log and
store.log for the same timeframe.

With what (little) I know right now, I suspect that either:
1) the coporate proxy server is refusing the https connection
from my squid server, or
2) I have to modify something in my configuration file, or
3) To use pass-thru https requests, I need to build squid
using '--enable-ssl'
4) both 2 & 3

Thanks for helping out.
Tom


cvs9058[logs] cat cache.log
2006/09/21 11:51:39| Starting Squid Cache version 2.6.STABLE2 for
i686-unknown-sysv5UnixWare7.1.3...
2006/09/21 11:51:39| Process ID 22047
2006/09/21 11:51:39| With 2048 file descriptors available
2006/09/21 11:51:39| DNS Socket created at 0.0.0.0, port 33787, FD 4
2006/09/21 11:51:39| Adding nameserver 10.16.11.11 from /etc/resolv.conf
2006/09/21 11:51:39| Adding nameserver 10.4.3.112 from /etc/resolv.conf
2006/09/21 11:51:39| Adding domain rxstores.cvs.com from
/etc/resolv.conf
2006/09/21 11:51:39| Adding domain cvs.com from /etc/resolv.conf
2006/09/21 11:51:39| Referer logging is disabled.
2006/09/21 11:51:39| Unlinkd pipe opened on FD 9
2006/09/21 11:51:39| Swap maxSize 102400 KB, estimated 7876 objects
2006/09/21 11:51:39| Target number of buckets: 393
2006/09/21 11:51:39| Using 8192 Store buckets
2006/09/21 11:51:39| Max Mem size: 8192 KB
2006/09/21 11:51:39| Max Swap size: 102400 KB
2006/09/21 11:51:39| storeDigestCalcCap: have: 0, want 7876 entries;
limits: [1, 7876]
2006/09/21 11:51:39| cacheDigestInit: capacity: 7876 entries, bpe: 5;
size: 4923 bytes
2006/09/21 11:51:39| Local cache digest enabled; rebuild/rewrite every
3600/3600 sec
2006/09/21 11:51:39| Rebuilding storage in /usr/local/squid/var/cache
(CLEAN)
2006/09/21 11:51:39| Using Least Load store dir selection
2006/09/21 11:51:39| Set Current Directory to
/usr/local/squid/var/coredumps
2006/09/21 11:51:39| Loaded Icons.
2006/09/21 11:51:39| Accepting transparently proxied HTTP connections at
0.0.0.0, port 80, FD 11.
2006/09/21 11:51:39| WCCP Disabled.
2006/09/21 11:51:39| WCCPv2 Disabled.
2006/09/21 11:51:39| Configuring Parent 10.64.2.72/80/0
2006/09/21 11:51:39| --> IP address #0: 10.64.2.72
2006/09/21 11:51:39| Ready to serve requests.
2006/09/21 11:51:39| Done reading /usr/local/squid/var/cache swaplog
(249 entries)
2006/09/21 11:51:39| xrename: renaming
/usr/local/squid/var/cache/swap.state.new to
/usr/local/squid/var/cache/swap.state
2006/09/21 11:51:39| Finished rebuilding storage from disk.
2006/09/21 11:51:39| 249 Entries scanned
2006/09/21 11:51:39| 0 Invalid entries.
2006/09/21 11:51:39| 0 With invalid flags.
2006/09/21 11:51:39| 249 Objects loaded.
2006/09/21 11:51:39| 0 Objects expired.
2006/09/21 11:51:39| 0 Objects cancelled.
2006/09/21 11:51:39| 0 Duplicate URLs purged.
2006/09/21 11:51:39| 0 Swapfile clashes avoided.
2006/09/21 11:51:39| Took 0.4 seconds ( 605.7 objects/sec).
2006/09/21 11:51:39| Beginning Validation Procedure
2006/09/21 11:51:40| Completed Validation Procedure
2006/09/21 11:51:40| Validated 249 Entries
2006/09/21 11:51:40| store_swap_size = 3146k
2006/09/21 11:51:40| storeDigestRebuildStart: rebuild #1
2006/09/21 11:51:40| storeDigestCalcCap: have: 274, want 274 entries;
limits: [243, 7876]
2006/09/21 11:51:40| storeDigestResize: 7876 -> 274; change: 7602 (97%)
2006/09/21 11:51:40| storeDigestResize: big change, resizing.
2006/09/21 11:51:40| cacheDigestInit: capacity: 274 entries, bpe: 5;
size: 172 bytes
2006/09/21 11:51:40| storeDigestRewrite: start rewrite #1
2006/09/21 11:51:40| storeDigestRewriteStart: waiting for rebuild to
finish.
2006/09/21 11:51:40| storeDigestRebuildFinish: done.
2006/09/21 11:51:40| storeDigestRewriteFinish: digest expires at
1158857500 (+3600)
2006/09/21 11:51:40| storeLateRelease: released 0 objects
2006/09/21 11:51:45| NOTICE: no explicit transparent proxy support.
Assuming getsockname works
2006/09/21 11:51:45| The request GET
http://sb.google.com/safebrowsing/update?version=goog-sandbox-text:1:5&w
rkey=MTrwnZd9nPSBFSlC3vjL0M_4 is AL
LOWED, because it matched 'all'
2006/09/21 11:51:45| aclMatchRegex: match '\?' found in
'/safebrowsing/update?version=goog-sandbox-text:1:5&wrkey=MTrwnZd9nPSBFS
lC3vjL0M_4'
2006/09/21 11:51:45| The reply for GET
http://sb.google.com/safebrowsing/update?version=goog-sandbox-text:1:5&w
rkey=MTrwnZd9nPSBFSlC3vjL0M_4 is
ALLOWED, because it matched 'all'
2006/09/21 11:51:45| fwdServerClosed: FD 12
http://sb.google.com/safebrowsing/update?version=goog-sandbox-text:1:5&w
rkey=MTrwnZd9nPSBFSlC3vjL0M_
4
2006/09/21 11:52:14| The request GET http://www.woot.com/Blog/Rss.aspx
is ALLOWED, because it matched 'all'
2006/09/21 11:52:14| The reply for GET http://www.woot.com/Blog/Rss.aspx
is ALLOWED, because it matched 'all'
2006/09/21 11:52:14| fwdServerClosed: FD 12
http://www.woot.com/Blog/Rss.aspx
2006/09/21 11:52:29| The request GET
http://blogs.ittoolbox.com/RSSNewBlogs.asp is ALLOWED, because it
matched 'all'
2006/09/21 11:52:29| The reply for GET
http://blogs.ittoolbox.com/RSSNewBlogs.asp is ALLOWED, because it
matched 'all'
2006/09/21 11:52:29| fwdServerClosed: FD 12
http://blogs.ittoolbox.com/RSSNewBlogs.asp
2006/09/21 11:52:31| clientReadRequest: FD 10 Invalid Request
2006/09/21 11:52:31| The reply for CONNECT error:invalid-request is
ALLOWED, because it matched 'all'
2006/09/21 11:52:36| Preparing for shutdown after 4 requests
2006/09/21 11:52:36| Waiting 30 seconds for active connections to finish

cvs9058[logs] cat access.log
1158853905.613 19 10.31.129.28 TCP_MISS/502 2622 GET
http://sb.google.com/safebrowsing/update? - DEFAULT_PARENT/10.64.2.72
text/html
1158853934.264 19 10.31.129.28 TCP_MISS/502 2622 GET
http://www.woot.com/Blog/Rss.aspx - DEFAULT_PARENT/10.64.2.72 text/html
1158853949.260 19 10.31.129.28 TCP_MISS/502 2622 GET
http://blogs.ittoolbox.com/RSSNewBlogs.asp - DEFAULT_PARENT/10.64.2.72
text/html
1158853951.535 0 10.31.129.28 TCP_DENIED/400 1381 CONNECT
error:invalid-request - NONE/- text/html


cvs9058[logs] cat store.log
1158853905.613 RELEASE -1 FFFFFFFF 6C929B18F5ACD096CF20542F98215314 502
-1 -1 -1 text/html 2358/2358 GET
http://sb.google.com/safebrowsing/update?
1158853934.264 RELEASE -1 FFFFFFFF 5326E7ABDF2D3885D9FB47D2BD3F7FD2 502
-1 -1 -1 text/html 2358/2358 GET
http://www.woot.com/Blog/Rss.aspx
1158853949.260 RELEASE -1 FFFFFFFF 517A296D24FF5EA30F5FC8C6185D9634 502
-1 -1 -1 text/html 2358/2358 GET
http://blogs.ittoolbox.com/RSSNewBlogs.asp
1158853951.535 RELEASE -1 FFFFFFFF 8A86CF060E86EDCF94E6B2078B2CE473 400
1158853951 0 1158853951 text/html 1381/1381 CONNECT
error:invalid-request
cvs9058[logs
Henrik Nordstrom
2006-09-22 02:23:45 UTC
Permalink
Post by Brand, Thomas R.
1) the coporate proxy server is refusing the https connection
from my squid server, or
2) I have to modify something in my configuration file, or
3) To use pass-thru https requests, I need to build squid
using '--enable-ssl'
4) both 2 & 3
As I said there is something about this CONNECT request your Squid
heavily dislikes. So it's none of the above..

I was expecting some more information about the request to be shown in
cache.log, but unfortunately there is only "invalid request" which isn't
very much to go on..

Hmm.. how is your http_port configured? Just remembered that if you for
some reason have configured Squid as an accelerator then CONNECT won't
be supported as it's not relevant in accelerator mode.

Regards
Henrik

Loading...