md5 fastcgi cache collisions

[Ian Evans]

On 25/09/2012 9:16 AM, Maxim Dounin wrote:
> Hello!
>
> On Tue, Sep 25, 2012 at 01:58:17AM -0400, Ian Evans wrote:
>
>> On 25/09/2012 1:01 AM, Maxim Dounin wrote:
>>> I mean to ask about cache file, as reported in the error message
>>> provided.  But you may want to just provide several error messages
>>> to show variations possible.
>>
>> 2012/09/24 22:15:03 [crit] 641#0: *5061221 cache file
>> "/var/lib/nginx/fastcgicache/3/04/41c3d443a1763965e630855f45c2b043"
>> has md5 collision, client: x.x.x.x, server: www.example.com,
>> request: "GET /cr/tomselleck/ HTTP/1.1", host: "www.example.com"
>> 2012/09/24 22:41:52 [crit] 641#0: *5062571 cache file
>> "/var/lib/nginx/fastcgicache/3/4d/c02f0ccb51ecff32ce8f8576384a54d3"
>> has md5 collision, client: x.x.x.x, server: www.example.com,
>> request: "GET /cr/katdennings/gallery HTTP/1.1", host:
>> "www.example.com"
>> 2012/09/24 22:53:31 [crit] 641#0: *5063073 cache file
>> "/var/lib/nginx/fastcgicache/4/1f/3be079f5446cf74fbdcc64c6400301f4"
>> has md5 collision, client: x.x.x.x, server: www.example.com,
>> request: "GET /cr/drewbarrymore/ HTTP/1.1", host: "www.example.com"
>
> Ok, so there are different cache files affected.
>
>>> Fine - as a cache file, with binary header, "KEY: ..." line and so
>>> on?
>>
>> No they appear to be clean text files...no binary stuff or KEY: line
>> in them.
>
> This is the problem.
>
>>> You mean - md5 collision is reported on first request after you've
>>> removed the cache file?  Or on second request, when another cache
>>> file is already created by first request?
>>
>> It was on the first request after I deleted it.
>
> That's strange, as there shouldn't be the cache file to read from
> (as you've just deleted it).
>
> Are you using open_file_cache?  This might explain why there is a
> lag between cache file removal and disappear of error messages.
>
>>> What does nginx -V show?
>>
>> nginx version: nginx/1.2.2
>> built by gcc 4.1.2 20080704 (Red Hat 4.1.2-52)
>> TLS SNI support disabled
>> configure arguments: --with-http_stub_status_module
>> --with-http_ssl_module --with-debug --with-http_gzip_static_module
>> --with-cc-opt='-I /usr/include' --with-ld-opt='-L /usr/lib'
>
> Looks fine.
>
>>> And could you please provide hd/xxd of several first bytes of a
>>> cache file, up to and including "KEY: " line?
>>
>> As above, the fastcgi cache files are just plain html...is that wrong
>
> Yes, it's wrong.  It's not something that should happen, cache
> file header was lost somehow.

Update...was randomly looking at some of the cache files. Found one that 
is one of the /cr files in question:

ÎêaPp¯ÉI¢éaPúëd
KEY: httpGETwww.example.com/cr/brucewillis/


So that's interesting...