Maxim Dounin Wrote:
-------------------------------------------------------
> Could you please provide nginx -V output, full
> config and debug
> log for faulty request(s)? See here for
> instructions how to
> obtain debug log:
>
> http://nginx.org/en/docs/debugging_log.html
>
> Note well: using try_files and not using dynamic
> hostname
> resolution as suggested in previous reply is
> anyway preffered.
> But config as shown in your post should work
> without problems, and
> it would be good to investigate problem roots.
>
> Maxim Dounin
Many thanks for your suggestions, I have changed to use the try_files method instead (is this a new directive?). Unfortunately the behaviour is exactly the same. I've run off a debug log for a page request but it's 99kb(!) so I can't really post it all here. In it I can see there are double requests for some files and for some of these I can't see the 200. Here is a part of the debug log where you can see two requests for "main.css" (there should only be one request) and it looks to me as if only one of them is finished with proper response headers:
2010/02/05 19:42:53 [debug] 38652#171748: *4 http process request line
2010/02/05 19:42:53 [debug] 38652#171748: *4 http request line: "GET /main.css HTTP/1.1"
2010/02/05 19:42:53 [debug] 38652#171748: *4 http uri: "/main.css"
2010/02/05 19:42:53 [debug] 38652#171748: *4 http args: ""
2010/02/05 19:42:53 [debug] 38652#171748: *4 http exten: "css"
2010/02/05 19:42:53 [debug] 38652#171748: *4 http process request header line
2010/02/05 19:42:53 [debug] 38652#171748: *4 http header: "Host: new.mysite.co.uk"
2010/02/05 19:42:53 [debug] 38652#171748: *4 http header: "User-Agent: Mozilla/5.0 (Windows; U; Windows NT 5.0; en-GB; rv:1.9.1.7) Gecko/20091221 Firefox/3.5.7"
2010/02/05 19:42:53 [debug] 38652#171748: *4 http header: "Accept: text/css,*/*;q=0.1"
2010/02/05 19:42:53 [debug] 38652#171748: *4 http header: "Accept-Language: en-gb,en;q=0.5"
2010/02/05 19:42:53 [debug] 38652#171748: *4 http header: "Accept-Encoding: gzip,deflate"
2010/02/05 19:42:53 [debug] 38652#171748: *4 http header: "Accept-Charset: ISO-8859-1,utf-8;q=0.7,*;q=0.7"
2010/02/05 19:42:53 [debug] 38652#171748: *4 http header: "Keep-Alive: 300"
2010/02/05 19:42:53 [debug] 38652#171748: *4 http header: "Connection: keep-alive"
2010/02/05 19:42:53 [debug] 38652#171748: *4 http header: "Referer: http://new.mysite.co.uk/"
2010/02/05 19:42:53 [debug] 38652#171748: *4 http alloc large header buffer
2010/02/05 19:42:53 [debug] 38652#171748: *4 malloc: 007C2900:8192
2010/02/05 19:42:53 [debug] 38652#171748: *4 http large header alloc: 007C2900 8192
2010/02/05 19:42:53 [debug] 38652#171748: *4 http large header copy: 646
2010/02/05 19:42:53 [debug] 38652#171748: *4 WSARecv: fd:300 rc:0 43 of 7546
2010/02/05 19:42:53 [debug] 38652#171748: *4 http header: "Cookie: __utma=199252669.1348250431.1258842534.1265312340.1265330842.32; __utmz=199252669.1265242890.29.5.utmcsr=localhost:3002|utmccn=(referral)|utmcmd=referral|utmcct=/; __utma=254979479.1627312296.1265337519.1265366781.1265398672.6; __utmz=254979479.1265337519.1.1.utmcsr=(direct)|utmccn=(direct)|utmcmd=(none); __utmc=254979479; _MySite_session=BAh7CToPc2Vzc2lvbl9pZCIlYjhlOTZiZDllZTMxZmRlYzIxYTRjYjE5NDM0YzRlYzk6EF9jc3JmX3Rva2VuIjFXZkFDb0wyVWtMblRxeFZuZTJ1N0NEUk9ULzVxakhoSkhqaE0rR2syUTM0PSIMdXNlcl9pZGkGIgpmbGFzaElDOidBY3Rpb25Db250cm9sbGVyOjpGbGFzaDo6Rmxhc2hIYXNoewAGOgpAdXNlZHsA--f4af4fb56bea7b896f827000b464cb24ea0045d5; __utmc=199252669; __utmb=254979479.1.10.1265398672"
2010/02/05 19:42:53 [debug] 38652#171748: *4 http header done
2010/02/05 19:42:53 [debug] 38652#171748: *4 event timer del: 300: 2678663774
2010/02/05 19:42:53 [debug] 38652#171748: *4 generic phase: 0
2010/02/05 19:42:53 [debug] 38652#171748: *4 generic phase: 1
2010/02/05 19:42:53 [debug] 38652#171748: *4 test location: "/"
2010/02/05 19:42:53 [debug] 38652#171748: *4 using configuration "/"
2010/02/05 19:42:53 [debug] 38652#171748: *4 http cl:-1 max:1048576
2010/02/05 19:42:53 [debug] 38652#171748: *4 generic phase: 3
2010/02/05 19:42:53 [debug] 38652#171748: *4 post rewrite phase: 4
2010/02/05 19:42:53 [debug] 38652#171748: *4 generic phase: 5
2010/02/05 19:42:53 [debug] 38652#171748: *4 generic phase: 6
2010/02/05 19:42:53 [debug] 38652#171748: *4 generic phase: 7
2010/02/05 19:42:53 [debug] 38652#171748: *4 access phase: 8
2010/02/05 19:42:53 [debug] 38652#171748: *4 access phase: 9
2010/02/05 19:42:53 [debug] 38652#171748: *4 post access phase: 10
2010/02/05 19:42:53 [debug] 38652#171748: *4 try files phase: 11
2010/02/05 19:42:53 [debug] 38652#171748: *4 http script var: "/main.css"
2010/02/05 19:42:53 [debug] 38652#171748: *4 try to use file: "/main.css" "c:\nginx/../rails/MySite/public/main.css"
2010/02/05 19:42:53 [debug] 38652#171748: *4 try file uri: "/main.css"
2010/02/05 19:42:53 [debug] 38652#171748: *4 content phase: 12
2010/02/05 19:42:53 [debug] 38652#171748: *4 content phase: 13
2010/02/05 19:42:53 [debug] 38652#171748: *4 content phase: 14
2010/02/05 19:42:53 [debug] 38652#171748: *4 content phase: 15
2010/02/05 19:42:53 [debug] 38652#171748: *4 content phase: 16
2010/02/05 19:42:53 [debug] 38652#171748: *4 content phase: 17
2010/02/05 19:42:53 [debug] 38652#171748: *4 http filename: "c:\nginx/../rails/MySite/public/main.css"
2010/02/05 19:42:53 [debug] 38652#171748: *4 add cleanup: 007C1ECC
2010/02/05 19:42:55 [debug] 160580#180468: master WaitForMultipleObjects: 4
2010/02/05 19:42:55 [debug] 160580#180468: reap worker
2010/02/05 19:42:55 [notice] 160580#180468: worker process 38652 exited with code C0000005
2010/02/05 19:42:55 [debug] 160580#180468: GetModuleFileName: "c:\nginx\nginx.exe"
2010/02/05 19:42:55 [notice] 160580#180468: start worker process 149388
2010/02/05 19:42:55 [debug] 149388#151852: bind() 77.235.41.34:80 #240
2010/02/05 19:42:55 [debug] 149388#151852: malloc: 00775560:24
2010/02/05 19:42:55 [debug] 149388#151852: counter: 00B00080, 5
2010/02/05 19:42:55 [notice] 149388#151852: nginx/0.8.33
2010/02/05 19:42:55 [info] 149388#151852: OS: 250220 build:3790, "Service Pack 2", suite:112, type:3
2010/02/05 19:42:55 [debug] 149388#151852: worker started
2010/02/05 19:42:56 [debug] 160580#180468: WaitForMultipleObjects: 0
2010/02/05 19:42:56 [debug] 160580#180468: process: 0 149388 000006F0 e:0 j:0
2010/02/05 19:42:55 [notice] 149388#151852: create thread 142336
2010/02/05 19:42:55 [debug] 149388#142336: malloc: 007758D8:8192
2010/02/05 19:42:55 [debug] 149388#142336: malloc: 007778E0:106496
2010/02/05 19:42:55 [debug] 149388#142336: malloc: 007918E8:98304
2010/02/05 19:42:55 [notice] 149388#151852: create thread 180212
2010/02/05 19:42:56 [debug] 149388#180212: cache manager WaitForMultipleObjects: 129
2010/02/05 19:42:56 [debug] 149388#142336: malloc: 007A98F0:98304
2010/02/05 19:42:56 [notice] 149388#151852: create thread 163456
2010/02/05 19:42:56 [debug] 149388#142336: select add event fd:240 ev:0
2010/02/05 19:42:56 [debug] 149388#142336: worker cycle
2010/02/05 19:42:56 [debug] 149388#142336: select event: fd:240 wr:0
2010/02/05 19:42:56 [debug] 149388#142336: select timer: 500
2010/02/05 19:42:56 [debug] 149388#142336: select ready 1
2010/02/05 19:42:56 [debug] 149388#142336: select read 240
2010/02/05 19:42:56 [debug] 149388#142336: post event 007918E8
2010/02/05 19:42:56 [debug] 149388#142336: timer delta: 141
2010/02/05 19:42:56 [debug] 149388#142336: posted event 007918E8
2010/02/05 19:42:56 [debug] 149388#142336: delete posted event 007918E8
2010/02/05 19:42:56 [debug] 149388#142336: accept on 77.235.41.34:80, ready: 0
2010/02/05 19:42:56 [debug] 149388#142336: malloc: 007546E0:256
2010/02/05 19:42:56 [debug] 149388#142336: *5 accept: 78.86.0.188 fd:300
2010/02/05 19:42:56 [debug] 149388#142336: *5 event timer add: 300: 60000:2678651603
2010/02/05 19:42:56 [debug] 149388#142336: *5 select add event fd:300 ev:0
2010/02/05 19:42:56 [debug] 149388#142336: posted event 00000000
2010/02/05 19:42:56 [debug] 149388#142336: posted events 00000000
2010/02/05 19:42:56 [debug] 149388#142336: worker cycle
2010/02/05 19:42:56 [debug] 149388#142336: select event: fd:240 wr:0
2010/02/05 19:42:56 [debug] 149388#142336: select event: fd:300 wr:0
2010/02/05 19:42:56 [debug] 149388#142336: select timer: 500
2010/02/05 19:42:56 [debug] 149388#142336: select ready 1
2010/02/05 19:42:56 [debug] 149388#142336: select read 300
2010/02/05 19:42:56 [debug] 149388#142336: *5 post event 00791948
2010/02/05 19:42:56 [debug] 149388#142336: timer delta: 15
2010/02/05 19:42:56 [debug] 149388#142336: posted events 00791948
2010/02/05 19:42:56 [debug] 149388#142336: posted event 00791948
2010/02/05 19:42:56 [debug] 149388#142336: *5 delete posted event 00791948
2010/02/05 19:42:56 [debug] 149388#142336: *5 malloc: 0075C128:720
2010/02/05 19:42:56 [debug] 149388#142336: *5 malloc: 00900048:1024
2010/02/05 19:42:56 [debug] 149388#142336: *5 malloc: 00767FA8:4096
2010/02/05 19:42:56 [debug] 149388#142336: *5 http process request line
2010/02/05 19:42:56 [debug] 149388#142336: *5 WSARecv: fd:300 rc:0 1024 of 1024
2010/02/05 19:42:56 [debug] 149388#142336: *5 http request line: "GET /main.css HTTP/1.1"
2010/02/05 19:42:56 [debug] 149388#142336: *5 http uri: "/main.css"
2010/02/05 19:42:56 [debug] 149388#142336: *5 http args: ""
2010/02/05 19:42:56 [debug] 149388#142336: *5 http exten: "css"
2010/02/05 19:42:56 [debug] 149388#142336: *5 http process request header line
2010/02/05 19:42:56 [debug] 149388#142336: *5 http header: "Host: new.mysite.co.uk"
2010/02/05 19:42:56 [debug] 149388#142336: *5 http header: "User-Agent: Mozilla/5.0 (Windows; U; Windows NT 5.0; en-GB; rv:1.9.1.7) Gecko/20091221 Firefox/3.5.7"
2010/02/05 19:42:56 [debug] 149388#142336: *5 http header: "Accept: text/css,*/*;q=0.1"
2010/02/05 19:42:56 [debug] 149388#142336: *5 http header: "Accept-Language: en-gb,en;q=0.5"
2010/02/05 19:42:56 [debug] 149388#142336: *5 http header: "Accept-Encoding: gzip,deflate"
2010/02/05 19:42:56 [debug] 149388#142336: *5 http header: "Accept-Charset: ISO-8859-1,utf-8;q=0.7,*;q=0.7"
2010/02/05 19:42:56 [debug] 149388#142336: *5 http header: "Keep-Alive: 300"
2010/02/05 19:42:56 [debug] 149388#142336: *5 http header: "Connection: keep-alive"
2010/02/05 19:42:56 [debug] 149388#142336: *5 http header: "Referer: http://new.mysite.co.uk/"
2010/02/05 19:42:56 [debug] 149388#142336: *5 http alloc large header buffer
2010/02/05 19:42:56 [debug] 149388#142336: *5 malloc: 0075C400:256
2010/02/05 19:42:56 [debug] 149388#142336: *5 malloc: 00768FB0:8192
2010/02/05 19:42:56 [debug] 149388#142336: *5 http large header alloc: 00768FB0 8192
2010/02/05 19:42:56 [debug] 149388#142336: *5 http large header copy: 646
2010/02/05 19:42:56 [debug] 149388#142336: *5 WSARecv: fd:300 rc:0 43 of 7546
2010/02/05 19:42:56 [debug] 149388#142336: *5 http header: "Cookie: __utma=199252669.1348250431.1258842534.1265312340.1265330842.32; __utmz=199252669.1265242890.29.5.utmcsr=localhost:3002|utmccn=(referral)|utmcmd=referral|utmcct=/; __utma=254979479.1627312296.1265337519.1265366781.1265398672.6; __utmz=254979479.1265337519.1.1.utmcsr=(direct)|utmccn=(direct)|utmcmd=(none); __utmc=254979479; _MySite_session=BAh7CToPc2Vzd2lvbl9pZCIlYjhlOTZiZDllZTMxZmRlYzIxYURjYjE5NDM0YzRlYzk6EF9jc3JmX3Rva2VuIjFXZkFDb0wyVWtMblRxeFZuZTJ1N0NEUk9ULzVxalhoSkhqaE0rR2syUTM0PSIMdXNlcl9pZGkGIgpmbGFzaElDOidBY3Rpb25Db250cm9sbGVyOjpGbGFzaDo6Rmxhc2hIYZNoewAGOgpAdXNlZHsA--f4af4fb56bea7b896f827000b464cb24ea0045d5; __utmc=199252669; __utmb=254979479.1.10.1265398672"
2010/02/05 19:42:56 [debug] 149388#142336: *5 http header done
2010/02/05 19:42:56 [debug] 149388#142336: *5 event timer del: 300: 2678651603
2010/02/05 19:42:56 [debug] 149388#142336: *5 generic phase: 0
2010/02/05 19:42:56 [debug] 149388#142336: *5 generic phase: 1
2010/02/05 19:42:56 [debug] 149388#142336: *5 test location: "/"
2010/02/05 19:42:56 [debug] 149388#142336: *5 using configuration "/"
2010/02/05 19:42:56 [debug] 149388#142336: *5 http cl:-1 max:1048576
2010/02/05 19:42:56 [debug] 149388#142336: *5 generic phase: 3
2010/02/05 19:42:56 [debug] 149388#142336: *5 post rewrite phase: 4
2010/02/05 19:42:56 [debug] 149388#142336: *5 generic phase: 5
2010/02/05 19:42:56 [debug] 149388#142336: *5 generic phase: 6
2010/02/05 19:42:56 [debug] 149388#142336: *5 generic phase: 7
2010/02/05 19:42:56 [debug] 149388#142336: *5 access phase: 8
2010/02/05 19:42:56 [debug] 149388#142336: *5 access phase: 9
2010/02/05 19:42:56 [debug] 149388#142336: *5 post access phase: 10
2010/02/05 19:42:56 [debug] 149388#142336: *5 try files phase: 11
2010/02/05 19:42:56 [debug] 149388#142336: *5 http script var: "/main.css"
2010/02/05 19:42:56 [debug] 149388#142336: *5 try to use file: "/main.css" "c:\nginx/../rails/MySite/public/main.css"
2010/02/05 19:42:56 [debug] 149388#142336: *5 try file uri: "/main.css"
2010/02/05 19:42:56 [debug] 149388#142336: *5 content phase: 12
2010/02/05 19:42:56 [debug] 149388#142336: *5 content phase: 13
2010/02/05 19:42:56 [debug] 149388#142336: *5 content phase: 14
2010/02/05 19:42:56 [debug] 149388#142336: *5 content phase: 15
2010/02/05 19:42:56 [debug] 149388#142336: *5 content phase: 16
2010/02/05 19:42:56 [debug] 149388#142336: *5 content phase: 17
2010/02/05 19:42:56 [debug] 149388#142336: *5 http filename: "c:\nginx/../rails/MySite/public/main.css"
2010/02/05 19:42:56 [debug] 149388#142336: *5 add cleanup: 0076857C
2010/02/05 19:42:56 [debug] 149388#142336: *5 http static fd: 312
2010/02/05 19:42:56 [debug] 149388#142336: *5 http set discard body
2010/02/05 19:42:56 [debug] 149388#142336: *5 HTTP/1.1 200 OK
Server: nginx/0.8.33
Date: Fri, 05 Feb 2010 19:42:56 GMT
Content-Type: text/css
Content-Length: 527
Last-Modified: Fri, 05 Feb 2010 01:25:56 GMT
Connection: keep-alive
Accept-Ranges: bytes
