[squid-users] squid does not send cached object to an icap-server

Mon May 18 11:17:40 UTC 2015

Hi Yuri.
>
> http://i.imgur.com/mW7gNwD.png
>
> http://squidclamav.darold.net/config.html
>
> This is for squidclamav (I use it and have no problems with malware).

I just installed squidclamav - but the behaviour is always the same. An 
object which has been stored in squid-cache will not be detected by an 
icap server because squid does not scan the body again:

squidclamav.c(283) squidclamav_init_request_data: DEBUG initializing 
request data handler.
pool hits:5 allocations: 1
Allocating from objects pool object 0
Requested service: squidclamav
squidclamav.c(337) squidclamav_check_preview_handler: DEBUG processing 
preview header.
squidclamav.c(358) squidclamav_check_preview_handler: DEBUG X-Client-IP: 
192.168.216.54
squidclamav.c(1319) extract_http_info: DEBUG method GET
squidclamav.c(1330) extract_http_info: DEBUG url 
http://www.intern/eicar_com.zip
squidclamav.c(389) squidclamav_check_preview_handler: DEBUG URL 
requested: http://www.intern/eicar_com.zip
squidclamav.c(430) squidclamav_check_preview_handler: DEBUG 
Content-Length: 0
squidclamav.c(449) squidclamav_check_preview_handler: DEBUG No body 
data, allow 204
squidclamav.c(304) squidclamav_release_request_data: DEBUG Releasing 
request data.
Storing to objects pool object 0
Log request to access log file /var/log/c-icap/access.log
Width: 0, Parameter:

Any idea, how I can solve that problem. It seems that the only way to be 
secure is to disable caching in squid. But I hope, this can't be the 
solution.

Regards,
Stefan
>
> 05.05.15 17:45, Stefan Kügler пишет:
>> Hi Yuri.
>>
>> Am 05.05.2015 um 12:51 schrieb Yuri Voinov:
>>> This is not squid issue but your AV engine library or ICAP intermediate
>>> AV library configuration.
>>
>> Thank you for your answer.
>>
>> Can you explain me a litte bit more detailed why this is not a squid
> issue?
>>
>> In the icap-logfile, I can see a REQMOD-request _AND_ a
> RESPMOD-request to the icap-server if the object is not in cache.
>>
>> But - if the object is in cache - I can only see a REQMOD-request to
> the icap-server. I am missing RESPMOD.
>>
>> It seems to me, that it is a decision of the client (squid) which
> request (REQMOD or RESPMOD) will be send to the icap-server (AV-scanner)
> - and not a decision of the av-library.
>>
>> Regards, Stefan
>>
>>>
>>> 05.05.15 16:43, Stefan Kügler пишет:
>>>> Hello.
>>>>
>>>>
>>>> I have a short question using squid as an ICAP-client.
>>>>
>>>>
>>>> It seems that squid doesn't send an already downloaded (and cached)
>>>> object to an ICAP-server.
>>>>
>>>> Here is a short description what I have done:
>>>>
>>>> 1. downloading a word-document with a macro-virus. The Virus-scanner
>>>> (ICAP-server) uses an old pattern-file and does not detect the virus.
>>>>
>>>> The object is now in cache.
>>>>
>>>> 2. updating the virus-scanner to the newest pattern-file. The
>>>> virus-scanner will now detect the macro virus.
>>>>
>>>> 3. downloading the same word-document. The object has been delivered
>>>> to the client without a new virus scan.
>>>>
>>>>
>>>>
>>>> And now some log-entries:
>>>>
>>>> 1. First download of the word document:
>>>>
>>>> access.log:
>>>> 2015-05-05 12:23:52    144 192.168.2.54 TCP_MISS/200 553301 GET
>>>> http://www.intern/virus.doc - HIER_DIRECT/193.175.80.229
>>>> application/msword
>>>>
>>>> icap.log:
>>>> 2015-05-05 12:23:52      5 192.168.2.54 ICAP_ECHO/204 135 REQMOD
>>>> icap://127.0.0.1:1344/service_scanner - -/127.0.0.1 -
>>>> 2015-05-05 12:23:52    130 192.168.2.54 ICAP_MOD/200 553897 RESPMOD
>>>> icap://127.0.0.1:1344/service_scanner - -/127.0.0.1 -
>>>>
>>>> AV-Scanner:
>>>> May  5 12:23:52 sk1 av-icapd[12412]: [7FD24D2B0700] INFO: Starting
>>>> ICAP request decoding
>>>> May  5 12:23:52 sk1 av-icapd[12412]: [7FD24D2B0700] INFO: Request
>>>> message decoded in 1 chunks
>>>> May  5 12:23:52 sk1 av-icapd[12412]: [7FD24D2B0700] INFO: Finished
>>>> ICAP request decoding
>>>> May  5 12:23:52 sk1 av-icapd[12412]: [7FD24D2B0700] INFO: Starting
>>>> ICAP request processing
>>>> May  5 12:23:52 sk1 av-icapd[12412]: [7FD24D2B0700] INFO: Starting
>>>> service processing
>>>> May  5 12:23:52 sk1 av-icapd[12412]: [7FD24D2B0700] INFO: REQMOD
>>>> processing
>>>> May  5 12:23:52 sk1 av-icapd[12412]: [7FD24D2B0700] INFO: Resource at
>>>> <GET http://www.intern/virus.doc HTTP/1.1> has no body to be scanned
>>>> May  5 12:23:52 sk1 av-icapd[12412]: [7FD24D2B0700] INFO: Finished
>>>> service processing
>>>> May  5 12:23:52 sk1 av-icapd[12412]: [7FD24D2B0700] INFO: The request
>>>> for URI 'http://www.intern/virus.doc' was allowed (Reason: 'Clean'.
>>>> Details: '')
>>>> May  5 12:23:52 sk1 av-icapd[12412]: [7FD24D2B0700] INFO: Create
>>>> response headers type: CLEAN 204
>>>> May  5 12:23:52 sk1 av-icapd[12412]: [7FD24D2B0700] INFO: Send headers
>>>> May  5 12:23:52 sk1 av-icapd[12412]: [7FD24D2B0700] INFO: Finished
>>>> ICAP request processing
>>>> May  5 12:23:52 sk1 av-icapd[12412]: [7FD24D2B0700] INFO: Core library
>>>> session cleared
>>>> May  5 12:23:52 sk1 av-icapd[12412]: [7FD24D1AF700] INFO: Connection
>>>> closed by foreign host while waiting for requests
>>>> May  5 12:23:52 sk1 av-icapd[12412]: [7FD24D1AF700] INFO: Core library
>>>> session cleared
>>>> May  5 12:23:52 sk1 av-icapd[12412]: [7FD24CFAD700] INFO: Starting
>>>> ICAP request decoding
>>>> May  5 12:23:52 sk1 av-icapd[12412]: [7FD24CFAD700] INFO: Request
>>>> message decoded in 259 chunks
>>>> May  5 12:23:52 sk1 av-icapd[12412]: [7FD24CFAD700] INFO: Finished
>>>> ICAP request decoding
>>>> May  5 12:23:52 sk1 av-icapd[12412]: [7FD24CFAD700] INFO: Starting
>>>> ICAP request processing
>>>> May  5 12:23:52 sk1 av-icapd[12412]: [7FD24CFAD700] INFO: Starting
>>>> service processing
>>>> May  5 12:23:52 sk1 av-icapd[12412]: [7FD24CFAD700] INFO: RESPMOD
>>>> processing
>>>> May  5 12:23:52 sk1 av-icapd[12412]: [7FD24CFAD700] INFO: Starting
>>>> virus scanning for resource at: <GET http://www.intern/virus.doc
>>>> HTTP/1.1>
>>>> May  5 12:23:52 sk1 av-icapd[12412]: [7FD24CFAD700] INFO: Starting
>>>> virus scanning for resource at: <GET http://www.intern/virus.doc
>>>> HTTP/1.1>
>>>> May  5 12:23:52 sk1 av-icapd[12412]: [7FD24CFAD700] INFO:
>>>> [service_scanner]File 'virus.doc' content is stored in
>>>> '/var/spool/avira-icap/icap-tmp.6baFv3'
>>>> May  5 12:23:52 sk1 av-icapd[12412]: [7FD24CFAD700] INFO: Finished
>>>> service processing
>>>> May  5 12:23:52 sk1 av-icapd[12412]: [7FD24CFAD700] INFO: The request
>>>> for URI 'http://www.intern/virus.doc' was allowed (Reason: 'Clean'.
>>>> Details: '')
>>>> May  5 12:23:52 sk1 av-icapd[12412]: [7FD24CFAD700] INFO: Create
>>>> response headers type: CLEAN
>>>> May  5 12:23:52 sk1 av-icapd[12412]: [7FD24CFAD700] INFO: Adding HTTP
>>>> headers for response type: CLEAN
>>>> May  5 12:23:52 sk1 av-icapd[12412]: [7FD24CFAD700] INFO: Send headers
>>>> May  5 12:23:52 sk1 av-icapd[12412]: [7FD24CFAD700] INFO: Send the
>>>> original body (552960 bytes)
>>>> May  5 12:23:52 sk1 av-icapd[12412]: [7FD24CFAD700] INFO: Finished
>>>> ICAP request processing
>>>> May  5 12:23:52 sk1 av-icapd[12412]: [7FD24CFAD700] INFO: Core library
>>>> session cleared
>>>>
>>>>
>>>>
>>>>
>>>>
>>>> 2. Second download of the word document (after the pattern-update):
>>>>
>>>> access.log:
>>>> 2015-05-05 12:27:43     35 192.168.2.54 TCP_MEM_HIT/200 553309 GET
>>>> http://www.intern/virus.doc - HIER_NONE/- application/msword
>>>>
>>>> icap.log:
>>>> 2015-05-05 12:27:43      2 192.168.2.54 ICAP_ECHO/204 135 REQMOD
>>>> icap://127.0.0.1:1344/service_scanner - -/127.0.0.1 -
>>>>
>>>> AV-Scanner:
>>>> May  5 12:27:43 sk1 av-icapd[12412]: [7FD24C4A2700] INFO: Starting
>>>> ICAP request decoding
>>>> May  5 12:27:43 sk1 av-icapd[12412]: [7FD24C4A2700] INFO: Request
>>>> message decoded in 1 chunks
>>>> May  5 12:27:43 sk1 av-icapd[12412]: [7FD24C4A2700] INFO: Finished
>>>> ICAP request decoding
>>>> May  5 12:27:43 sk1 av-icapd[12412]: [7FD24C4A2700] INFO: Starting
>>>> ICAP request processing
>>>> May  5 12:27:43 sk1 av-icapd[12412]: [7FD24C4A2700] INFO: Starting
>>>> service processing
>>>> May  5 12:27:43 sk1 av-icapd[12412]: [7FD24C4A2700] INFO: REQMOD
>>>> processing
>>>> May  5 12:27:43 sk1 av-icapd[12412]: [7FD24C4A2700] INFO: Resource at
>>>> <GET http://www.intern/virus.doc HTTP/1.1> has no body to be scanned
>>>> May  5 12:27:43 sk1 av-icapd[12412]: [7FD24C4A2700] INFO: Finished
>>>> service processing
>>>> May  5 12:27:43 sk1 av-icapd[12412]: [7FD24C4A2700] INFO: The request
>>>> for URI 'http://www.intern/virus.doc' was allowed (Reason: 'Clean'.
>>>> Details: '')
>>>> May  5 12:27:43 sk1 av-icapd[12412]: [7FD24C4A2700] INFO: Create
>>>> response headers type: CLEAN 204
>>>> May  5 12:27:43 sk1 av-icapd[12412]: [7FD24C4A2700] INFO: Send headers
>>>> May  5 12:27:43 sk1 av-icapd[12412]: [7FD24C4A2700] INFO: Finished
>>>> ICAP request processing
>>>> May  5 12:27:43 sk1 av-icapd[12412]: [7FD24C4A2700] INFO: Core library
>>>> session cleared
>>>>
>>>>
>>>> And now my question: Is this a bug in squid - or is it possible to
>>>> tell squid to send already cached object to the icap-server?
>>>>
>>>> Kind regards,
>>>>
>>>> Stefan Kuegler
>>>> _______________________________________________
>>>> squid-users mailing list
>>>> squid-users at lists.squid-cache.org
>>>> http://lists.squid-cache.org/listinfo/squid-users
>>>
>>> _______________________________________________
>>> squid-users mailing list
>>> squid-users at lists.squid-cache.org
>>> http://lists.squid-cache.org/listinfo/squid-users
>
> -----BEGIN PGP SIGNATURE-----
> Version: GnuPG v2
>
> iQEcBAEBCAAGBQJVSNkvAAoJENNXIZxhPexGsh8IAJGL1gSY3rzshF+BeHmsqZIJ
> 4L0y2fjrQ66Q8Jz8fKk5saSemIdDRigH0fPAt4Bbb8cVnMcniP09cZ/lspaz3NxA
> blodVyDYSLnmWIYzFfg19nd3UWDgIq4yOz3/rXCmHEkQ5sXrJQhJeP4Azeyez4Zj
> Qef9ae75cbHexa12U8KERr9SDSnN18tRt4SPz8ZRaoYsoqIC4WRfkO8a0NPfHJp0
> cYVj8pwHwbz5TPzYpPrGRR/rPbeO5FOVlIDVrxdHbafLjeYofVR8UOnKn67dxIVu
> MJuunsVNtbPaWcDaGkUQ5Z8vvebGDB3pRPNm8XHXp7idGoDTQFJ6JbdK7ofA6do=
> =VGI/
> -----END PGP SIGNATURE-----
>

Viele Grüße - Stefan Kügler
SerNet GmbH
-- 