[squid-dev] File descriptor leak at ICAP reqmod rewrites of CONNECT requests

Alexey Sergin alexey.sergin at gmail.com
Fri Dec 11 17:21:41 UTC 2020


Hi Eliezer!


> What version of Squid are you using?

I have reproduced the leak on squid versions: 4.8, 5.0.4, git master
38da9c24e.
In production deployment we use squid 4.x


> Can you provide a setup example for re-production?

Blow are the steps to reproduce the problem on the CentOS 7 system.

Test icap server is based on Example3 from
https://github.com/Peoplecantfly/icapserver/blob/master/TUTORIAL.md
The only difference is that implementations of example_REQMOD and
example_RESPMOD methods are swapped.

1. Put the following code to file server.py:
# vvvvvvvvvvvvvvvv
# vvv cut here vvv
# vvvvvvvvvvvvvvvv
import time
import threading

from icapserver import *

class ExampleICAPHandler(BaseICAPRequestHandler):

    def example_OPTIONS(self):
        self.set_icap_response(200)
        self.set_icap_header('Methods', 'RESPMOD, REQMOD')
        self.set_icap_header('Service',
            'ICAP Server' + ' ' + self._server_version)
        self.set_icap_header('Options-TTL', '3600')
        self.set_icap_header('Preview', '0')
        self.send_headers(False)

    def example_RESPMOD(self):
        self.no_adaptation_required()

    def example_REQMOD(self):
        if self.has_body:
            while True:
                if self.read_chunk() == '':
                    break
        self.set_icap_response(200)
        self.set_enc_status('HTTP/1.1 451 Unavailable For Legal Reasons')
        self.send_headers(False)

class ExampleICAPServer():

    def __init__(self, addr='', port=13440):
        self.addr = addr
        self.port = port

    def start(self):
        self.server = ICAPServer((self.addr, self.port), ExampleICAPHandler)
        self.thread = threading.Thread(target=self.server.serve_forever)
        self.thread.start()
        return True

    def stop(self):
        self.server.shutdown()
        self.server.server_close()
        self.thread.join(2)
        return True


try:
    server = ExampleICAPServer()
    server.start()
    print 'Use Control-C to exit'
    while True:
        time.sleep(1)
except KeyboardInterrupt:
    server.stop()
    print "Finished"
# ^^^^^^^^^^^^^^^^
# ^^^ cut here ^^^
# ^^^^^^^^^^^^^^^^

2. Prepare environment for test icap server:
# yum install -y python2-virtualenv
# virtualenv-2 icapserver
# source icapserver/bin/activate
# pip install icapserver

3. Run the test icap server:
# source icapserver/bin/activate
# python server.py &

4. Install squid version 4 or above (built with --enable-icap-client).

5. Rewrite /etc/squid/squid.conf:
cache deny all
cache_mem 0
shutdown_lifetime 5 seconds
http_port 3128
acl localnet src 127.0.0.1
http_access deny !localnet
http_access allow all
icap_enable on
icap_service example_req reqmod_precache icap://127.0.0.1:13440/example
adaptation_access example_req allow all
icap_service_failure_limit -1

6. Apply squid configuration changes:
# systemctl restart squid

7. Initiate http request:
# curl -q -x http://127.0.0.1:3128 https://example.com

8. Output of curl should look like:
curl: (56) Received HTTP code 451 from proxy after CONNECT

9. Leaked descriptor is in a CLOSE-WAIT state:
# ss -natpo | grep CLOSE-WAIT


> If you can supply couple(2-3 or more) ICAP connections pcap I can try to
see what happens in the connection level.

Pcap file with 3 connections attached.


> >From my experience there is much differences between holding the ICAP
session open or closed after once request.
> The reason for this is that like HTTP/1.0 ICAP is a “blocking”(don’t
remember the exact word, Alex might remember).
> There for if the proxy has 800 requests per seconds it’s better for the
setup to open new connection per request to match the load.
> It will const memory and CPU in the short term but in the long term the
clients requests will bock less and..
> It will probably consume less then the ICAP connections memory leak.

Leak happens both with and without the load.
Http client connections do leak, but ICAP connections do not.


> There for if the proxy has 800 requests per seconds it’s better for the
setup to open new connection per request to match the load.

Production ICAP server reports "Max-Connections: 5000" in response to ICAP
OPTIONS request.
Is in sufficient? If not, what should ICAP server do, and what should be
done squid (and in squid.conf), to achieve the "open new connection per
request" behaviour?


Thanks!

On Fri, Dec 11, 2020 at 12:11 AM Eliezer Croitor <ngtech1ltd at gmail.com>
wrote:

> Hey Alexey,
>
>
>
> What version of Squid are you using?
>
> Can you provide a setup example for re-production?
>
> I can write the relevant ICAP service however I am missing pcap file to
> understand the ICAP sessions.
>
> If you can supply couple(2-3 or more) ICAP connections pcap I can try to
> see what happens in the connection level.
>
>
>
> From my experience there is much differences between holding the ICAP
> session open or closed after once request.
>
> The reason for this is that like HTTP/1.0 ICAP is a “blocking”(don’t
> remember the exact word, Alex might remember).
>
> There for if the proxy has 800 requests per seconds it’s better for the
> setup to open new connection per request to match the load.
>
> It will const memory and CPU in the short term but in the long term the
> clients requests will bock less and..
>
> It will probably consume less then the ICAP connections memory leak.
>
>
>
> Waiting,
>
> Eliezer
>
>
>
> ----
>
> Eliezer Croitoru
>
> Tech Support
>
> Mobile: +972-5-28704261
>
> Email: ngtech1ltd at gmail.com
>
>
>
> *From:* squid-dev <squid-dev-bounces at lists.squid-cache.org> *On Behalf Of
> *Alexey Sergin
> *Sent:* Thursday, December 10, 2020 10:33 PM
> *To:* squid-dev at lists.squid-cache.org
> *Subject:* [squid-dev] File descriptor leak at ICAP reqmod rewrites of
> CONNECT requests
>
>
>
> Hello Squid Developers.
>
> I'm a software engineer.
>
> My team uses Squid with an ICAP server. We have noticed that Squid leaks
> file descriptor and memory when (reqmod) ICAP server replies with http "403
> Forbidden" on http CONNECT request.
>
> Here is a step-by-step description of the problematic scenario:
> - An http client connects to Squid and sends CONNECT request (for example,
> "curl -q -x http://127.0.0.1:3128 https://example.com");
> - Squid sends CONNECT request to the (reqmod) ICAP server;
> - ICAP server sends back a "403 Forbidden" http response;
> - Squid sends "403 Forbidden" http response to the http client (in the
> example above, curl reports "Received HTTP code 403 from proxy after
> CONNECT");
> - Squid writes to cache.log a message like "kick abandoning <....>";
> - Squid does not close the file descriptor used for http client connection.
>
> Those file descriptors and associated memory do pile up. For instance,
> after 200.000 forbidden requests squid (built from git master) has ~200.000
> open descriptors and consumes ~4 Gb RAM. On production deployment with
> 1000+ users it takes less than a day for Squid to eat out all available RAM.
>
> It seems that the same problem was previously reported here:
> http://www.squid-cache.org/mail-archive/squid-users/201301/0096.html
>
> Message "kick abandoning <....>" comes from ConnStateData::kick() in
> client_side.cc. Closing clientConnection right after
> "debugs(<....>abandoning<....>)" fixes the leak.
>
> Is it ok to always close() clientConnection when "abandoning" thing
> happens? Are there any known scenarios where this close() would be
> inappropriate?
>
> Could you please give me some advice on a better/proper fix, if close() at
> "abandoning" time is wrong?
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.squid-cache.org/pipermail/squid-dev/attachments/20201211/a8fc9610/attachment-0001.htm>
-------------- next part --------------
cache deny all
cache_mem 0
shutdown_lifetime 5 seconds
http_port 3128
acl localnet src 127.0.0.1
http_access deny !localnet
http_access allow all
icap_enable on
icap_service example_req reqmod_precache icap://127.0.0.1:13440/example
adaptation_access example_req allow all
icap_service_failure_limit -1
-------------- next part --------------
A non-text attachment was scrubbed...
Name: example.pcap
Type: application/vnd.tcpdump.pcap
Size: 6416 bytes
Desc: not available
URL: <http://lists.squid-cache.org/pipermail/squid-dev/attachments/20201211/a8fc9610/attachment-0001.pcap>
-------------- next part --------------
A non-text attachment was scrubbed...
Name: server.py
Type: text/x-python
Size: 1498 bytes
Desc: not available
URL: <http://lists.squid-cache.org/pipermail/squid-dev/attachments/20201211/a8fc9610/attachment-0001.py>


More information about the squid-dev mailing list