frontpage not using boost cache

[jfrstnc]

For some reason i can't get the frontpage to load from boost cache. Other pages load from boost cache quite happily it's just the frontpage that doesn't.
The config is pretty much default.

[jfrstnc]

Like you suggested in a another issue, i've added in nginx.conf

map $request_uri $is_index {
    default 0;
    /index.php 1;
    / 1;    
}

And commented out and added in drupal_boost.conf

##location = / {
##error_page 404 =200 /index.html;
##}

error_page 418 =200 @cache;
if ($is_index) {
    return 418;
}

With this setup frontpage is loaded from the boost cache for anonymous users, but only if index page exists in the cache folder. When i clear the cache, frontpage will not load, i get the drupal's "The requested page could not be found." error

For logged in users the frontpage fails to load, except if i request the index.php directly (i.e. somewebsite.com/index.php)

[perusio]

Hello,

I'm working on a new version of the config that fixes that issue. I'll push it tomorrow morning (GMT). Wait just a little bit.

That workaround is broken.

[jfrstnc]

Oh cool. Thanks for this wonderful config though, i tested my box with ab, and your config can handle 33 times more request than mine lol!

[perusio]

I've pushed a new config and I tested the frontpage cache. Try it out and report back.

[jfrstnc]

It says i'm missing fastcgi_drupal.conf

[perusio]

Oops fixed now.

[jfrstnc]

Weird behavior with this one.
On first reload the frontpage was boosted, so were all the other pages.
Then i went on to clear the boost cache but I couldn't log in normally, had to use the non clean q?=/user/login link.
Now that i've I cleared the boost cache I can't access the front page at all, i get drupal's The requested page could not be found message for both anon and logged in users.
If I try to login with /user/login the login form is loaded, but i get 405 Not Allowed from nginx when i hit submit

[perusio]

That's really strange I cannot reproduce it. I just logged in a boosted site using this config :(

[perusio]

Did you remove the previous hack? The one about /index.php not being cached?

[jfrstnc]

Yeah, i cloned the whole thing again and reconfigured. I'm using pressflow distro could that be the problem?

[perusio]

Oh. You're on D6. Then use the previous config, i.e. the drupal_boost6.conf file. The config is now splitted in D6 and D7. In D6 index.php must be accessible hence I cannot use the same config. Now on D7 the index.php file is internal. If you're using D7 pressflow I haven't tested it yet.

[perusio]

I have a very ugly hack to make the front page caching work on D6.

1. At the server level define:

    set $cache_not_visited 1;
   

2. At the @cache location define:

    set $cache_not_visited 0;
   

3. Inside the index.php location define:

    error_page 418 @cache;
   
    if ($cache_not_visited) {
        return 418;
    }
   

[perusio]

I'm testing this. Stay tuned.

[jfrstnc]

Yes, i'm using D6 pressflow :) I can get the frontpage to load now with the drupal_boost6.conf
The frontpage still wont cache. Not even with that hack above. It will give me WSOD if i put set $cache_not_visited 1; in the second server block.
I've also noticed other pages show boost cache tag only if you hit ctr+shift+F5.

[perusio]

Ok. I fixed one issue. There was a Nginx cache setting on the boost config (facepalm). It should work normally minus the frontpage not being served from Boost cache. I'm working on it.

[perusio]

Ok. I pushed the fix. It was quite simple. But as usual simplicity is the most elusive of qualities. Try it out.

[jfrstnc]

It definitely works! :D

Any ideas why i get 405 Not Allowed when trying to login with clean /user/login url? Other clean urls work just fine.

[jfrstnc]

Another issue while it worked initially, the index.php is now offered as a download file when visiting frontpage.

[perusio]

It seems that Boost is caching the login page and somehow the POST is hitting the cache. I suspect of a Boost issue. I pushed a workaround. Is commented out. Basically I added an exact location for /user/login.

location = /user/login {
    try_files $uri /index.php?q=$uri&$args;
}

[perusio]

That can only happen (download of index.php) if you have not enabled the FastCGI or proxying to an upstream that handles the PHP. e.g. (apache + mod_php). Check your PHP setup.

[jfrstnc]

I've got fastcgi running with php-fpm listening on a unix socket, not using apache at all for two weeks now.

Not sure what is going on, socket is alive processes running... all i've done recently is fiddle with nginx configs and its obviously not an nginx config issue, since index.php is being downloded with the my old (slow) working one too

[jfrstnc]

I reinstalled your config again, and set it up only changing what is absolutely necessary for it to work on my setup.
Debian6, Nginx 1.0.1,1 Drupal 6 Pressflow, PHP 5.3.8-1~dotdeb.2 (fpm-fcgi).
Using only one pool listening to a unix socket.

Changes i've made to the config are specific to my nginx server version recommended in the config.

What i've got now is a working and boosted version for anonymous users.
I'm however unable to login to the website, due to 405 Not Allowed error when using /user/login
and index.php is being downloaded when using /?q=/user/login

This is an issue specific to my setup and your config. If I reinstate my old config things are back to normal (contrary to what i've been claiming in my post above, sorry about that), I can login and pages are served from boost cache for anonymous users.
In both configs I'm using the same socket running at /var/run/php-fpm.sock

Additionally I've noticed /var/cache/nginx/microcache is not being populated, but that I guess is not related (except if microcaching supposed to work for logged in users only?)

[perusio]

Yes. The microcache is just populated if you're using the FCGI cache. The directory is created but no filesystem beneath it.

The UNIX socket will work without any issues. However when on a high-traffic site up until 5.3.8 TCP sockets are, according to my experience, much more reliable.

Glad you solved all issues.

[jfrstnc]

You've probably misread my post, I reverted to my old config just to double check if there is a problem with FastCGI (there isn't, old config works as expected).
When using your config, PHP does not get handled hence the 405 Not Allowed and the downloading of the index.php file.

If you don't mind me asking, what is considered a high-traffic website? I'm getting about 10 pageviews/second (according to google analytics realtime stats) at peak times.
According to tests i've done with http siege on a local box, unix performed about 20% better than a tcp socket.

[perusio]

Hmm. Is the FCGI server definition on upstream_phpcgi_unix.conf pointing to the correct file? Note that by default the file included is upstream_phpcgi_tcp.conf. Therefore you have to comment out line 117 and uncomment line 122 of nginx.conf to use UNIX sockets.

[jfrstnc]

Yeah that's sorted, anyway the issue is the same for either tcp or unix sockets.
Funny thing is when I do log in with

location /user/login {
     try_files $uri /index.php?q=$uri&$args;
}

some sections of the site work, like comments certain articles and whatnot, but the frontpage, and the logout page are getting downloaded :) Plus i'm getting logged out randomly on other sections of the website... so i'm kind of lost :)

[perusio]

Paste the debug log somewhere so that I can help debug this out.

[jfrstnc]

There are no other debug messages apart from this in vhost log:

2012/01/12 01:10:16 [info] 27548#0: *13 client ::ffff:xx.xxx.13.182 closed keepalive connection

and this in nginx debug log

2012/01/12 01:10:29 [info] 27548#0: *26 client closed prematurely connection while reading client request line, client: ::ffff:xx.xxx.13.182, server: mywebsite.org

What happened here was I loaded up my old working nginx conf, cleared the boost cache, then loaded your config restarted server and tried to browse.
When i try to log back in I get the cached version of "/user/login" page and then the 405 Not Allowed error upon submit.

At this point, I could not replicate the index.php download problem, but when it previously just happened out of the blue simply swapping your nginx config for mine, did not solve the problem. I had to clear my browser's cache completely and then reload my old nginx config.

Now i'm OK with my config - it works, but it lacks sophistication, microcaching and is full of if's that check for cookies headers and stuff, to decide whether to load boost cache or not.

[perusio]

This is not a debug log. A debug log is something like this. It traces pointer references and request processing at a low level. What you posted is not enough to proceed. Too vague :(

[jfrstnc]

I've got "debug" set for all error_logs occurrences.
Here is a new log with steps explained. http://pastebin.com/000C6bnS

[perusio]

Ok. Very strange. Do you have microcaching enabled? Because it's trying to read a cache file but since there are permission problems the cache_loader bombs out and the all thing dies. I've checked and there's no microcache enabled in my config. You cannot have both microcaching and Boost. Choose one. I can help you set up one or the other but not the two. They're concurrent. They cannot be used simultaneously. You can use both, for example, microcaching for authenticated users and boost for anon users. But it's a more involved config.

[jfrstnc]

Yes I enabled microcache and the permission problem occurs only if running my config.
Anyways the same thing happens when I disable microcaching.
I understand D6 Pressflow cookie management is more like that of Drupal 7? Just thinking maybe that's where my problem lies.

[perusio]

In pressflow there are no cookies for anon users.

Paste the full debug log. The one you posted above is too redacted. Just remove the IPs and hostnames. But leave everything else in place. Do this for the Boost config. It's the one I know and that I can trace the execution.

[fidelix]

05:46 is when I access /user
05:49 is when I press enter, and therefore get error 405

By the way, I am able to access /user corretly, but I get 405 when I try to login.

2012/01/12 15:05:46 [debug] 55943#0: *28 event timer del: 22: 1326409606982
2012/01/12 15:05:46 [debug] 55943#0: *28 generic phase: 0
2012/01/12 15:05:46 [debug] 55943#0: *28 rewrite phase: 1
2012/01/12 15:05:46 [debug] 55943#0: *28 http script var
2012/01/12 15:05:46 [debug] 55943#0: *28 http map started
2012/01/12 15:05:46 [debug] 55943#0: *28 http script var: "Mozilla/5.0 (Windows NT 6.1; WOW64; rv:9.0.1) Gecko/20100101 Firefox/9.0.1"
2012/01/12 15:05:46 [debug] 55943#0: *28 http map: "Mozilla/5.0 (Windows NT 6.1; WOW64; rv:9.0.1) Gecko/20100101 Firefox/9.0.1" "0"
2012/01/12 15:05:46 [debug] 55943#0: *28 http script var: "0"
2012/01/12 15:05:46 [debug] 55943#0: *28 http script if
2012/01/12 15:05:46 [debug] 55943#0: *28 http script if: false
2012/01/12 15:05:46 [debug] 55943#0: *28 http script var
2012/01/12 15:05:46 [debug] 55943#0: *28 http geo started: 0.0.0.0
2012/01/12 15:05:46 [debug] 55943#0: *28 http geo: 
2012/01/12 15:05:46 [debug] 55943#0: *28 http script var: ""
2012/01/12 15:05:46 [debug] 55943#0: *28 http script if
2012/01/12 15:05:46 [debug] 55943#0: *28 http script if: false
2012/01/12 15:05:46 [debug] 55943#0: *28 http script regex: "^(.*/?)category/.*/(.*)$"
2012/01/12 15:05:46 [notice] 55943#0: *28 "^(.*/?)category/.*/(.*)$" does not match "/user", client: 0.0.0.0, server: *.somesite.com, request: "GET /user HTTP/1.1", host: "en.somesite.com"
2012/01/12 15:05:46 [debug] 55943#0: *28 test location: "/"
2012/01/12 15:05:46 [debug] 55943#0: *28 test location: "nginx_status"
2012/01/12 15:05:46 [debug] 55943#0: *28 test location: "productcatcher"
2012/01/12 15:05:46 [debug] 55943#0: *28 test location: "rss.xml"
2012/01/12 15:05:46 [debug] 55943#0: *28 test location: "sitemap.xml"
2012/01/12 15:05:46 [debug] 55943#0: *28 test location: "/sites/default/files/advagg_js/"
2012/01/12 15:05:46 [debug] 55943#0: *28 test location: "/system/files/"
2012/01/12 15:05:46 [debug] 55943#0: *28 test location: ~ "/imagecache/"
2012/01/12 15:05:46 [debug] 55943#0: *28 test location: ~ "/files/styles/"
2012/01/12 15:05:46 [debug] 55943#0: *28 test location: ~ "^.+\.(?:css|js|jpe?g|gif|htc|ico|png|html|xml)$"
2012/01/12 15:05:46 [debug] 55943#0: *28 test location: ~ "^.+\.(?:pdf|pptx?)$"
2012/01/12 15:05:46 [debug] 55943#0: *28 test location: ~ "^(?:.+\.(?:htaccess|make|txt|engine|inc|info|install|module|profile|po|sh|.*sql|theme|tpl(?:\.php)?|xtmpl)|code-style\.pl|/Entries.*|/Repository|/Root|/Tag|/Template)$"
2012/01/12 15:05:46 [debug] 55943#0: *28 test location: ~ "/xml/"
2012/01/12 15:05:46 [debug] 55943#0: *28 test location: ~ "/sites/default/seq_flash_catalog/index.php"
2012/01/12 15:05:46 [debug] 55943#0: *28 test location: ~ "/sites/default/seq_flash_catalog/"
2012/01/12 15:05:46 [debug] 55943#0: *28 test location: ~ "^.+\.php$"
2012/01/12 15:05:46 [debug] 55943#0: *28 test location: ~ "(.*)/x-progress-id:(\w*)"
2012/01/12 15:05:46 [debug] 55943#0: *28 using configuration "/"
2012/01/12 15:05:46 [debug] 55943#0: *28 http cl:-1 max:10485760
2012/01/12 15:05:46 [debug] 55943#0: *28 rewrite phase: 3
2012/01/12 15:05:46 [debug] 55943#0: *28 rewrite phase: 4
2012/01/12 15:05:46 [debug] 55943#0: *28 post rewrite phase: 5
2012/01/12 15:05:46 [debug] 55943#0: *28 generic phase: 6
2012/01/12 15:05:46 [debug] 55943#0: *28 generic phase: 7
2012/01/12 15:05:46 [debug] 55943#0: *28 generic phase: 8
2012/01/12 15:05:46 [debug] 55943#0: *28 limit zone: 6E6ACB28 1
2012/01/12 15:05:46 [debug] 55943#0: *28 add cleanup: 00000000026620F8
2012/01/12 15:05:46 [debug] 55943#0: *28 access phase: 9
2012/01/12 15:05:46 [debug] 55943#0: *28 access phase: 10
2012/01/12 15:05:46 [debug] 55943#0: *28 access phase: 11
2012/01/12 15:05:46 [debug] 55943#0: *28 post access phase: 12
2012/01/12 15:05:46 [debug] 55943#0: *28 try files phase: 13
2012/01/12 15:05:46 [debug] 55943#0: *28 http script var: "/user"
2012/01/12 15:05:46 [debug] 55943#0: *28 trying to use file: "/user" "/www/somesite.com/live/user"
2012/01/12 15:05:46 [debug] 55943#0: *28 trying to use file: "@cache" "/www/somesite.com/live@cache"
2012/01/12 15:05:46 [debug] 55943#0: *28 test location: "@cache"
2012/01/12 15:05:46 [debug] 55943#0: *28 using location: @cache "/user?"
2012/01/12 15:05:46 [debug] 55943#0: *28 rewrite phase: 3
2012/01/12 15:05:46 [debug] 55943#0: *28 rewrite phase: 4
2012/01/12 15:05:46 [debug] 55943#0: *28 http script var
2012/01/12 15:05:46 [debug] 55943#0: *28 http map started
2012/01/12 15:05:46 [debug] 55943#0: *28 posix_memalign: 00000000026622E0:4096 @16
2012/01/12 15:05:46 [debug] 55943#0: *28 http script var: "__utma=266859866.264827013.1326141179.1326381797.1326392130.7; __utmz=266859866.1326329851.3.3.utmcsr=somesite.zomecompany.com|utmccn=(referral)|utmcmd=referral|utmcct=/life-style/fashion-blog/category/style; __utmc=266859866; shoppingfor=both; canbuy=TRUE; loc=; country=; lat=; lng=; notification_0=true"
2012/01/12 15:05:46 [debug] 55943#0: *28 http map: "__utma=266859866.264827013.1326141179.1326381797.1326392130.7; __utmz=266859866.1326329851.3.3.utmcsr=somesite.zomecompany.com|utmccn=(referral)|utmcmd=referral|utmcct=/life-style/fashion-blog/category/style; __utmc=266859866; shoppingfor=both; canbuy=TRUE; loc=; country=; lat=; lng=; notification_0=true" "0"
2012/01/12 15:05:46 [debug] 55943#0: *28 http script var: "0"
2012/01/12 15:05:46 [debug] 55943#0: *28 http script if
2012/01/12 15:05:46 [debug] 55943#0: *28 http script if: false
2012/01/12 15:05:46 [debug] 55943#0: *28 post rewrite phase: 5
2012/01/12 15:05:46 [debug] 55943#0: *28 generic phase: 6
2012/01/12 15:05:46 [debug] 55943#0: *28 generic phase: 7
2012/01/12 15:05:46 [debug] 55943#0: *28 generic phase: 8
2012/01/12 15:05:46 [debug] 55943#0: *28 access phase: 9
2012/01/12 15:05:46 [debug] 55943#0: *28 access phase: 10
2012/01/12 15:05:46 [debug] 55943#0: *28 access phase: 11
2012/01/12 15:05:46 [debug] 55943#0: *28 post access phase: 12
2012/01/12 15:05:46 [debug] 55943#0: *28 try files phase: 13
2012/01/12 15:05:46 [debug] 55943#0: *28 http script copy: "/cache/normal/"
2012/01/12 15:05:46 [debug] 55943#0: *28 http script var: "en.somesite.com"
2012/01/12 15:05:46 [debug] 55943#0: *28 http script var: "/user"
2012/01/12 15:05:46 [debug] 55943#0: *28 http script copy: "_"
2012/01/12 15:05:46 [debug] 55943#0: *28 http script copy: ".html"
2012/01/12 15:05:46 [debug] 55943#0: *28 trying to use file: "/cache/normal/en.somesite.com/user_.html" "/www/somesite.com/live/cache/normal/en.somesite.com/user_.html"
2012/01/12 15:05:46 [debug] 55943#0: *28 try file uri: "/cache/normal/en.somesite.com/user_.html"
2012/01/12 15:05:46 [debug] 55943#0: *28 content phase: 14
2012/01/12 15:05:46 [debug] 55943#0: *28 content phase: 15
2012/01/12 15:05:46 [debug] 55943#0: *28 content phase: 16
2012/01/12 15:05:46 [debug] 55943#0: *28 content phase: 17
2012/01/12 15:05:46 [debug] 55943#0: *28 content phase: 18
2012/01/12 15:05:46 [debug] 55943#0: *28 http filename: "/www/somesite.com/live/cache/normal/en.somesite.com/user_.html.gz"
2012/01/12 15:05:46 [debug] 55943#0: *28 add cleanup: 00000000026622A8
2012/01/12 15:05:46 [debug] 55943#0: *28 content phase: 19
2012/01/12 15:05:46 [debug] 55943#0: *28 http filename: "/www/somesite.com/live/cache/normal/en.somesite.com/user_.html"
2012/01/12 15:05:46 [debug] 55943#0: *28 add cleanup: 0000000002662618
2012/01/12 15:05:46 [debug] 55943#0: *28 http static fd: 23
2012/01/12 15:05:46 [debug] 55943#0: *28 http set discard body
2012/01/12 15:05:46 [debug] 55943#0: *28 http ims:1326408402 lm:1326408402
2012/01/12 15:05:46 [debug] 55943#0: *28 uploadprogress error-tracker error: 0
2012/01/12 15:05:46 [debug] 55943#0: *28 xslt filter header
2012/01/12 15:05:46 [debug] 55943#0: *28 HTTP/1.1 304 Not Modified
Server: nginx
Date: Thu, 12 Jan 2012 23:05:46 GMT
Last-Modified: Thu, 12 Jan 2012 22:46:42 GMT
Connection: keep-alive
Keep-Alive: timeout=10
Expires: Tue, 13 Jun 1977 03:45:00 GMT
Cache-Control: must-revalidate, post-check=0, pre-check=0
X-Header: Boost Helás Avril 1.0

2012/01/12 15:05:46 [debug] 55943#0: *28 write new buf t:1 f:0 00000000026627B0, pos 00000000026627B0, size: 308 file: 0, size: 0
2012/01/12 15:05:46 [debug] 55943#0: *28 http write filter: l:1 f:0 s:308
2012/01/12 15:05:46 [debug] 55943#0: *28 http write filter limit 0
2012/01/12 15:05:46 [debug] 55943#0: *28 writev: 308
2012/01/12 15:05:46 [debug] 55943#0: *28 http write filter 0000000000000000
2012/01/12 15:05:46 [debug] 55943#0: *28 http finalize request: 0, "/cache/normal/en.somesite.com/user_.html?" a:1, c:2
2012/01/12 15:05:46 [debug] 55943#0: *28 http request count:2 blk:0
2012/01/12 15:05:46 [debug] 55943#0: *28 http finalize request: -4, "/cache/normal/en.somesite.com/user_.html?" a:1, c:1
2012/01/12 15:05:46 [debug] 55943#0: *28 set http keepalive handler
2012/01/12 15:05:46 [debug] 55943#0: *28 http close request
2012/01/12 15:05:46 [debug] 55943#0: *28 http log handler
2012/01/12 15:05:46 [debug] 55943#0: *28 run cleanup: 0000000002662618
2012/01/12 15:05:46 [debug] 55943#0: *28 file cleanup: fd:23
2012/01/12 15:05:46 [debug] 55943#0: *28 run cleanup: 00000000026620F8
2012/01/12 15:05:46 [debug] 55943#0: *28 free: 00000000026612D0, unused: 8
2012/01/12 15:05:46 [debug] 55943#0: *28 free: 00000000026622E0, unused: 2520
2012/01/12 15:05:46 [debug] 55943#0: *28 event timer add: 22: 10000:1326409556995
2012/01/12 15:05:46 [debug] 55943#0: *28 free: 0000000002689F90
2012/01/12 15:05:46 [debug] 55943#0: *28 free: 000000000268A4C0
2012/01/12 15:05:46 [debug] 55943#0: *28 hc free: 0000000000000000 0
2012/01/12 15:05:46 [debug] 55943#0: *28 hc busy: 0000000000000000 0
2012/01/12 15:05:46 [debug] 55943#0: *28 tcp_nodelay
2012/01/12 15:05:46 [debug] 55943#0: *28 reusable connection: 1
2012/01/12 15:05:46 [debug] 55943#0: *28 post event 00000000026FC0D8
2012/01/12 15:05:46 [debug] 55943#0: *28 delete posted event 00000000026FC0D8
2012/01/12 15:05:46 [debug] 55943#0: *28 http keepalive handler
2012/01/12 15:05:46 [debug] 55943#0: *28 malloc: 0000000002573DC0:1024
2012/01/12 15:05:46 [debug] 55943#0: *28 recv: fd:22 -1 of 1024
2012/01/12 15:05:46 [debug] 55943#0: *28 recv() not ready (11: Resource temporarily unavailable)
2012/01/12 15:05:49 [debug] 55943#0: *29 event timer del: 23: 1326409607221
2012/01/12 15:05:49 [debug] 55943#0: *29 generic phase: 0
2012/01/12 15:05:49 [debug] 55943#0: *29 rewrite phase: 1
2012/01/12 15:05:49 [debug] 55943#0: *29 http script var
2012/01/12 15:05:49 [debug] 55943#0: *29 http map started
2012/01/12 15:05:49 [debug] 55943#0: *29 http script var: "Mozilla/5.0 (Windows NT 6.1; WOW64; rv:9.0.1) Gecko/20100101 Firefox/9.0.1"
2012/01/12 15:05:49 [debug] 55943#0: *29 http map: "Mozilla/5.0 (Windows NT 6.1; WOW64; rv:9.0.1) Gecko/20100101 Firefox/9.0.1" "0"
2012/01/12 15:05:49 [debug] 55943#0: *29 http script var: "0"
2012/01/12 15:05:49 [debug] 55943#0: *29 http script if
2012/01/12 15:05:49 [debug] 55943#0: *29 http script if: false
2012/01/12 15:05:49 [debug] 55943#0: *29 http script var
2012/01/12 15:05:49 [debug] 55943#0: *29 http geo started: 0.0.0.0
2012/01/12 15:05:49 [debug] 55943#0: *29 http geo: 
2012/01/12 15:05:49 [debug] 55943#0: *29 http script var: ""
2012/01/12 15:05:49 [debug] 55943#0: *29 http script if
2012/01/12 15:05:49 [debug] 55943#0: *29 http script if: false
2012/01/12 15:05:49 [debug] 55943#0: *29 http script regex: "^(.*/?)category/.*/(.*)$"
2012/01/12 15:05:49 [notice] 55943#0: *29 "^(.*/?)category/.*/(.*)$" does not match "/user", client: 0.0.0.0, server: *.somesite.com, request: "POST /user HTTP/1.1", host: "en.somesite.com", referrer: "http://en.somesite.com/user"
2012/01/12 15:05:49 [debug] 55943#0: *29 test location: "/"
2012/01/12 15:05:49 [debug] 55943#0: *29 test location: "nginx_status"
2012/01/12 15:05:49 [debug] 55943#0: *29 test location: "productcatcher"
2012/01/12 15:05:49 [debug] 55943#0: *29 test location: "rss.xml"
2012/01/12 15:05:49 [debug] 55943#0: *29 test location: "sitemap.xml"
2012/01/12 15:05:49 [debug] 55943#0: *29 test location: "/sites/default/files/advagg_js/"
2012/01/12 15:05:49 [debug] 55943#0: *29 test location: "/system/files/"
2012/01/12 15:05:49 [debug] 55943#0: *29 test location: ~ "/imagecache/"
2012/01/12 15:05:49 [debug] 55943#0: *29 test location: ~ "/files/styles/"
2012/01/12 15:05:49 [debug] 55943#0: *29 test location: ~ "^.+\.(?:css|js|jpe?g|gif|htc|ico|png|html|xml)$"
2012/01/12 15:05:49 [debug] 55943#0: *29 test location: ~ "^.+\.(?:pdf|pptx?)$"
2012/01/12 15:05:49 [debug] 55943#0: *29 test location: ~ "^(?:.+\.(?:htaccess|make|txt|engine|inc|info|install|module|profile|po|sh|.*sql|theme|tpl(?:\.php)?|xtmpl)|code-style\.pl|/Entries.*|/Repository|/Root|/Tag|/Template)$"
2012/01/12 15:05:49 [debug] 55943#0: *29 test location: ~ "/xml/"
2012/01/12 15:05:49 [debug] 55943#0: *29 test location: ~ "/sites/default/seq_flash_catalog/index.php"
2012/01/12 15:05:49 [debug] 55943#0: *29 test location: ~ "/sites/default/seq_flash_catalog/"
2012/01/12 15:05:49 [debug] 55943#0: *29 test location: ~ "^.+\.php$"
2012/01/12 15:05:49 [debug] 55943#0: *29 test location: ~ "(.*)/x-progress-id:(\w*)"
2012/01/12 15:05:49 [debug] 55943#0: *29 using configuration "/"
2012/01/12 15:05:49 [debug] 55943#0: *29 http cl:99 max:10485760
2012/01/12 15:05:49 [debug] 55943#0: *29 rewrite phase: 3
2012/01/12 15:05:49 [debug] 55943#0: *29 upload-progress: get_tracking_id
2012/01/12 15:05:49 [debug] 55943#0: *29 upload-progress: get_tracking_id no header found
2012/01/12 15:05:49 [debug] 55943#0: *29 upload-progress: get_tracking_id no id found
2012/01/12 15:05:49 [debug] 55943#0: *29 trackuploads no id found in POST upload req
2012/01/12 15:05:49 [debug] 55943#0: *29 rewrite phase: 4
2012/01/12 15:05:49 [debug] 55943#0: *29 post rewrite phase: 5
2012/01/12 15:05:49 [debug] 55943#0: *29 generic phase: 6
2012/01/12 15:05:49 [debug] 55943#0: *29 generic phase: 7
2012/01/12 15:05:49 [debug] 55943#0: *29 generic phase: 8
2012/01/12 15:05:49 [debug] 55943#0: *29 limit zone: 6E6ACB28 1
2012/01/12 15:05:49 [debug] 55943#0: *29 add cleanup: 0000000002662100
2012/01/12 15:05:49 [debug] 55943#0: *29 access phase: 9
2012/01/12 15:05:49 [debug] 55943#0: *29 access phase: 10
2012/01/12 15:05:49 [debug] 55943#0: *29 access phase: 11
2012/01/12 15:05:49 [debug] 55943#0: *29 post access phase: 12
2012/01/12 15:05:49 [debug] 55943#0: *29 try files phase: 13
2012/01/12 15:05:49 [debug] 55943#0: *29 http script var: "/user"
2012/01/12 15:05:49 [debug] 55943#0: *29 trying to use file: "/user" "/www/somesite.com/live/user"
2012/01/12 15:05:49 [debug] 55943#0: *29 trying to use file: "@cache" "/www/somesite.com/live@cache"
2012/01/12 15:05:49 [debug] 55943#0: *29 test location: "@cache"
2012/01/12 15:05:49 [debug] 55943#0: *29 using location: @cache "/user?"
2012/01/12 15:05:49 [debug] 55943#0: *29 rewrite phase: 3
2012/01/12 15:05:49 [debug] 55943#0: *29 upload-progress: get_tracking_id
2012/01/12 15:05:49 [debug] 55943#0: *29 upload-progress: get_tracking_id no header found
2012/01/12 15:05:49 [debug] 55943#0: *29 upload-progress: get_tracking_id no id found
2012/01/12 15:05:49 [debug] 55943#0: *29 trackuploads no id found in POST upload req
2012/01/12 15:05:49 [debug] 55943#0: *29 rewrite phase: 4
2012/01/12 15:05:49 [debug] 55943#0: *29 http script var
2012/01/12 15:05:49 [debug] 55943#0: *29 http map started
2012/01/12 15:05:49 [debug] 55943#0: *29 posix_memalign: 00000000026622E0:4096 @16
2012/01/12 15:05:49 [debug] 55943#0: *29 http script var: "__utma=266859866.264827013.1326141179.1326381797.1326392130.7; __utmz=266859866.1326329851.3.3.utmcsr=somesite.zomecompany.com|utmccn=(referral)|utmcmd=referral|utmcct=/life-style/fashion-blog/category/style; __utmc=266859866; shoppingfor=both; canbuy=TRUE; loc=; country=; lat=; lng=; notification_0=true"
2012/01/12 15:05:49 [debug] 55943#0: *29 http map: "__utma=266859866.264827013.1326141179.1326381797.1326392130.7; __utmz=266859866.1326329851.3.3.utmcsr=somesite.zomecompany.com|utmccn=(referral)|utmcmd=referral|utmcct=/life-style/fashion-blog/category/style; __utmc=266859866; shoppingfor=both; canbuy=TRUE; loc=; country=; lat=; lng=; notification_0=true" "0"
2012/01/12 15:05:49 [debug] 55943#0: *29 http script var: "0"
2012/01/12 15:05:49 [debug] 55943#0: *29 http script if
2012/01/12 15:05:49 [debug] 55943#0: *29 http script if: false
2012/01/12 15:05:49 [debug] 55943#0: *29 post rewrite phase: 5
2012/01/12 15:05:49 [debug] 55943#0: *29 generic phase: 6
2012/01/12 15:05:49 [debug] 55943#0: *29 generic phase: 7
2012/01/12 15:05:49 [debug] 55943#0: *29 generic phase: 8
2012/01/12 15:05:49 [debug] 55943#0: *29 access phase: 9
2012/01/12 15:05:49 [debug] 55943#0: *29 access phase: 10
2012/01/12 15:05:49 [debug] 55943#0: *29 access phase: 11
2012/01/12 15:05:49 [debug] 55943#0: *29 post access phase: 12
2012/01/12 15:05:49 [debug] 55943#0: *29 try files phase: 13
2012/01/12 15:05:49 [debug] 55943#0: *29 http script copy: "/cache/normal/"
2012/01/12 15:05:49 [debug] 55943#0: *29 http script var: "en.somesite.com"
2012/01/12 15:05:49 [debug] 55943#0: *29 http script var: "/user"
2012/01/12 15:05:49 [debug] 55943#0: *29 http script copy: "_"
2012/01/12 15:05:49 [debug] 55943#0: *29 http script copy: ".html"
2012/01/12 15:05:49 [debug] 55943#0: *29 trying to use file: "/cache/normal/en.somesite.com/user_.html" "/www/somesite.com/live/cache/normal/en.somesite.com/user_.html"
2012/01/12 15:05:49 [debug] 55943#0: *29 try file uri: "/cache/normal/en.somesite.com/user_.html"
2012/01/12 15:05:49 [debug] 55943#0: *29 content phase: 14
2012/01/12 15:05:49 [debug] 55943#0: *29 content phase: 15
2012/01/12 15:05:49 [debug] 55943#0: *29 content phase: 16
2012/01/12 15:05:49 [debug] 55943#0: *29 content phase: 17
2012/01/12 15:05:49 [debug] 55943#0: *29 content phase: 18
2012/01/12 15:05:49 [debug] 55943#0: *29 content phase: 19
2012/01/12 15:05:49 [debug] 55943#0: *29 http filename: "/www/somesite.com/live/cache/normal/en.somesite.com/user_.html"
2012/01/12 15:05:49 [debug] 55943#0: *29 add cleanup: 00000000026622B0
2012/01/12 15:05:49 [debug] 55943#0: *29 http static fd: 24
2012/01/12 15:05:49 [debug] 55943#0: *29 http finalize request: 405, "/cache/normal/en.somesite.com/user_.html?" a:1, c:2
2012/01/12 15:05:49 [debug] 55943#0: *29 http special response: 405, "/cache/normal/en.somesite.com/user_.html?"
2012/01/12 15:05:49 [debug] 55943#0: *29 http set discard body
2012/01/12 15:05:49 [debug] 55943#0: *29 uploadprogress error-tracker error: 405
2012/01/12 15:05:49 [debug] 55943#0: *29 uploadprogress error-tracker not tracking in this location
2012/01/12 15:05:49 [debug] 55943#0: *29 xslt filter header
2012/01/12 15:05:49 [debug] 55943#0: *29 HTTP/1.1 405 Not Allowed
Server: nginx
Date: Thu, 12 Jan 2012 23:05:49 GMT
Content-Type: text/html
Content-Length: 166
Connection: keep-alive
Keep-Alive: timeout=10

2012/01/12 15:05:49 [debug] 55943#0: *29 write new buf t:1 f:0 0000000002662620, pos 0000000002662620, size: 174 file: 0, size: 0
2012/01/12 15:05:49 [debug] 55943#0: *29 http write filter: l:0 f:0 s:174
2012/01/12 15:05:49 [debug] 55943#0: *29 http output filter "/cache/normal/en.somesite.com/user_.html?"
2012/01/12 15:05:49 [debug] 55943#0: *29 http copy filter: "/cache/normal/en.somesite.com/user_.html?"
2012/01/12 15:05:49 [debug] 55943#0: *29 image filter
2012/01/12 15:05:49 [debug] 55943#0: *29 xslt filter body
2012/01/12 15:05:49 [debug] 55943#0: *29 http postpone filter "/cache/normal/en.somesite.com/user_.html?" 0000000002662810
2012/01/12 15:05:49 [debug] 55943#0: *29 write old buf t:1 f:0 0000000002662620, pos 0000000002662620, size: 174 file: 0, size: 0
2012/01/12 15:05:49 [debug] 55943#0: *29 write new buf t:0 f:0 0000000000000000, pos 00000000006CF640, size: 120 file: 0, size: 0
2012/01/12 15:05:49 [debug] 55943#0: *29 write new buf t:0 f:0 0000000000000000, pos 00000000006CF000, size: 46 file: 0, size: 0
2012/01/12 15:05:49 [debug] 55943#0: *29 http write filter: l:1 f:0 s:340
2012/01/12 15:05:49 [debug] 55943#0: *29 http write filter limit 0
2012/01/12 15:05:49 [debug] 55943#0: *29 writev: 340
2012/01/12 15:05:49 [debug] 55943#0: *29 http write filter 0000000000000000
2012/01/12 15:05:49 [debug] 55943#0: *29 http copy filter: 0 "/cache/normal/en.somesite.com/user_.html?"
2012/01/12 15:05:49 [debug] 55943#0: *29 http finalize request: 0, "/cache/normal/en.somesite.com/user_.html?" a:1, c:2
2012/01/12 15:05:49 [debug] 55943#0: *29 http request count:2 blk:0
2012/01/12 15:05:49 [debug] 55943#0: *29 http finalize request: -4, "/cache/normal/en.somesite.com/user_.html?" a:1, c:1
2012/01/12 15:05:49 [debug] 55943#0: *29 set http keepalive handler
2012/01/12 15:05:49 [debug] 55943#0: *29 http close request
2012/01/12 15:05:49 [debug] 55943#0: *29 http log handler
2012/01/12 15:05:49 [debug] 55943#0: *29 run cleanup: 00000000026622B0
2012/01/12 15:05:49 [debug] 55943#0: *29 file cleanup: fd:24
2012/01/12 15:05:49 [debug] 55943#0: *29 run cleanup: 0000000002662100
2012/01/12 15:05:49 [debug] 55943#0: *29 free: 00000000026612D0, unused: 8
2012/01/12 15:05:49 [debug] 55943#0: *29 free: 00000000026622E0, unused: 2704
2012/01/12 15:05:49 [debug] 55943#0: *29 event timer add: 23: 10000:1326409559996
2012/01/12 15:05:49 [debug] 55943#0: *29 free: 0000000002689F90
2012/01/12 15:05:49 [debug] 55943#0: *29 free: 000000000268A4C0
2012/01/12 15:05:49 [debug] 55943#0: *29 hc free: 0000000000000000 0
2012/01/12 15:05:49 [debug] 55943#0: *29 hc busy: 0000000000000000 0
2012/01/12 15:05:49 [debug] 55943#0: *29 tcp_nodelay
2012/01/12 15:05:49 [debug] 55943#0: *29 reusable connection: 1
2012/01/12 15:05:49 [debug] 55943#0: *29 post event 00000000026FC1A8
2012/01/12 15:05:49 [debug] 55943#0: *29 delete posted event 00000000026FC1A8
2012/01/12 15:05:49 [debug] 55943#0: *29 http keepalive handler
2012/01/12 15:05:49 [debug] 55943#0: *29 malloc: 0000000002689F90:1024
2012/01/12 15:05:49 [debug] 55943#0: *29 recv: fd:23 -1 of 1024
2012/01/12 15:05:49 [debug] 55943#0: *29 recv() not ready (11: Resource temporarily unavailable)

[fidelix]

And yes, I do have correct file permissions.

[fidelix]

It's something on the drupal_boost.conf file that is NOT present on drupal.conf, because I don't get 405 with drupal.conf.

[perusio]

Try:

location @no_cache {
    try_files /index.php?q=$uri&$args =404;      
}

and report back please.

Thanks,

[fidelix]

Did you mean:

location @no_cache {
    try_files $uri /index.php?q=$uri&$args =404;      
}

???

[perusio]

@fidelix No. I mean remove $uri. This location is only hit if $no_cache is 1, hence we either have an authenticated user or a POST request.

[fidelix]

Alright, but you did forget the try_files, right?

[perusio]

@fidelix (facepalm) Yes :) Fixed.

[fidelix]

Well, now I get a 404 on all clean URL's.

[perusio]

@fidelix I can't reproduce this issue. Your config has much more stuff as the debug log above shows. So as quick fix I propose you set up a map directive like this:

map $uri $no_cache {
    default 0;
    ~^/user 1;           
}

Reinstating the @no_cache named location as it was previously.I'm going to work on the D6 config this weekend and also push an authenticated user microcache setup. Hopefully I'll be able to merge all D6 locations, i.e., with and without spaces.

[fidelix]

Thanks for the help. I hope this is something specific to my configuration.

And good luck with the work you will do with the locations, let me know if you need any help testing.

[perusio]

@fidelix I've updated the config and the README. Go grab it. Testing appreciated :)

Thanks,

[perusio]

@fidelix fixed and tested in latest version of config.