[squid-users] external icap issue with squid 5 and higher

Mon Feb 5 09:38:11 UTC 2024

Hello Alex,

Thank you so much for your time and this detailed analysis.

We will get back to the Forcepoint editor and ask for a correction.

Best regards,

Yvain PAYEN

Pôle Opérations & Technologies
Equipe Infrastructure système
T. +33 (0)5 57 57 01 85 (Poste 1185)
M. +33 (0)7 87 30 34 01

Absent tous les mercredi

Tessi France
Immeuble Cassiopée
1-3 avenue des Satellites
33185 Le Haillan

Pensez à l'environnement avant d'imprimer cet e-mail.

-----Message d'origine-----
De : Alex Rousskov <rousskov at measurement-factory.com> 
Envoyé : samedi 3 février 2024 04:32
À : Yvain PAYEN <yvain.payen at tessi.fr>; squid-users at lists.squid-cache.org
Objet : Re: [squid-users] external icap issue with squid 5 and higher

⚠ FR : Ce message provient de l'extérieur de l'organisation. N'ouvrez pas de liens ou de pièces jointes à moins que vous ne sachiez que le contenu est fiable.  ⚠

On 2024-02-02 17:36, Yvain PAYEN wrote:

> I just sent you a Onedrive link to 2 pcap files, one for http request 
> and one for https request.

Thank you. The ICAP service you are using is sending a malformed ICAP response to Squid. That ICAP response promises that there will be no HTTP body in the encapsulated HTTP message:

     Encapsulated: res-hdr=0, null-body=524

... but the service does send a body after HTTP headers. That HTTP body contains an HTML resource explaining that the CONNECT message was blocked and redirecting the user to blockpage.cgi, but that content does not really matter here. What matters is that there are some bytes after the encapsulated HTTP header. There should be no such bytes (or the ICAP Encapsulated header should have res-body=184 instead of null-body=524).

The null-body offset in the ICAP Encapsulated header is wrong. It should be 184 bytes (i.e. the size of the encapsulated HTTP response header), not 524 bytes. FWIW, 524 is the sum of the encapsulated HTTP response header (184 bytes) and the encapsulated HTTP response body (340 bytes).
It sounds like the ICAP service thinks that it is encapsulating an HTTP response header, but it is actually encapsulating the whole HTTP response.

Since this is an ICAP framing error(s), Squid rejects the whole transaction and bypasses the ICAP service (as configured).

To fix this, fix the ICAP service configuration (or code).

It is also possible to modify Squid code to ignore these errors, but I do not recommend that, and a hard-coded or rigid tolerance code like that should not be accepted by the Squid Project for the official inclusion.

The ICAP response in the "http request" capture does not have this problem. It contains an encapsulated HTTP 302 Moved header without any encapsulated HTTP body. That encapsulation matches the ICAP Encapsulated header.

HTH,

Alex.

> -----Message d'origine-----
> De : Alex Rousskov <rousskov at measurement-factory.com>
> Envoyé : vendredi 2 février 2024 18:45 À : Yvain PAYEN 
> <yvain.payen at tessi.fr>; squid-users at lists.squid-cache.org Objet : Re: 
> [squid-users] external icap issue with squid 5 and higher
>
> ⚠ FR : Ce message provient de l'extérieur de l'organisation. N'ouvrez 
> pas de liens ou de pièces jointes à moins que vous ne sachiez que le 
> contenu est fiable.  ⚠
>
>
>
> On 2024-02-02 12:04, Yvain PAYEN wrote:
>
>> We don't use ssl_bump, icap service only analyze HTTP CONNECT 
>> requests
>
> Great, that simplifies things a lot.
>
>
>> Adaptation::Icap::Xaction::noteCommRead threw exception: > check
>> failed: readBuf.isEmpty()> exception location: ModXact.cc(1219)
> stopParsing
>
> It looks like Squid found some leftovers after the ICAP response that Squid (thought it) had fully parsed. I do not yet know whether that ICAP response was malformed or Squid is buggy.
>
> Can you share raw ICAP response bytes (preferrably in libpcap or similar raw packet capture format) collected by tcpdump, wireshark, or a similar tool? You can obfuscate/convert that ICAP response to text as needed, but if those extra bytes get lost in those conversions, then we would not be able to tell what those bytes are (e.g., they may contain whitespace characters that get easily lost).
>
>
> Thank you,
>
> Alex.
>
>
>>        2024/02/02 17:40:41.943 kid1| 93,3| ModXact.cc(679) callException: bypassing 0x558f358fdae0*2 exception: check failed: readBuf.isEmpty()
>>                exception location: ModXact.cc(1219) stopParsing  [FD 17;rp(1)S(2)YG/Rw job17]
>>        2024/02/02 17:40:41.943 kid1| 93,7| ModXact.cc(720) disableBypass: will never start bypass because already started to bypass
>>        2024/02/02 17:40:41.943 kid1| 93,5| Xaction.cc(127) disableRepeats: Adaptation::Icap::ModXact still cannot be repeated because preparing to echo content [FD    17;rp(1)S(2)G/Rw job17]
>>        2024/02/02 17:40:41.943 kid1| 93,7| ModXact.cc(724) disableBypass: not protecting group bypass because preparing to echo content
>>        2024/02/02 17:40:41.943 kid1| 93,3| Xaction.cc(564) setOutcome: WARNING: resetting outcome: from ICAP_SAT to ICAP_ECHO
>>        2024/02/02 17:40:41.943 kid1| 93,7| ModXact.cc(962) prepEchoing: cloning virgin message 0x558f358ff040
>>        2024/02/02 17:40:41.943 kid1| 93,3| Xaction.cc(564) setOutcome: WARNING: resetting outcome: from ICAP_ECHO to ICAP_ERR_OTHER
>>        2024/02/02 17:40:41.943 kid1| 93,4| ServiceRep.cc(97) noteFailure:  failure 1 out of 10 allowed in 0sec [up,fail1]
>>        2024/02/02 17:40:41.943 kid1| 93,2| AsyncJob.cc(130) callException: check failed: !adapted.header
>>                 exception location: ModXact.cc(971) prepEchoing
>>        2024/02/02 17:40:41.943 kid1| 93,5| AsyncJob.cc(85) mustStop: Adaptation::Icap::ModXact will stop, reason: exception
>>        2024/02/02 17:40:41.943 kid1| 93,5| AsyncJob.cc(140) callEnd: Adaptation::Icap::Xaction::noteCommRead(conn8 local=X.X.X.X:46704 remote=X.X.X.X:1344 FD  17 flags=1, data=0x558f358fe888) ends job [FD 17;rp(1)S(2)/StoppedRw job17]
>>        2024/02/02 17:40:41.943 kid1| 93,5| ModXact.cc(1295) swanSong: swan sings [FD 17;rp(1)S(2)/StoppedRw job17]
>>        2024/02/02 17:40:41.943 kid1| 93,7| ModXact.cc(616) stopSending: Enter stop sending
>>        2024/02/02 17:40:41.943 kid1| 93,7| ModXact.cc(619) stopSending:
>> Proceed with stop sending
>>
>> It seems to bypass because something gone wrong.
>>
>> Yvain PAYEN
>>
>> Pôle Opérations & Technologies
>> Equipe Infrastructure système
>> T. +33 (0)5 57 57 01 85 (Poste 1185)
>> M. +33 (0)7 87 30 34 01
>>
>> Absent tous les mercredi
>>
>> Tessi France
>> Immeuble Cassiopée
>> 1-3 avenue des Satellites
>> 33185 Le Haillan
>>
>> Pensez à l'environnement avant d'imprimer cet e-mail.
>>
>> -----Message d'origine-----
>> De : squid-users <squid-users-bounces at lists.squid-cache.org> De la 
>> part de Alex Rousskov Envoyé : vendredi 2 février 2024 17:19 À :
>> squid-users at lists.squid-cache.org Objet : Re: [squid-users] external 
>> icap issue with squid 5 and higher
>>
>> ⚠ FR : Ce message provient de l'extérieur de l'organisation. N'ouvrez 
>> pas de liens ou de pièces jointes à moins que vous ne sachiez que le 
>> contenu est fiable.  ⚠
>>
>>
>>
>> On 2024-02-02 11:00, Yvain PAYEN wrote:
>>> Hi Squid users,
>>>
>>> I have an issue with an external icap service I have to use (from 
>>> Forcepoint).
>>>
>>> This service is working great with squid v3 and v4.
>>>
>>> Starting v5 (v6 also tested) the service only work with plain text 
>>> http requests, all requests for https content are allowed even if 
>>> the website should be denied.
>>
>> Do you use ssl_bump rules to decode affected HTTPS traffic? Or is your service supposed to analyze plain HTTP CONNECT requests?
>>
>> With Squid v6, does your ICAP service actually receive expected "requests for https content" for analysis from Squid? Or does Squid allow them without contacting the ICAP service with those requests? You can check service logs and/or enable icap.log in Squid to answer these high-level questions (see icap_log).
>>
>>
>>> My first question is : do you know if a big change in the icap code 
>>> happened between v4 and v5 ?
>>
>> I do not recall, unfortunately; it was too long ago. Please keep in mind that your problems may not be triggered by ICAP code changes (if any).
>>
>>
>>> My second question : How can I trace only icap debug logs
>>
>> ICAP code uses debug section 93. See debug_options directive and docs/debug-sections.txt.
>>
>>
>> HTH,
>>
>> Alex.
>>
>>
>>
>>> Service is setup like this :
>>>
>>> icap_service service_req reqmod_precache icap://10.1.1.1:1344/icap
>>> bypass=1
>>>
>>> Regards,
>>>
>>> *Yvain PAYEN*
>>>
>>> *
>>> **Pôle Opérations & Technologies
>>> *Equipe Infrastructure système
>>> T. +33 (0)5 57 57 01 85 (Poste 1185)
>>>
>>> M. +33 (0)7 87 30 34 01
>>>
>>> Absent tous les mercredi
>>>
>>>
>>> Tessi France
>>> Immeuble Cassiopée
>>>
>>> 1-3 avenue des Satellites
>>> 33185 Le Haillan
>>>
>>>
>>> *yvain.payen at tessi.fr <mailto:yvain.payen at tessi.fr> www.tessi.eu 
>>> <www.tessi.eu>
>>> ***
>>> Pensez à l'environnement avant d'imprimer cet e-mail.**
>>>
>>>
>>> _______________________________________________
>>> 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
>