md5 fastcgi cache collisions

[Maxim Dounin]

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.

> >It would be also good to look at config and debug log of two
> >requests after the cache file removal.
> 
> Right now, like a watched kettle that doesn't boil it's not
> happening as I type this email...but it has happened in the last
> hour.

If you are indeed using open_file_cache - please disable it and 
try with another resource which reports the error from scratch.  

-- 
Maxim Dounin
http://nginx.com/support.html