[squid-users] Spliced domains tunnel connect is very slow
Ben Goz
ben.goz87 at gmail.com
Sun Oct 22 09:46:27 UTC 2023
By the help of God.
I think I can pinpoint the problem but I'm not sure, It looks like the
issue is between c-icap and squid communication.
>From squid logs I can see lots of traces:
2023/10/22 12:31:50.654 kid1| 93,3| ModXact.cc(556) readMore: not reading
because ICAP reply pipe is full
2023/10/22 12:31:50.654 kid1| 93,3| ModXact.cc(556) readMore: not reading
because ICAP reply pipe is full
2023/10/22 12:31:50.654 kid1| 93,3| AsyncJob.cc(161) callEnd:
Adaptation::Icap::ModXact status out: [FD 319;rp(2)S(2)/RwP(ieof) job2845
And on c-icap logs I can see that squid closing connection:
Sun Oct 22 12:38:07 2023, 709785/139749352670784, Error while sending rest
responce or client closed the connection
Those traces are coming from a relatively high debug level so I'm not sure
if it's pointing to an issue but it is worth thinking about.
To me it sounds not good if c-icap needs to send back data to squid and
while it's sending the session is closed.
What do you think?
בתאריך שבת, 21 באוק׳ 2023 ב-22:35 מאת Ben Goz <ben.goz87 at gmail.com>:
> By the help of God.
>
> I'll clarify more when I'm looking at chrome's Internet Tools network
> traffic of one of the users that several
> Requests are timed out and at the same time I see in Squid's access log a
> trace that according to your explanations
> was opened for more that 60 secs for the timed out url at client side.
> This issue is observed only for certain urls while the other urls are
> working as expected.
>
> I asked the question very generally but I think I should say that the
> question is regarding TPROXY setup with ssl-bump
> And eventually an icap service. The weird thing here is that for many
> other URLs this setup works fine.
> So currently I don't have any idea how to work it out.
>
> If more information about my setup is needed please let me know.
>
> Thanks,
> Ben
>
>
>
> בתאריך יום ו׳, 20 באוק׳ 2023 ב-6:27 מאת Amos Jeffries <
> squid3 at treenet.co.nz>:
>
>> On 19/10/23 01:21, Ben Goz wrote:
>> > By the help of God.
>> >
>> > Hi,
>> > I saw in my access log a traces that shows that spliced URLs tunneling
>> > is very slowly:
>>
>> Please clarify what you mean by "slow" ?
>>
>> How have you determined speed ?
>> What speed are you expecting / would you call non-slow ?
>>
>>
>>
>> FYI, Several things to be aware of:
>>
>> 1) CONNECT tunnel is not a simple thing with a constant "speed" of
>> transfer. It represents and entire set of tunneled messages (or other
>> opaque data) over indefinite timespan. Each of those messages has its
>> own "speed" of transfer, with possible empty periods of 0 bytes
>> transferred between.
>>
>> 2) the SSL-Bump procedure may pause a CONNECT tunnel during TLS
>> handshake and/or validation process to asynchronously fetch missing
>> certificate details, and/or validate other data with ACLs, etc.
>> Each of these subsidiary transactions may add indefinite effects on
>> timing of the 'bumped' CONNECT tunnel.
>>
>> 3) modern networking systems utilize "Happy Eyeballs" algorithms
>> wherein they may open multiple TCP connections to various (or same)
>> services in parallel and only utilize the fastest to connect. This can
>> result in CONNECT tunnel being initiated and unused - either closed
>> immediately or left open waiting activity for long periods.
>>
>>
>> So, as you should be able to see the log snippet shows some details
>> about tunnels duration of use, you cannot tell "speed" from these logs.
>>
>>
>> For example:
>> >
>> > 18/Oct/2023:15:18:50 +0300 240841 192.168.3.98 TCP_TUNNEL/200 6225
>> > CONNECT beacons2.gvt2.com:443 <http://beacons2.gvt2.com:443> -
>> > HIER_DIRECT/172.217.0.67 <http://172.217.0.67> - beacons2.gvt2.com
>> > <http://beacons2.gvt2.com> - splice -
>>
>>
>> Tunnel was _open_ for 240 seconds. 6225 bytes transferred.
>>
>> Those bytes may have been transferred in the first 1 milliseconds of the
>> tunnel being open. Then Squid leaving it open waiting for further uses
>> which never came.
>>
>> ... "slow" at 1.4 GB/sec.
>>
>> ... or it could have been "slow" at 10 bytes/sec the whole time. One
>> cannot tell.
>>
>>
>> > 18/Oct/2023:15:18:50 +0300 680 192.168.3.173 TCP_TUNNEL/500 4977
>> > CONNECT mobile.events.data.microsoft.com:443
>> > <http://mobile.events.data.microsoft.com:443> - HIER_DIRECT/
>> 13.89.178.26
>> > <http://13.89.178.26> - mobile.events.data.microsoft.com
>> > <http://mobile.events.data.microsoft.com> - splice -
>>
>> This tunnel was never open at all. It was *rejected*.
>> "speed" in that case was 3 KB/sec.
>>
>>
>> > 18/Oct/2023:15:18:51 +0300 127307 192.168.3.97 TCP_TUNNEL/500 3101
>> > CONNECT array612.prod.do.dsp.mp.microsoft.com:443
>> > <http://array612.prod.do.dsp.mp.microsoft.com:443> -
>> > HIER_DIRECT/20.54.24.148 <http://20.54.24.148> -
>> > array612.prod.do.dsp.mp.microsoft.com
>> > <http://array612.prod.do.dsp.mp.microsoft.com> - splice -
>>
>> Tunnel was _open_ for 127 seconds. 3101 bytes transferred.
>>
>> Those bytes may have been transferred in the first 1 milliseconds of the
>> tunnel being open. Then Squid leaving it open waiting for further uses
>> which never came.
>>
>> ... "slow" at 376 MB/sec.
>>
>> ... or it could have been "slow" at 25 bytes/sec the whole time. One
>> cannot tell.
>>
>>
>>
>> > This is my squid configurations:
>> >
>> > acl NoSSLInterceptRegexp_always ssl::server_name --client-requested
>> > "/usr/local/squid/etc/splice.list"
>>
>> > acl alwaysBump ssl::server_name --client-requested
>> > storage.googleapis.com <http://storage.googleapis.com>
>> > youtubei.googleapis.com <http://youtubei.googleapis.com> www.eset.com
>> > <http://www.eset.com> eset.com <http://eset.com>
>> > safebrowsing.googleapis.com <http://safebrowsing.googleapis.com>
>> > play.google.com <http://play.google.com>
>> > on_unsupported_protocol tunnel
>> > acl DiscoverSNIHost at_step SslBump1
>> > ssl_bump peek DiscoverSNIHost
>> > ssl_bump bump alwaysBump - Used to bumd certain subdomains before
>> the
>> > whole domain is bumped.
>> > ssl_bump splice NoSSLInterceptRegexp_always
>> > ssl_bump stare all
>> >
>> >
>> >
>> > Other CONNECT requests are served noramly.
>> > Is this issue could be a root cause for the generally slow internet?
>> >
>> > Thanks,
>> > Ben
>> >
>> > _______________________________________________
>> > squid-users mailing list
>> > squid-users at lists.squid-cache.org
>> > https://lists.squid-cache.org/listinfo/squid-users
>> _______________________________________________
>> squid-users mailing list
>> squid-users at lists.squid-cache.org
>> https://lists.squid-cache.org/listinfo/squid-users
>>
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.squid-cache.org/pipermail/squid-users/attachments/20231022/db9b41ce/attachment-0001.htm>
More information about the squid-users
mailing list