403 forbidden with private files

[ghost]

Hello,

I have a 403 forbidden for each file served via the private folder. I can't see any thumbnail, favicon, logo, etc...

I tried to change the path for my private folder, to modify the system/files rule, mothing changes.

Can you help me ?

Thanks.

[perusio]

These files pass through drupal right? Can you access the files directly? Do you get a 404 if you do?

[ghost]

I get a 403 if I try to access by system/files and a 404 by /sites/.*/files/private/.

The intended behavior for direct acces is ok but the processing by drupal causes a problem. I don't know if it's related to the nginx config or drupal itself.

[ghost]

I can upload files and they appear in the folders so it's not a permission problem.

[ghost]

I tested with a fressh drupal installation and it didn't work. So, it is a nginx or php-fpm config problem. I use the php-fpm config you created also (the unix branch).

[ghost]

I would like to test further with simpletest, to see deeper if it's a drupal problem, but it requires to acces to php files. What are the directives I should comment during the tests ?

[perusio]

I think there's something wrong with the interaction between drupal and Nginx. Get a debug log of the request so that I can help you further.

[ghost]

Sorry for the late answer. Estern was there.

Here is my log for the welcome page (more than 4000 lines, sorry):

2013/04/02 10:21:22 [debug] 26682#0: _6181 event timer del: 27: 1364890912868 2013/04/02 10:21:22 [debug] 26682#0: 6181 generic phase: 0 2013/04/02 10:21:22 [debug] 26682#0: 6181 rewrite phase: 1 2013/04/02 10:21:22 [debug] 26682#0: 6181 http script var 2013/04/02 10:21:22 [debug] 26682#0: 6181 http map started 2013/04/02 10:21:22 [debug] 26682#0: 6181 http script var: "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.22 (KHTML, like Gecko) Ubuntu Chromium/25.0.1364.160 Chrome/25.0.1364.160 Safari/537.22" 2013/04/02 10:21:22 [debug] 26682#0: 6181 http map: "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.22 (KHTML, like Gecko) Ubuntu Chromium/25.0.1364.160 Chrome/25.0.1364.160 Safari/537.22" "0" 2013/04/02 10:21:22 [debug] 26682#0: 6181 http script var: "0" 2013/04/02 10:21:22 [debug] 26682#0: 6181 http script if 2013/04/02 10:21:22 [debug] 26682#0: 6181 http script if: false 2013/04/02 10:21:22 [debug] 26682#0: 6181 http script var 2013/04/02 10:21:22 [debug] 26682#0: 6181 http geo started: 172.19.32.67 2013/04/02 10:21:22 [debug] 26682#0: 6181 http geo: 2013/04/02 10:21:22 [debug] 26682#0: 6181 http script var: "" 2013/04/02 10:21:22 [debug] 26682#0: 6181 http script if 2013/04/02 10:21:22 [debug] 26682#0: 6181 http script if: false 2013/04/02 10:21:22 [debug] 26682#0: 6181 http script var 2013/04/02 10:21:22 [debug] 26682#0: 6181 http map started 2013/04/02 10:21:22 [debug] 26682#0: 6181 http script var: "GET" 2013/04/02 10:21:22 [debug] 26682#0: 6181 http map: "GET" "0" 2013/04/02 10:21:22 [debug] 26682#0: 6181 http script var: "0" 2013/04/02 10:21:22 [debug] 26682#0: 6181 http script if 2013/04/02 10:21:22 [debug] 26682#0: 6181 http script if: false 2013/04/02 10:21:22 [debug] 26682#0: 6181 test location: "/" 2013/04/02 10:21:22 [debug] 26682#0: 6181 test location: "/sites/172.19.65.71/files/audio/ogg" 2013/04/02 10:21:22 [debug] 26682#0: 6181 test location: "/sites/172.19.65.71/files/advagg_js/" 2013/04/02 10:21:22 [debug] 26682#0: 6181 test location: "/sites/172.19.65.71/files/advagg_css/" 2013/04/02 10:21:22 [debug] 26682#0: 6181 test location: "/help/" 2013/04/02 10:21:22 [debug] 26682#0: 6181 test location: ~ "/imagecache/" 2013/04/02 10:21:22 [debug] 26682#0: 6181 test location: ~ "/files/styles/" 2013/04/02 10:21:22 [debug] 26682#0: 6181 test location: ~ "^.+.(?:css|cur|js|jpg|jpeg|gif|ico|png|html|xml)$" 2013/04/02 10:21:22 [debug] 26682#0: 6181 test location: ~ "^.+.(?:pdf|pptx?)$" 2013/04/02 10:21:22 [debug] 26682#0: 6181 test location: ~ "^(?:.+.(?:htaccess|make|txt|engine|inc|info|install|module|profile|po|sh|.sql|test|theme|tpl(?:.php)?|xtmpl)|code-style.pl|/Entries.|/Repository|/Root|/Tag|/Template)$" 2013/04/02 10:21:22 [debug] 26682#0: 6181 test location: ~ "^.+.php$" 2013/04/02 10:21:22 [debug] 26682#0: 6181 test location: ~ "(?._)/x-progress-id:(?\d_)" 2013/04/02 10:21:22 [debug] 26682#0: 6181 using configuration "/" 2013/04/02 10:21:22 [debug] 26682#0: 6181 http cl:-1 max:10485760 2013/04/02 10:21:22 [debug] 26682#0: 6181 rewrite phase: 3 2013/04/02 10:21:22 [debug] 26682#0: 6181 rewrite phase: 4 2013/04/02 10:21:22 [debug] 26682#0: 6181 post rewrite phase: 5 2013/04/02 10:21:22 [debug] 26682#0: 6181 generic phase: 6 2013/04/02 10:21:22 [debug] 26682#0: 6181 generic phase: 7 2013/04/02 10:21:22 [debug] 26682#0: 6181 generic phase: 8 2013/04/02 10:21:22 [debug] 26682#0: 6181 limit conn: 42C85000 1 2013/04/02 10:21:22 [debug] 26682#0: 6181 add cleanup: 0000000002393280 2013/04/02 10:21:22 [debug] 26682#0: 6181 access phase: 9 2013/04/02 10:21:22 [debug] 26682#0: 6181 access phase: 10 2013/04/02 10:21:22 [debug] 26682#0: 6181 access phase: 11 2013/04/02 10:21:22 [debug] 26682#0: 6181 access phase: 12 2013/04/02 10:21:22 [debug] 26682#0: 6181 post access phase: 13 2013/04/02 10:21:22 [debug] 26682#0: 6181 try files phase: 14 2013/04/02 10:21:22 [debug] 26682#0: 6181 http script var: "/" 2013/04/02 10:21:22 [debug] 26682#0: 6181 trying to use file: "/" "/var/www/drupalair/" 2013/04/02 10:21:22 [debug] 26682#0: 6181 trying to use file: "@cache" "/var/www/drupalair@cache" 2013/04/02 10:21:22 [debug] 26682#0: 6181 test location: "@cache" 2013/04/02 10:21:22 [debug] 26682#0: 6181 using location: @cache "/?" 2013/04/02 10:21:22 [debug] 26682#0: 6181 rewrite phase: 3 2013/04/02 10:21:22 [debug] 26682#0: 6181 rewrite phase: 4 2013/04/02 10:21:22 [debug] 26682#0: 6181 posix_memalign: 0000000002393330:4096 @16 2013/04/02 10:21:22 [debug] 26682#0: 6181 http script var 2013/04/02 10:21:22 [debug] 26682#0: 6181 http map started 2013/04/02 10:21:22 [debug] 26682#0: 6181 http script var: "Drupal.tableDrag.showWeight=0; SESS773cbbd8c4121e030ddac5237a542fce=rvwU8AROtsn1FltAsHi3OCsxJXr_Adx5zrKSOSqsgRs; has_js=1; _pk_id.1.db96=d1c334637f15b083.1363607937.34.1364890882.1364884290.; _pkses.1.db96=" 2013/04/02 10:21:22 [debug] 26682#0: _6181 http map: "Drupal.tableDrag.showWeight=0; SESS773cbbd8c4121e030ddac5237a542fce=rvwU8AROtsn1FltAsHi3OCsxJXr_Adx5zrKSOSqsgRs; has_js=1; _pk_id.1.db96=d1c334637f15b083.1363607937.34.1364890882.1364884290.; _pkses.1.db96=" "1" 2013/04/02 10:21:22 [debug] 26682#0: _6181 http script var: "1" 2013/04/02 10:21:22 [debug] 26682#0: 6181 http script if 2013/04/02 10:21:22 [debug] 26682#0: 6181 http finalize request: 418, "/?" a:1, c:2 2013/04/02 10:21:22 [debug] 26682#0: 6181 http special response: 418, "/?" 2013/04/02 10:21:22 [debug] 26682#0: 6181 test location: "@cache" 2013/04/02 10:21:22 [debug] 26682#0: 6181 test location: "@drupal" 2013/04/02 10:21:22 [debug] 26682#0: 6181 using location: @drupal "/?" 2013/04/02 10:21:22 [debug] 26682#0: 6181 rewrite phase: 3 2013/04/02 10:21:22 [debug] 26682#0: 6181 rewrite phase: 4 2013/04/02 10:21:22 [debug] 26682#0: 6181 post rewrite phase: 5 2013/04/02 10:21:22 [debug] 26682#0: 6181 generic phase: 6 2013/04/02 10:21:22 [debug] 26682#0: 6181 generic phase: 7 2013/04/02 10:21:22 [debug] 26682#0: 6181 generic phase: 8 2013/04/02 10:21:22 [debug] 26682#0: 6181 access phase: 9 2013/04/02 10:21:22 [debug] 26682#0: 6181 access phase: 10 2013/04/02 10:21:22 [debug] 26682#0: 6181 access phase: 11 2013/04/02 10:21:22 [debug] 26682#0: 6181 access phase: 12 2013/04/02 10:21:22 [debug] 26682#0: 6181 post access phase: 13 2013/04/02 10:21:22 [debug] 26682#0: 6181 try files phase: 14 2013/04/02 10:21:22 [debug] 26682#0: 6181 upload-progress: ngx_http_uploadprogress_content_handler 2013/04/02 10:21:22 [debug] 26682#0: 6181 http init upstream, client timer: 0 2013/04/02 10:21:22 [debug] 26682#0: 6181 epoll add event: fd:27 op:3 ev:80000005 2013/04/02 10:21:22 [debug] 26682#0: 6181 http map started 2013/04/02 10:21:22 [debug] 26682#0: 6181 http script var: "Drupal.tableDrag.showWeight=0; SESS773cbbd8c4121e030ddac5237a542fce=rvwU8AROtsn1FltAsHi3OCsxJXr_Adx5zrKSOSqsgRs; has_js=1; _pk_id.1.db96=d1c334637f15b083.1363607937.34.1364890882.1364884290.; _pkses.1.db96=" 2013/04/02 10:21:22 [debug] 26682#0: _6181 http regex set $session_id to "rvwU8AROtsn1FltAsHi3OCsxJXr_Adx5zrKSOSqsgRs;" 2013/04/02 10:21:22 [debug] 26682#0: 6181 http map: "Drupal.tableDrag.showWeight=0; SESS773cbbd8c4121e030ddac5237a542fce=rvwU8AROtsn1FltAsHi3OCsxJXr_Adx5zrKSOSqsgRs; has_js=1; _pk_id.1.db96=d1c334637f15b083.1363607937.34.1364890882.1364884290.; _pkses.1.db96=" "rvwU8AROtsn1FltAsHi3OCsxJXr_Adx5zrKSOSqsgRs;" 2013/04/02 10:21:22 [debug] 26682#0: _6181 http script var: "rvwU8AROtsn1FltAsHi3OCsxJXr_Adx5zrKSOSqsgRs;" 2013/04/02 10:21:22 [debug] 26682#0: 6181 http script copy: "@" 2013/04/02 10:21:22 [debug] 26682#0: 6181 http script var: "172.19.65.71" 2013/04/02 10:21:22 [debug] 26682#0: 6181 http script var: "/" 2013/04/02 10:21:22 [debug] 26682#0: 6181 http cache key: "rvwU8AROtsn1FltAsHi3OCsxJXr_Adx5zrKSOSqsgRs;@172.19.65.71/" 2013/04/02 10:21:22 [debug] 26682#0: 6181 add cleanup: 0000000002393300 2013/04/02 10:21:22 [debug] 26682#0: 6181 http file cache exists: 0 e:1 2013/04/02 10:21:22 [debug] 26682#0: 6181 cache file: "/var/cache/nginx/microcache/3/dc/d3c9006473ee85c3d7e3f16c6a7d7dc3" 2013/04/02 10:21:22 [debug] 26682#0: 6181 add cleanup: 0000000002393F08 2013/04/02 10:21:22 [debug] 26682#0: 6181 http file cache fd: 30 2013/04/02 10:21:22 [debug] 26682#0: 6181 read: 30, 0000000002393F88, 531, 0 2013/04/02 10:21:22 [debug] 26682#0: 6181 http file cache expired: 4 1364890879 1364890882 2013/04/02 10:21:22 [debug] 26682#0: 6181 http upstream cache: 4 2013/04/02 10:21:22 [debug] 26682#0: 6181 posix_memalign: 0000000002394340:4096 @16 2013/04/02 10:21:22 [debug] 26682#0: 6181 http script copy: "QUERY_STRING" 2013/04/02 10:21:22 [debug] 26682#0: 6181 http script copy: "q=" 2013/04/02 10:21:22 [debug] 26682#0: 6181 http script var: "/" 2013/04/02 10:21:22 [debug] 26682#0: 6181 http script copy: "&" 2013/04/02 10:21:22 [debug] 26682#0: 6181 fastcgi param: "QUERY_STRING: q=/&" 2013/04/02 10:21:22 [debug] 26682#0: 6181 http script copy: "REQUEST_METHOD" 2013/04/02 10:21:22 [debug] 26682#0: 6181 http script var: "GET" 2013/04/02 10:21:22 [debug] 26682#0: 6181 fastcgi param: "REQUEST_METHOD: GET" 2013/04/02 10:21:22 [debug] 26682#0: 6181 http script copy: "CONTENT_TYPE" 2013/04/02 10:21:22 [debug] 26682#0: 6181 fastcgi param: "CONTENT_TYPE: " 2013/04/02 10:21:22 [debug] 26682#0: 6181 http script copy: "CONTENT_LENGTH" 2013/04/02 10:21:22 [debug] 26682#0: 6181 fastcgi param: "CONTENT_LENGTH: " 2013/04/02 10:21:22 [debug] 26682#0: 6181 http script copy: "SCRIPT_NAME" 2013/04/02 10:21:22 [debug] 26682#0: 6181 http script copy: "/index.php" 2013/04/02 10:21:22 [debug] 26682#0: 6181 fastcgi param: "SCRIPT_NAME: /index.php" 2013/04/02 10:21:22 [debug] 26682#0: 6181 http script copy: "REQUEST_URI" 2013/04/02 10:21:22 [debug] 26682#0: 6181 http script var: "/" 2013/04/02 10:21:22 [debug] 26682#0: 6181 fastcgi param: "REQUEST_URI: /" 2013/04/02 10:21:22 [debug] 26682#0: 6181 http script copy: "DOCUMENT_URI" 2013/04/02 10:21:22 [debug] 26682#0: 6181 http script var: "/" 2013/04/02 10:21:22 [debug] 26682#0: 6181 fastcgi param: "DOCUMENT_URI: /" 2013/04/02 10:21:22 [debug] 26682#0: 6181 http script copy: "DOCUMENT_ROOT" 2013/04/02 10:21:22 [debug] 26682#0: 6181 http script var: "/var/www/drupalair" 2013/04/02 10:21:22 [debug] 26682#0: 6181 fastcgi param: "DOCUMENT_ROOT: /var/www/drupalair" 2013/04/02 10:21:22 [debug] 26682#0: 6181 http script copy: "SERVER_PROTOCOL" 2013/04/02 10:21:22 [debug] 26682#0: 6181 http script var: "HTTP/1.1" 2013/04/02 10:21:22 [debug] 26682#0: 6181 fastcgi param: "SERVER_PROTOCOL: HTTP/1.1" 2013/04/02 10:21:22 [debug] 26682#0: 6181 http script copy: "GATEWAY_INTERFACE" 2013/04/02 10:21:22 [debug] 26682#0: 6181 http script copy: "CGI/1.1" 2013/04/02 10:21:22 [debug] 26682#0: 6181 fastcgi param: "GATEWAY_INTERFACE: CGI/1.1" 2013/04/02 10:21:22 [debug] 26682#0: 6181 http script copy: "SERVER_SOFTWARE" 2013/04/02 10:21:22 [debug] 26682#0: 6181 http script copy: "nginx/" 2013/04/02 10:21:22 [debug] 26682#0: 6181 http script var: "1.2.7" 2013/04/02 10:21:22 [debug] 26682#0: 6181 fastcgi param: "SERVER_SOFTWARE: nginx/1.2.7" 2013/04/02 10:21:22 [debug] 26682#0: 6181 http script copy: "REMOTE_ADDR" 2013/04/02 10:21:22 [debug] 26682#0: 6181 http script var: "172.19.32.67" 2013/04/02 10:21:22 [debug] 26682#0: 6181 fastcgi param: "REMOTE_ADDR: 172.19.32.67" 2013/04/02 10:21:22 [debug] 26682#0: 6181 http script copy: "REMOTE_PORT" 2013/04/02 10:21:22 [debug] 26682#0: 6181 http script var: "54601" 2013/04/02 10:21:22 [debug] 26682#0: 6181 fastcgi param: "REMOTE_PORT: 54601" 2013/04/02 10:21:22 [debug] 26682#0: 6181 http script copy: "SERVER_ADDR" 2013/04/02 10:21:22 [debug] 26682#0: 6181 http script var: "172.19.65.71" 2013/04/02 10:21:22 [debug] 26682#0: 6181 fastcgi param: "SERVER_ADDR: 172.19.65.71" 2013/04/02 10:21:22 [debug] 26682#0: 6181 http script copy: "SERVER_PORT" 2013/04/02 10:21:22 [debug] 26682#0: 6181 http script var: "80" 2013/04/02 10:21:22 [debug] 26682#0: 6181 fastcgi param: "SERVER_PORT: 80" 2013/04/02 10:21:22 [debug] 26682#0: 6181 http script copy: "SERVER_NAME" 2013/04/02 10:21:22 [debug] 26682#0: 6181 http script var: "172.19.65.71" 2013/04/02 10:21:22 [debug] 26682#0: 6181 fastcgi param: "SERVER_NAME: 172.19.65.71" 2013/04/02 10:21:22 [debug] 26682#0: 6181 http script copy: "REDIRECT_STATUS" 2013/04/02 10:21:22 [debug] 26682#0: 6181 http script copy: "200" 2013/04/02 10:21:22 [debug] 26682#0: 6181 fastcgi param: "REDIRECT_STATUS: 200" 2013/04/02 10:21:22 [debug] 26682#0: 6181 http script copy: "SCRIPT_FILENAME" 2013/04/02 10:21:22 [debug] 26682#0: 6181 http script var: "/var/www/drupalair" 2013/04/02 10:21:22 [debug] 26682#0: 6181 http script copy: "/index.php" 2013/04/02 10:21:22 [debug] 26682#0: 6181 fastcgi param: "SCRIPT_FILENAME: /var/www/drupalair/index.php" 2013/04/02 10:21:22 [debug] 26682#0: 6181 fastcgi param: "HTTP_HOST: 172.19.65.71" 2013/04/02 10:21:22 [debug] 26682#0: 6181 fastcgi param: "HTTP_CONNECTION: keep-alive" 2013/04/02 10:21:22 [debug] 26682#0: 6181 fastcgi param: "HTTP_CACHE_CONTROL: max-age=0" 2013/04/02 10:21:22 [debug] 26682#0: 6181 fastcgi param: "HTTPACCEPT: text/html,application/xhtml+xml,application/xml;q=0.9,/_;q=0.8" 2013/04/02 10:21:22 [debug] 26682#0: 6181 fastcgi param: "HTTP_USER_AGENT: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.22 (KHTML, like Gecko) Ubuntu Chromium/25.0.1364.160 Chrome/25.0.1364.160 Safari/537.22" 2013/04/02 10:21:22 [debug] 26682#0: 6181 fastcgi param: "HTTP_REFERER: http://172.19.65.71/user" 2013/04/02 10:21:22 [debug] 26682#0: 6181 fastcgi param: "HTTP_ACCEPT_ENCODING: gzip,deflate,sdch" 2013/04/02 10:21:22 [debug] 26682#0: 6181 fastcgi param: "HTTP_ACCEPT_LANGUAGE: fr-FR,fr;q=0.8,en-US;q=0.6,en;q=0.4" 2013/04/02 10:21:22 [debug] 26682#0: 6181 fastcgi param: "HTTP_ACCEPTCHARSET: ISO-8859-1,utf-8;q=0.7,;q=0.3" 2013/04/02 10:21:22 [debug] 26682#0: _6181 fastcgi param: "HTTP_COOKIE: Drupal.tableDrag.showWeight=0; SESS773cbbd8c4121e030ddac5237a542fce=rvwU8AROtsn1FltAsHi3OCsxJXr_Adx5zrKSOSqsgRs; has_js=1; _pk_id.1.db96=d1c334637f15b083.1363607937.34.1364890882.1364884290.; _pkses.1.db96=" 2013/04/02 10:21:22 [debug] 26682#0: 6181 http cleanup add: 00000000023942E8 2013/04/02 10:21:22 [debug] 26682#0: 6181 [upstream_fair] peer 0 is idle 2013/04/02 10:21:22 [debug] 26682#0: 6181 [upstream_fair] chose peer 0 2013/04/02 10:21:22 [debug] 26682#0: 6181 [upstream_fair] fp->current = 0, peer_id = 0, ret = 0 2013/04/02 10:21:22 [debug] 26682#0: 6181 [upstream_fair] nreq for peer 0 @ 0000000002371AB0/00007FC0AD569050 now 1, total 1, delta 1 2013/04/02 10:21:22 [debug] 26682#0: 6181 socket 31 2013/04/02 10:21:22 [debug] 26682#0: 6181 epoll add connection: fd:31 ev:80000005 2013/04/02 10:21:22 [debug] 26682#0: 6181 connect to unix:/var/run/php-fpm.sock, fd:31 #6184 2013/04/02 10:21:22 [debug] 26682#0: 6181 connected 2013/04/02 10:21:22 [debug] 26682#0: 6181 http upstream connect: 0 2013/04/02 10:21:22 [debug] 26682#0: 6181 posix_memalign: 0000000002436330:128 @16 2013/04/02 10:21:22 [debug] 26682#0: 6181 http upstream send request 2013/04/02 10:21:22 [debug] 26682#0: 6181 chain writer buf fl:0 s:1168 2013/04/02 10:21:22 [debug] 26682#0: 6181 chain writer in: 00000000023947F0 2013/04/02 10:21:22 [debug] 26682#0: 6181 writev: 1168 2013/04/02 10:21:22 [debug] 26682#0: 6181 chain writer out: 0000000000000000 2013/04/02 10:21:22 [debug] 26682#0: 6181 event timer add: 31: 14400000:1364905282872 2013/04/02 10:21:22 [debug] 26682#0: 6181 http finalize request: -4, "/?" a:1, c:4 2013/04/02 10:21:22 [debug] 26682#0: 6181 http request count:4 blk:0 2013/04/02 10:21:22 [debug] 26682#0: 6181 http finalize request: -4, "/?" a:1, c:3 2013/04/02 10:21:22 [debug] 26682#0: 6181 http request count:3 blk:0 2013/04/02 10:21:22 [debug] 26682#0: 6181 http finalize request: -4, "/?" a:1, c:2 2013/04/02 10:21:22 [debug] 26682#0: 6181 http request count:2 blk:0 2013/04/02 10:21:22 [debug] 26682#0: 6181 post event 00007FC0A7235690 2013/04/02 10:21:22 [debug] 26682#0: 6181 post event 00007FC0A7235488 2013/04/02 10:21:22 [debug] 26682#0: 6181 delete posted event 00007FC0A7235488 2013/04/02 10:21:22 [debug] 26682#0: 6181 http upstream request: "/?" 2013/04/02 10:21:22 [debug] 26682#0: 6181 http upstream dummy handler 2013/04/02 10:21:22 [debug] 26682#0: 6181 delete posted event 00007FC0A7235690 2013/04/02 10:21:22 [debug] 26682#0: 6181 http run request: "/?" 2013/04/02 10:21:22 [debug] 26682#0: 6181 http upstream check client, write event:1, "/" 2013/04/02 10:21:22 [debug] 26682#0: 6181 http upstream recv(): -1 (11: Resource temporarily unavailable) 2013/04/02 10:21:23 [debug] 26682#0: 6181 post event 00007FC0A7418488 2013/04/02 10:21:23 [debug] 26682#0: 6181 post event 00007FC0A7235488 2013/04/02 10:21:23 [debug] 26682#0: 6181 delete posted event 00007FC0A7235488 2013/04/02 10:21:23 [debug] 26682#0: 6181 http upstream request: "/?" 2013/04/02 10:21:23 [debug] 26682#0: 6181 http upstream dummy handler 2013/04/02 10:21:23 [debug] 26682#0: 6181 delete posted event 00007FC0A7418488 2013/04/02 10:21:23 [debug] 26682#0: 6181 http upstream request: "/?" 2013/04/02 10:21:23 [debug] 26682#0: 6181 http upstream process header 2013/04/02 10:21:23 [debug] 26682#0: 6181 malloc: 00000000023722A0:4096 2013/04/02 10:21:23 [debug] 26682#0: 6181 recv: fd:31 3991 of 3991 2013/04/02 10:21:23 [debug] 26682#0: 6181 http fastcgi record byte: 01 2013/04/02 10:21:23 [debug] 26682#0: 6181 http fastcgi record byte: 06 2013/04/02 10:21:23 [debug] 26682#0: 6181 http fastcgi record byte: 00 2013/04/02 10:21:23 [debug] 26682#0: 6181 http fastcgi record byte: 01 2013/04/02 10:21:23 [debug] 26682#0: 6181 http fastcgi record byte: 11 2013/04/02 10:21:23 [debug] 26682#0: 6181 http fastcgi record byte: F1 2013/04/02 10:21:23 [debug] 26682#0: 6181 http fastcgi record byte: 07 2013/04/02 10:21:23 [debug] 26682#0: 6181 http fastcgi record byte: 00 2013/04/02 10:21:23 [debug] 26682#0: 6181 http fastcgi record length: 4593 2013/04/02 10:21:23 [debug] 26682#0: 6181 http fastcgi parser: 0 2013/04/02 10:21:23 [debug] 26682#0: 6181 http fastcgi header: "Expires: Sun, 19 Nov 1978 05:00:00 GMT" 2013/04/02 10:21:23 [debug] 26682#0: 6181 http fastcgi parser: 0 2013/04/02 10:21:23 [debug] 26682#0: 6181 http fastcgi header: "Last-Modified: Tue, 02 Apr 2013 08:21:22 +0000" 2013/04/02 10:21:23 [debug] 26682#0: 6181 http fastcgi parser: 0 2013/04/02 10:21:23 [debug] 26682#0: 6181 http fastcgi header: "Cache-Control: no-cache, must-revalidate, post-check=0, pre-check=0" 2013/04/02 10:21:23 [debug] 26682#0: 6181 http fastcgi parser: 0 2013/04/02 10:21:23 [debug] 26682#0: 6181 http fastcgi header: "ETag: "1364890882"" 2013/04/02 10:21:23 [debug] 26682#0: 6181 http fastcgi parser: 0 2013/04/02 10:21:23 [debug] 26682#0: 6181 http fastcgi header: "Content-Type: text/html; charset=utf-8" 2013/04/02 10:21:23 [debug] 26682#0: 6181 http fastcgi parser: 0 2013/04/02 10:21:23 [debug] 26682#0: 6181 http fastcgi header: "Content-Language: fr" 2013/04/02 10:21:23 [debug] 26682#0: 6181 http fastcgi parser: 0 2013/04/02 10:21:23 [debug] 26682#0: 6181 http fastcgi header: "X-Generator: Drupal 7 (http://drupal.org)" 2013/04/02 10:21:23 [debug] 26682#0: 6181 http fastcgi parser: 0 2013/04/02 10:21:23 [debug] 26682#0: 6181 http fastcgi header: "Link: http://172.19.65.71/; rel="canonical",http://172.19.65.71/; rel="shortlink"" 2013/04/02 10:21:23 [debug] 26682#0: 6181 http fastcgi parser: 0 2013/04/02 10:21:23 [debug] 26682#0: 6181 http fastcgi header: "Content-Encoding: gzip" 2013/04/02 10:21:23 [debug] 26682#0: 6181 http fastcgi parser: 0 2013/04/02 10:21:23 [debug] 26682#0: 6181 http fastcgi header: "Vary: Accept-Encoding" 2013/04/02 10:21:23 [debug] 26682#0: 6181 http fastcgi parser: 1 2013/04/02 10:21:23 [debug] 26682#0: 6181 http fastcgi header done 2013/04/02 10:21:23 [debug] 26682#0: 6181 http ims:1364890863 lm:1364890882 2013/04/02 10:21:23 [debug] 26682#0: 6181 http script var: "EXPIRED" 2013/04/02 10:21:23 [debug] 26682#0: 6181 uploadprogress error-tracker error: 0 2013/04/02 10:21:23 [debug] 26682#0: 6181 xslt filter header 2013/04/02 10:21:23 [debug] 26682#0: *6181 HTTP/1.1 200 OK Server: nginx Date: Tue, 02 Apr 2013 08:21:23 GMT Content-Type: text/html; charset=utf-8 Transfer-Encoding: chunked Connection: keep-alive Keep-Alive: timeout=5 Expires: Thu, 01 Jan 1970 00:00:01 GMT Last-Modified: Tue, 02 Apr 2013 08:21:22 +0000 Cache-Control: no-cache ETag: "1364890882" Content-Language: fr Link: http://172.19.65.71/; rel="canonical",http://172.19.65.71/; rel="shortlink" Content-Encoding: gzip Vary: Accept-Encoding X-Micro-Cache: EXPIRED

2013/04/02 10:21:23 [debug] 26682#0: 6181 write new buf t:1 f:0 0000000002394DA8, pos 0000000002394DA8, size: 499 file: 0, size: 0 2013/04/02 10:21:23 [debug] 26682#0: 6181 http write filter: l:0 f:0 s:499 2013/04/02 10:21:23 [debug] 26682#0: 6181 file cleanup: fd:30 2013/04/02 10:21:23 [debug] 26682#0: 6181 http file cache set header 2013/04/02 10:21:23 [debug] 26682#0: 6181 http cacheable: 1 2013/04/02 10:21:23 [debug] 26682#0: 6181 http upstream process upstream 2013/04/02 10:21:23 [debug] 26682#0: 6181 pipe read upstream: 1 2013/04/02 10:21:23 [debug] 26682#0: 6181 pipe preread: 3565 2013/04/02 10:21:23 [debug] 26682#0: 6181 input buf #0 00000000023724B3 2013/04/02 10:21:23 [debug] 26682#0: 6181 input buf 00000000023724B3 3565 2013/04/02 10:21:23 [debug] 26682#0: 6181 malloc: 00000000023732B0:4096 2013/04/02 10:21:23 [debug] 26682#0: 6181 readv: 1:4096 2013/04/02 10:21:23 [debug] 26682#0: 6181 pipe recv chain: 633 2013/04/02 10:21:23 [debug] 26682#0: 6181 readv: 1:3463 2013/04/02 10:21:23 [debug] 26682#0: 6181 pipe recv chain: 0 2013/04/02 10:21:23 [debug] 26682#0: 6181 pipe buf in s:1 t:1 f:0 00000000023722A0, pos 00000000023724B3, size: 3565 file: 0, size: 0 2013/04/02 10:21:23 [debug] 26682#0: 6181 pipe buf free s:0 t:1 f:0 00000000023732B0, pos 00000000023732B0, size: 633 file: 0, size: 0 2013/04/02 10:21:23 [debug] 26682#0: 6181 pipe length: -1 2013/04/02 10:21:23 [debug] 26682#0: 6181 input buf #1 00000000023732B0 2013/04/02 10:21:23 [debug] 26682#0: 6181 http fastcgi record byte: 01 2013/04/02 10:21:23 [debug] 26682#0: 6181 http fastcgi record byte: 03 2013/04/02 10:21:23 [debug] 26682#0: 6181 http fastcgi record byte: 00 2013/04/02 10:21:23 [debug] 26682#0: 6181 http fastcgi record byte: 01 2013/04/02 10:21:23 [debug] 26682#0: 6181 http fastcgi record byte: 00 2013/04/02 10:21:23 [debug] 26682#0: 6181 http fastcgi record byte: 08 2013/04/02 10:21:23 [debug] 26682#0: 6181 http fastcgi record byte: 00 2013/04/02 10:21:23 [debug] 26682#0: 6181 http fastcgi record byte: 00 2013/04/02 10:21:23 [debug] 26682#0: 6181 http fastcgi record length: 8 2013/04/02 10:21:23 [debug] 26682#0: 6181 http fastcgi sent end request 2013/04/02 10:21:23 [debug] 26682#0: 6181 input buf 00000000023732B0 610 2013/04/02 10:21:23 [debug] 26682#0: 6181 add cleanup: 0000000002395268 2013/04/02 10:21:23 [debug] 26682#0: 6181 hashed path: /var/lib/nginx/fastcgi/6/29/0000000296 2013/04/02 10:21:23 [debug] 26682#0: 6181 temp fd:30 2013/04/02 10:21:23 [debug] 26682#0: 6181 writev: 30, 4706 2013/04/02 10:21:23 [debug] 26682#0: 6181 pipe write downstream: 1 2013/04/02 10:21:23 [debug] 26682#0: 6181 pipe write downstream flush out 2013/04/02 10:21:23 [debug] 26682#0: 6181 http output filter "/?" 2013/04/02 10:21:23 [debug] 26682#0: 6181 http copy filter: "/?" 2013/04/02 10:21:23 [debug] 26682#0: 6181 posix_memalign: 00000000023742C0:4096 @16 2013/04/02 10:21:23 [debug] 26682#0: 6181 image filter 2013/04/02 10:21:23 [debug] 26682#0: 6181 xslt filter body 2013/04/02 10:21:23 [debug] 26682#0: 6181 http postpone filter "/?" 0000000002395298 2013/04/02 10:21:23 [debug] 26682#0: 6181 http chunk: 4175 2013/04/02 10:21:23 [debug] 26682#0: 6181 write old buf t:1 f:0 0000000002394DA8, pos 0000000002394DA8, size: 499 file: 0, size: 0 2013/04/02 10:21:23 [debug] 26682#0: 6181 write new buf t:1 f:0 00000000023743A0, pos 00000000023743A0, size: 6 file: 0, size: 0 2013/04/02 10:21:23 [debug] 26682#0: 6181 write new buf t:0 f:1 0000000000000000, pos 0000000000000000, size: 0 file: 531, size: 4175 2013/04/02 10:21:23 [debug] 26682#0: 6181 write new buf t:0 f:0 0000000000000000, pos 0000000000514F79, size: 2 file: 0, size: 0 2013/04/02 10:21:23 [debug] 26682#0: 6181 http write filter: l:0 f:0 s:4682 2013/04/02 10:21:23 [debug] 26682#0: 6181 http write filter limit 0 2013/04/02 10:21:23 [debug] 26682#0: 6181 tcp_nopush 2013/04/02 10:21:23 [debug] 26682#0: 6181 writev: 505 2013/04/02 10:21:23 [debug] 26682#0: 6181 sendfile: @531 4175 2013/04/02 10:21:23 [debug] 26682#0: 6181 sendfile: 4175, @531 4175:4175 2013/04/02 10:21:23 [debug] 26682#0: 6181 writev: 2 2013/04/02 10:21:23 [debug] 26682#0: 6181 http write filter 0000000000000000 2013/04/02 10:21:23 [debug] 26682#0: 6181 http copy filter: 0 "/?" 2013/04/02 10:21:23 [debug] 26682#0: 6181 pipe write downstream done 2013/04/02 10:21:23 [debug] 26682#0: 6181 event timer del: 31: 1364905282872 2013/04/02 10:21:23 [debug] 26682#0: 6181 event timer add: 31: 14400000:1364905283379 2013/04/02 10:21:23 [debug] 26682#0: 6181 http file cache update 2013/04/02 10:21:23 [debug] 26682#0: 6181 http file cache rename: "/var/lib/nginx/fastcgi/6/29/0000000296" to "/var/cache/nginx/microcache/3/dc/d3c9006473ee85c3d7e3f16c6a7d7dc3" 2013/04/02 10:21:23 [debug] 26682#0: 6181 http upstream exit: 0000000000000000 2013/04/02 10:21:23 [debug] 26682#0: 6181 finalize http upstream request: 0 2013/04/02 10:21:23 [debug] 26682#0: 6181 finalize http fastcgi request 2013/04/02 10:21:23 [debug] 26682#0: 6181 [upstream_fair] fp->current = 0, state = 0, pc->tries = 1, pc->data = 0000000002394300 2013/04/02 10:21:23 [debug] 26682#0: 6181 [upstream_fair] nreq for peer 0 @ 0000000002371AB0/00007FC0AD569050 now 0, total 0, delta -1 2013/04/02 10:21:23 [debug] 26682#0: 6181 close http upstream connection: 31 2013/04/02 10:21:23 [debug] 26682#0: 6181 free: 0000000002436330, unused: 48 2013/04/02 10:21:23 [debug] 26682#0: 6181 event timer del: 31: 1364905283379 2013/04/02 10:21:23 [debug] 26682#0: 6181 reusable connection: 0 2013/04/02 10:21:23 [debug] 26682#0: 6181 http upstream temp fd: 30 2013/04/02 10:21:23 [debug] 26682#0: 6181 http output filter "/?" 2013/04/02 10:21:23 [debug] 26682#0: 6181 http copy filter: "/?" 2013/04/02 10:21:23 [debug] 26682#0: 6181 image filter 2013/04/02 10:21:23 [debug] 26682#0: 6181 xslt filter body 2013/04/02 10:21:23 [debug] 26682#0: 6181 http postpone filter "/?" 00007FFF03EA3790 2013/04/02 10:21:23 [debug] 26682#0: 6181 http chunk: 0 2013/04/02 10:21:23 [debug] 26682#0: 6181 write new buf t:0 f:0 0000000000000000, pos 0000000000500EFA, size: 5 file: 0, size: 0 2013/04/02 10:21:23 [debug] 26682#0: 6181 http write filter: l:1 f:0 s:5 2013/04/02 10:21:23 [debug] 26682#0: 6181 http write filter limit 0 2013/04/02 10:21:23 [debug] 26682#0: 6181 writev: 5 2013/04/02 10:21:23 [debug] 26682#0: 6181 http write filter 0000000000000000 2013/04/02 10:21:23 [debug] 26682#0: 6181 http copy filter: 0 "/?" 2013/04/02 10:21:23 [debug] 26682#0: 6181 http finalize request: 0, "/?" a:1, c:1 2013/04/02 10:21:23 [debug] 26682#0: 6181 set http keepalive handler 2013/04/02 10:21:23 [debug] 26682#0: 6181 http close request 2013/04/02 10:21:23 [debug] 26682#0: 6181 http log handler 2013/04/02 10:21:23 [debug] 26682#0: 6181 http pinba handler 2013/04/02 10:21:23 [debug] 26682#0: 6181 run cleanup: 0000000002395268 2013/04/02 10:21:23 [debug] 26682#0: 6181 file cleanup: fd:30 2013/04/02 10:21:23 [debug] 26682#0: 6181 run cleanup: 0000000002393300 2013/04/02 10:21:23 [debug] 26682#0: 6181 run cleanup: 0000000002393280 2013/04/02 10:21:23 [debug] 26682#0: 6181 free: 00000000023732B0 2013/04/02 10:21:23 [debug] 26682#0: 6181 free: 00000000023722A0 2013/04/02 10:21:23 [debug] 26682#0: 6181 free: 0000000002392320, unused: 3 2013/04/02 10:21:23 [debug] 26682#0: 6181 free: 0000000002393330, unused: 0 2013/04/02 10:21:23 [debug] 26682#0: 6181 free: 0000000002394340, unused: 8 2013/04/02 10:21:23 [debug] 26682#0: 6181 free: 00000000023742C0, unused: 3354 2013/04/02 10:21:23 [debug] 26682#0: 6181 event timer add: 27: 5000:1364890888379 2013/04/02 10:21:23 [debug] 26682#0: 6181 free: 00000000022A4D20 2013/04/02 10:21:23 [debug] 26682#0: 6181 free: 00000000022A5250 2013/04/02 10:21:23 [debug] 26682#0: 6181 hc free: 0000000000000000 0 2013/04/02 10:21:23 [debug] 26682#0: 6181 hc busy: 0000000000000000 0 2013/04/02 10:21:23 [debug] 26682#0: 6181 reusable connection: 1 2013/04/02 10:21:23 [debug] 26682#0: 6181 post event 00007FC0A7418690 2013/04/02 10:21:23 [debug] 26682#0: 6181 delete posted event 00007FC0A7418690 2013/04/02 10:21:23 [debug] 26682#0: 6181 http keepalive handler 2013/04/02 10:21:23 [debug] 26682#0: 6181 malloc: 00000000022A4D20:1024 2013/04/02 10:21:23 [debug] 26682#0: 6181 recv: fd:27 -1 of 1024 2013/04/02 10:21:23 [debug] 26682#0: 6181 recv() not ready (11: Resource temporarily unavailable) 2013/04/02 10:21:23 [debug] 26682#0: 6181 free: 00000000022A4D20 2013/04/02 10:21:23 [debug] 26682#0: 6181 post event 00007FC0A7418690 2013/04/02 10:21:23 [debug] 26682#0: 6181 post event 00007FC0A7235690 2013/04/02 10:21:23 [debug] 26682#0: 6181 delete posted event 00007FC0A7235690 2013/04/02 10:21:23 [debug] 26682#0: 6181 http empty handler 2013/04/02 10:21:23 [debug] 26682#0: 6181 delete posted event 00007FC0A7418690 2013/04/02 10:21:23 [debug] 26682#0: 6181 http keepalive handler 2013/04/02 10:21:23 [debug] 26682#0: 6181 malloc: 00000000022A4D20:1024 2013/04/02 10:21:23 [debug] 26682#0: 6181 recv: fd:27 739 of 1024 2013/04/02 10:21:23 [debug] 26682#0: 6181 reusable connection: 0 2013/04/02 10:21:23 [debug] 26682#0: 6181 malloc: 00000000022A5130:1312 2013/04/02 10:21:23 [debug] 26682#0: 6181 event timer del: 27: 1364890888379 2013/04/02 10:21:23 [debug] 26682#0: 6181 generic phase: 0 2013/04/02 10:21:23 [debug] 26682#0: 6181 rewrite phase: 1 2013/04/02 10:21:23 [debug] 26682#0: 6181 http script var 2013/04/02 10:21:23 [debug] 26682#0: 6181 http map started 2013/04/02 10:21:23 [debug] 26682#0: 6181 http script var: "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.22 (KHTML, like Gecko) Ubuntu Chromium/25.0.1364.160 Chrome/25.0.1364.160 Safari/537.22" 2013/04/02 10:21:23 [debug] 26682#0: 6181 http map: "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.22 (KHTML, like Gecko) Ubuntu Chromium/25.0.1364.160 Chrome/25.0.1364.160 Safari/537.22" "0" 2013/04/02 10:21:23 [debug] 26682#0: 6181 http script var: "0" 2013/04/02 10:21:23 [debug] 26682#0: 6181 http script if 2013/04/02 10:21:23 [debug] 26682#0: 6181 http script if: false 2013/04/02 10:21:23 [debug] 26682#0: 6181 http script var 2013/04/02 10:21:23 [debug] 26682#0: 6181 http geo started: 172.19.32.67 2013/04/02 10:21:23 [debug] 26682#0: 6181 http geo: 2013/04/02 10:21:23 [debug] 26682#0: 6181 http script var: "" 2013/04/02 10:21:23 [debug] 26682#0: 6181 http script if 2013/04/02 10:21:23 [debug] 26682#0: 6181 http script if: false 2013/04/02 10:21:23 [debug] 26682#0: 6181 http script var 2013/04/02 10:21:23 [debug] 26682#0: 6181 http map started 2013/04/02 10:21:23 [debug] 26682#0: 6181 http script var: "GET" 2013/04/02 10:21:23 [debug] 26682#0: 6181 http map: "GET" "0" 2013/04/02 10:21:23 [debug] 26682#0: 6181 http script var: "0" 2013/04/02 10:21:23 [debug] 26682#0: 6181 http script if 2013/04/02 10:21:23 [debug] 26682#0: 6181 http script if: false 2013/04/02 10:21:23 [debug] 26682#0: 6181 test location: "/" 2013/04/02 10:21:23 [debug] 26682#0: 6181 test location: "patches" 2013/04/02 10:21:23 [debug] 26682#0: 6181 test location: "fpm-status" 2013/04/02 10:21:23 [debug] 26682#0: 6181 test location: "fpm-status-zwei" 2013/04/02 10:21:23 [debug] 26682#0: 6181 test location: "nginx_status" 2013/04/02 10:21:23 [debug] 26682#0: 6181 test location: "/sites/172.19.65.71/files/audio/ogg" 2013/04/02 10:21:23 [debug] 26682#0: 6181 test location: "/sites/172.19.65.71/files/advagg_js/" 2013/04/02 10:21:23 [debug] 26682#0: 6181 test location: "/sites/172.19.65.71/files/advagg_css/" 2013/04/02 10:21:23 [debug] 26682#0: 6181 test location: "/help/" 2013/04/02 10:21:23 [debug] 26682#0: 6181 test location: ~ "/imagecache/" 2013/04/02 10:21:23 [debug] 26682#0: 6181 test location: ~ "/files/styles/" 2013/04/02 10:21:23 [debug] 26682#0: 6181 test location: ~ "^.+.(?:css|cur|js|jpg|jpeg|gif|ico|png|html|xml)$" 2013/04/02 10:21:23 [debug] 26682#0: 6181 using configuration "^.+.(?:css|cur|js|jpg|jpeg|gif|ico|png|html|xml)$" 2013/04/02 10:21:23 [debug] 26682#0: 6181 http cl:-1 max:10485760 2013/04/02 10:21:23 [debug] 26682#0: 6181 rewrite phase: 3 2013/04/02 10:21:23 [debug] 26682#0: 6181 rewrite phase: 4 2013/04/02 10:21:23 [debug] 26682#0: 6181 post rewrite phase: 5 2013/04/02 10:21:23 [debug] 26682#0: 6181 generic phase: 6 2013/04/02 10:21:23 [debug] 26682#0: 6181 generic phase: 7 2013/04/02 10:21:23 [debug] 26682#0: 6181 generic phase: 8 2013/04/02 10:21:23 [debug] 26682#0: 6181 limit conn: 42C85000 1 2013/04/02 10:21:23 [debug] 26682#0: 6181 add cleanup: 00000000023731F0 2013/04/02 10:21:23 [debug] 26682#0: 6181 access phase: 9 2013/04/02 10:21:23 [debug] 26682#0: 6181 access phase: 10 2013/04/02 10:21:23 [debug] 26682#0: 6181 access phase: 11 2013/04/02 10:21:23 [debug] 26682#0: 6181 access phase: 12 2013/04/02 10:21:23 [debug] 26682#0: 6181 post access phase: 13 2013/04/02 10:21:23 [debug] 26682#0: 6181 try files phase: 14 2013/04/02 10:21:23 [debug] 26682#0: 6181 content phase: 15 2013/04/02 10:21:23 [debug] 26682#0: 6181 content phase: 16 2013/04/02 10:21:23 [debug] 26682#0: 6181 content phase: 17 2013/04/02 10:21:23 [debug] 26682#0: 6181 content phase: 18 2013/04/02 10:21:23 [debug] 26682#0: 6181 content phase: 19 2013/04/02 10:21:23 [debug] 26682#0: 6181 content phase: 20 2013/04/02 10:21:23 [debug] 26682#0: 6181 content phase: 21 2013/04/02 10:21:23 [debug] 26682#0: 6181 http filename: "/var/www/drupalair/modules/system/system.base.css" 2013/04/02 10:21:23 [debug] 26682#0: 6181 add cleanup: 0000000002373250 2013/04/02 10:21:23 [debug] 26682#0: 6181 http static fd: 30 2013/04/02 10:21:23 [debug] 26682#0: 6181 http set discard body 2013/04/02 10:21:23 [debug] 26682#0: 6181 posix_memalign: 00000000023732B0:4096 @16 2013/04/02 10:21:23 [debug] 26682#0: 6181 http ims:1364391700 lm:1364391700 2013/04/02 10:21:23 [debug] 26682#0: 6181 uploadprogress error-tracker error: 0 2013/04/02 10:21:23 [debug] 26682#0: 6181 xslt filter header 2013/04/02 10:21:23 [debug] 26682#0: 6181 HTTP/1.1 304 Not Modified Server: nginx Date: Tue, 02 Apr 2013 08:21:23 GMT Last-Modified: Wed, 27 Mar 2013 13:41:40 GMT Connection: keep-alive Keep-Alive: timeout=5 Expires: Thu, 02 May 2013 08:21:23 GMT Cache-Control: max-age=2592000 X-Frame-Options: SAMEORIGIN

2013/04/02 10:21:23 [debug] 26682#0: 6181 write new buf t:1 f:0 0000000002373480, pos 0000000002373480, size: 275 file: 0, size: 0 2013/04/02 10:21:23 [debug] 26682#0: 6181 http write filter: l:1 f:0 s:275 2013/04/02 10:21:23 [debug] 26682#0: 6181 http write filter limit 0 2013/04/02 10:21:23 [debug] 26682#0: 6181 writev: 275 2013/04/02 10:21:23 [debug] 26682#0: 6181 http write filter 0000000000000000 2013/04/02 10:21:23 [debug] 26682#0: 6181 http finalize request: 0, "/modules/system/system.base.css?mkmbil" a:1, c:1 2013/04/02 10:21:23 [debug] 26682#0: 6181 set http keepalive handler 2013/04/02 10:21:23 [debug] 26682#0: 6181 http close request 2013/04/02 10:21:23 [debug] 26682#0: 6181 http log handler 2013/04/02 10:21:23 [debug] 26682#0: 6181 http pinba handler 2013/04/02 10:21:23 [debug] 26682#0: 6181 run cleanup: 0000000002373250 2013/04/02 10:21:23 [debug] 26682#0: 6181 file cleanup: fd:30 2013/04/02 10:21:23 [debug] 26682#0: 6181 run cleanup: 00000000023731F0 2013/04/02 10:21:23 [debug] 26682#0: 6181 free: 00000000023722A0, unused: 8 2013/04/02 10:21:23 [debug] 26682#0: 6181 free: 00000000023732B0, unused: 3338 2013/04/02 10:21:23 [debug] 26682#0: 6181 event timer add: 27: 5000:1364890888468 2013/04/02 10:21:23 [debug] 26682#0: 6181 free: 00000000022A5130 2013/04/02 10:21:23 [debug] 26682#0: 6181 free: 00000000022A4D20 2013/04/02 10:21:23 [debug] 26682#0: 6181 hc free: 0000000000000000 0 2013/04/02 10:21:23 [debug] 26682#0: 6181 hc busy: 0000000000000000 0 2013/04/02 10:21:23 [debug] 26682#0: 6181 reusable connection: 1 2013/04/02 10:21:23 [debug] 26682#0: 6181 post event 00007FC0A7418690 2013/04/02 10:21:23 [debug] 26682#0: 6181 delete posted event 00007FC0A7418690 2013/04/02 10:21:23 [debug] 26682#0: 6181 http keepalive handler 2013/04/02 10:21:23 [debug] 26682#0: 6181 malloc: 00000000022A4D20:1024 2013/04/02 10:21:23 [debug] 26682#0: 6181 recv: fd:27 -1 of 1024 2013/04/02 10:21:23 [debug] 26682#0: 6181 recv() not ready (11: Resource temporarily unavailable) 2013/04/02 10:21:23 [debug] 26682#0: 6181 free: 00000000022A4D20 2013/04/02 10:21:23 [debug] 26682#0: 6182 event timer del: 28: 1364890912868 2013/04/02 10:21:23 [debug] 26682#0: 6182 generic phase: 0 2013/04/02 10:21:23 [debug] 26682#0: 6182 rewrite phase: 1 2013/04/02 10:21:23 [debug] 26682#0: 6182 http script var 2013/04/02 10:21:23 [debug] 26682#0: 6182 http map started 2013/04/02 10:21:23 [debug] 26682#0: 6182 http script var: "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.22 (KHTML, like Gecko) Ubuntu Chromium/25.0.1364.160 Chrome/25.0.1364.160 Safari/537.22" 2013/04/02 10:21:23 [debug] 26682#0: 6182 http map: "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.22 (KHTML, like Gecko) Ubuntu Chromium/25.0.1364.160 Chrome/25.0.1364.160 Safari/537.22" "0" 2013/04/02 10:21:23 [debug] 26682#0: 6182 http script var: "0" 2013/04/02 10:21:23 [debug] 26682#0: 6182 http script if 2013/04/02 10:21:23 [debug] 26682#0: 6182 http script if: false 2013/04/02 10:21:23 [debug] 26682#0: 6182 http script var 2013/04/02 10:21:23 [debug] 26682#0: 6182 http geo started: 172.19.32.67 2013/04/02 10:21:23 [debug] 26682#0: 6182 http geo: 2013/04/02 10:21:23 [debug] 26682#0: 6182 http script var: "" 2013/04/02 10:21:23 [debug] 26682#0: 6182 http script if 2013/04/02 10:21:23 [debug] 26682#0: 6182 http script if: false 2013/04/02 10:21:23 [debug] 26682#0: 6182 http script var 2013/04/02 10:21:23 [debug] 26682#0: 6182 http map started 2013/04/02 10:21:23 [debug] 26682#0: 6182 http script var: "GET" 2013/04/02 10:21:23 [debug] 26682#0: 6182 http map: "GET" "0" 2013/04/02 10:21:23 [debug] 26682#0: 6182 http script var: "0" 2013/04/02 10:21:23 [debug] 26682#0: 6182 http script if 2013/04/02 10:21:23 [debug] 26682#0: 6182 http script if: false 2013/04/02 10:21:23 [debug] 26682#0: 6182 test location: "/" 2013/04/02 10:21:23 [debug] 26682#0: 6182 test location: "patches" 2013/04/02 10:21:23 [debug] 26682#0: 6182 test location: "fpm-status" 2013/04/02 10:21:23 [debug] 26682#0: 6182 test location: "fpm-status-zwei" 2013/04/02 10:21:23 [debug] 26682#0: 6182 test location: "nginx_status" 2013/04/02 10:21:23 [debug] 26682#0: 6182 test location: "/sites/172.19.65.71/files/audio/ogg" 2013/04/02 10:21:23 [debug] 26682#0: 6182 test location: "/sites/172.19.65.71/files/advagg_js/" 2013/04/02 10:21:23 [debug] 26682#0: 6182 test location: "/sites/172.19.65.71/files/advagg_css/" 2013/04/02 10:21:23 [debug] 26682#0: 6182 test location: "/help/" 2013/04/02 10:21:23 [debug] 26682#0: 6182 test location: ~ "/imagecache/" 2013/04/02 10:21:23 [debug] 26682#0: 6182 test location: ~ "/files/styles/" 2013/04/02 10:21:23 [debug] 26682#0: 6182 test location: ~ "^.+.(?:css|cur|js|jpg|jpeg|gif|ico|png|html|xml)$" 2013/04/02 10:21:23 [debug] 26682#0: 6182 using configuration "^.+.(?:css|cur|js|jpg|jpeg|gif|ico|png|html|xml)$" 2013/04/02 10:21:23 [debug] 26682#0: 6182 http cl:-1 max:10485760 2013/04/02 10:21:23 [debug] 26682#0: 6182 rewrite phase: 3 2013/04/02 10:21:23 [debug] 26682#0: 6182 rewrite phase: 4 2013/04/02 10:21:23 [debug] 26682#0: 6182 post rewrite phase: 5 2013/04/02 10:21:23 [debug] 26682#0: 6182 generic phase: 6 2013/04/02 10:21:23 [debug] 26682#0: 6182 generic phase: 7 2013/04/02 10:21:23 [debug] 26682#0: 6182 generic phase: 8 2013/04/02 10:21:23 [debug] 26682#0: 6182 limit conn: 42C85000 1 2013/04/02 10:21:23 [debug] 26682#0: 6182 add cleanup: 00000000023731F0 2013/04/02 10:21:23 [debug] 26682#0: 6182 access phase: 9 2013/04/02 10:21:23 [debug] 26682#0: 6182 access phase: 10 2013/04/02 10:21:23 [debug] 26682#0: 6182 access phase: 11 2013/04/02 10:21:23 [debug] 26682#0: 6182 access phase: 12 2013/04/02 10:21:23 [debug] 26682#0: 6182 post access phase: 13 2013/04/02 10:21:23 [debug] 26682#0: 6182 try files phase: 14 2013/04/02 10:21:23 [debug] 26682#0: 6182 content phase: 15 2013/04/02 10:21:23 [debug] 26682#0: 6182 content phase: 16 2013/04/02 10:21:23 [debug] 26682#0: 6182 content phase: 17 2013/04/02 10:21:23 [debug] 26682#0: 6182 content phase: 18 2013/04/02 10:21:23 [debug] 26682#0: 6182 content phase: 19 2013/04/02 10:21:23 [debug] 26682#0: 6182 content phase: 20 2013/04/02 10:21:23 [debug] 26682#0: 6182 content phase: 21 2013/04/02 10:21:23 [debug] 26682#0: 6182 http filename: "/var/www/drupalair/modules/system/system.messages.css" 2013/04/02 10:21:23 [debug] 26682#0: 6182 add cleanup: 0000000002373250 2013/04/02 10:21:23 [debug] 26682#0: 6182 http static fd: 30 2013/04/02 10:21:23 [debug] 26682#0: 6182 http set discard body 2013/04/02 10:21:23 [debug] 26682#0: 6182 posix_memalign: 00000000023732B0:4096 @16 2013/04/02 10:21:23 [debug] 26682#0: 6182 http ims:1364391700 lm:1364391700 2013/04/02 10:21:23 [debug] 26682#0: 6182 uploadprogress error-tracker error: 0 2013/04/02 10:21:23 [debug] 26682#0: 6182 xslt filter header 2013/04/02 10:21:23 [debug] 26682#0: *6182 HTTP/1.1 304 Not Modified Server: nginx Date: Tue, 02 Apr 2013 08:21:23 GMT Last-Modified: Wed, 27 Mar 2013 13:41:40 GMT Connection: keep-alive Keep-Alive: timeout=5 Expires: Thu, 02 May 2013 08:21:23 GMT Cache-Control: max-age=2592000 X-Frame-Options: SAMEORIGIN

2013/04/02 10:21:23 [debug] 26682#0: 6182 write new buf t:1 f:0 0000000002373480, pos 0000000002373480, size: 275 file: 0, size: 0 2013/04/02 10:21:23 [debug] 26682#0: 6182 http write filter: l:1 f:0 s:275 2013/04/02 10:21:23 [debug] 26682#0: 6182 http write filter limit 0 2013/04/02 10:21:23 [debug] 26682#0: 6182 writev: 275 2013/04/02 10:21:23 [debug] 26682#0: 6182 http write filter 0000000000000000 2013/04/02 10:21:23 [debug] 26682#0: 6182 http finalize request: 0, "/modules/system/system.messages.css?mkmbil" a:1, c:1 2013/04/02 10:21:23 [debug] 26682#0: 6182 set http keepalive handler 2013/04/02 10:21:23 [debug] 26682#0: 6182 http close request 2013/04/02 10:21:23 [debug] 26682#0: 6182 http log handler 2013/04/02 10:21:23 [debug] 26682#0: 6182 http pinba handler 2013/04/02 10:21:23 [debug] 26682#0: 6182 run cleanup: 0000000002373250 2013/04/02 10:21:23 [debug] 26682#0: 6182 file cleanup: fd:30 2013/04/02 10:21:23 [debug] 26682#0: 6182 run cleanup: 00000000023731F0 2013/04/02 10:21:23 [debug] 26682#0: 6182 free: 00000000023722A0, unused: 8 2013/04/02 10:21:23 [debug] 26682#0: 6182 free: 00000000023732B0, unused: 3338 2013/04/02 10:21:23 [debug] 26682#0: 6182 event timer add: 28: 5000:1364890888468 2013/04/02 10:21:23 [debug] 26682#0: 6182 free: 00000000022A4D20 2013/04/02 10:21:23 [debug] 26682#0: 6182 free: 00000000022A5250 2013/04/02 10:21:23 [debug] 26682#0: 6182 hc free: 0000000000000000 0 2013/04/02 10:21:23 [debug] 26682#0: 6182 hc busy: 0000000000000000 0 2013/04/02 10:21:23 [debug] 26682#0: 6182 reusable connection: 1 2013/04/02 10:21:23 [debug] 26682#0: 6182 post event 00007FC0A7418898 2013/04/02 10:21:23 [debug] 26682#0: 6182 delete posted event 00007FC0A7418898 2013/04/02 10:21:23 [debug] 26682#0: 6182 http keepalive handler 2013/04/02 10:21:23 [debug] 26682#0: 6182 malloc: 00000000022A4D20:1024 2013/04/02 10:21:23 [debug] 26682#0: 6182 recv: fd:28 -1 of 1024 2013/04/02 10:21:23 [debug] 26682#0: 6182 recv() not ready (11: Resource temporarily unavailable) 2013/04/02 10:21:23 [debug] 26682#0: 6182 free: 00000000022A4D20 2013/04/02 10:21:23 [debug] 26682#0: 6183 event timer del: 29: 1364890912868 2013/04/02 10:21:23 [debug] 26682#0: 6183 generic phase: 0 2013/04/02 10:21:23 [debug] 26682#0: 6183 rewrite phase: 1 2013/04/02 10:21:23 [debug] 26682#0: 6183 http script var 2013/04/02 10:21:23 [debug] 26682#0: 6183 http map started 2013/04/02 10:21:23 [debug] 26682#0: 6183 http script var: "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.22 (KHTML, like Gecko) Ubuntu Chromium/25.0.1364.160 Chrome/25.0.1364.160 Safari/537.22" 2013/04/02 10:21:23 [debug] 26682#0: 6183 http map: "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.22 (KHTML, like Gecko) Ubuntu Chromium/25.0.1364.160 Chrome/25.0.1364.160 Safari/537.22" "0" 2013/04/02 10:21:23 [debug] 26682#0: 6183 http script var: "0" 2013/04/02 10:21:23 [debug] 26682#0: 6183 http script if 2013/04/02 10:21:23 [debug] 26682#0: 6183 http script if: false 2013/04/02 10:21:23 [debug] 26682#0: 6183 http script var 2013/04/02 10:21:23 [debug] 26682#0: 6183 http geo started: 172.19.32.67 2013/04/02 10:21:23 [debug] 26682#0: 6183 http geo: 2013/04/02 10:21:23 [debug] 26682#0: 6183 http script var: "" 2013/04/02 10:21:23 [debug] 26682#0: 6183 http script if 2013/04/02 10:21:23 [debug] 26682#0: 6183 http script if: false 2013/04/02 10:21:23 [debug] 26682#0: 6183 http script var 2013/04/02 10:21:23 [debug] 26682#0: 6183 http map started 2013/04/02 10:21:23 [debug] 26682#0: 6183 http script var: "GET" 2013/04/02 10:21:23 [debug] 26682#0: 6183 http map: "GET" "0" 2013/04/02 10:21:23 [debug] 26682#0: 6183 http script var: "0" 2013/04/02 10:21:23 [debug] 26682#0: 6183 http script if 2013/04/02 10:21:23 [debug] 26682#0: 6183 http script if: false 2013/04/02 10:21:23 [debug] 26682#0: 6183 test location: "/" 2013/04/02 10:21:23 [debug] 26682#0: 6183 test location: "patches" 2013/04/02 10:21:23 [debug] 26682#0: 6183 test location: "fpm-status" 2013/04/02 10:21:23 [debug] 26682#0: 6183 test location: "fpm-status-zwei" 2013/04/02 10:21:23 [debug] 26682#0: 6183 test location: "nginx_status" 2013/04/02 10:21:23 [debug] 26682#0: 6183 test location: "/sites/172.19.65.71/files/audio/ogg" 2013/04/02 10:21:23 [debug] 26682#0: 6183 test location: "/sites/172.19.65.71/files/advagg_js/" 2013/04/02 10:21:23 [debug] 26682#0: 6183 test location: "/sites/172.19.65.71/files/advagg_css/" 2013/04/02 10:21:23 [debug] 26682#0: 6183 test location: "/help/" 2013/04/02 10:21:23 [debug] 26682#0: 6183 test location: ~ "/imagecache/" 2013/04/02 10:21:23 [debug] 26682#0: 6183 test location: ~ "/files/styles/" 2013/04/02 10:21:23 [debug] 26682#0: 6183 test location: ~ "^.+.(?:css|cur|js|jpg|jpeg|gif|ico|png|html|xml)$" 2013/04/02 10:21:23 [debug] 26682#0: 6183 using configuration "^.+.(?:css|cur|js|jpg|jpeg|gif|ico|png|html|xml)$" 2013/04/02 10:21:23 [debug] 26682#0: 6183 http cl:-1 max:10485760 2013/04/02 10:21:23 [debug] 26682#0: 6183 rewrite phase: 3 2013/04/02 10:21:23 [debug] 26682#0: 6183 rewrite phase: 4 2013/04/02 10:21:23 [debug] 26682#0: 6183 post rewrite phase: 5 2013/04/02 10:21:23 [debug] 26682#0: 6183 generic phase: 6 2013/04/02 10:21:23 [debug] 26682#0: 6183 generic phase: 7 2013/04/02 10:21:23 [debug] 26682#0: 6183 generic phase: 8 2013/04/02 10:21:23 [debug] 26682#0: 6183 limit conn: 42C85000 1 2013/04/02 10:21:23 [debug] 26682#0: 6183 add cleanup: 00000000023731F0 2013/04/02 10:21:23 [debug] 26682#0: 6183 access phase: 9 2013/04/02 10:21:23 [debug] 26682#0: 6183 access phase: 10 2013/04/02 10:21:23 [debug] 26682#0: 6183 access phase: 11 2013/04/02 10:21:23 [debug] 26682#0: 6183 access phase: 12 2013/04/02 10:21:23 [debug] 26682#0: 6183 post access phase: 13 2013/04/02 10:21:23 [debug] 26682#0: 6183 try files phase: 14 2013/04/02 10:21:23 [debug] 26682#0: 6183 content phase: 15 2013/04/02 10:21:23 [debug] 26682#0: 6183 content phase: 16 2013/04/02 10:21:23 [debug] 26682#0: 6183 content phase: 17 2013/04/02 10:21:23 [debug] 26682#0: 6183 content phase: 18 2013/04/02 10:21:23 [debug] 26682#0: 6183 content phase: 19 2013/04/02 10:21:23 [debug] 26682#0: 6183 content phase: 20 2013/04/02 10:21:23 [debug] 26682#0: 6183 content phase: 21 2013/04/02 10:21:23 [debug] 26682#0: 6183 http filename: "/var/www/drupalair/modules/system/system.theme.css" 2013/04/02 10:21:23 [debug] 26682#0: 6183 add cleanup: 0000000002373250 2013/04/02 10:21:23 [debug] 26682#0: 6183 http static fd: 30 2013/04/02 10:21:23 [debug] 26682#0: 6183 http set discard body 2013/04/02 10:21:23 [debug] 26682#0: 6183 posix_memalign: 00000000023732B0:4096 @16 2013/04/02 10:21:23 [debug] 26682#0: 6183 http ims:1364391700 lm:1364391700 2013/04/02 10:21:23 [debug] 26682#0: 6183 uploadprogress error-tracker error: 0 2013/04/02 10:21:23 [debug] 26682#0: 6183 xslt filter header 2013/04/02 10:21:23 [debug] 26682#0: *6183 HTTP/1.1 304 Not Modified Server: nginx Date: Tue, 02 Apr 2013 08:21:23 GMT Last-Modified: Wed, 27 Mar 2013 13:41:40 GMT Connection: keep-alive Keep-Alive: timeout=5 Expires: Thu, 02 May 2013 08:21:23 GMT Cache-Control: max-age=2592000 X-Frame-Options: SAMEORIGIN

2013/04/02 10:21:23 [debug] 26682#0: 6183 write new buf t:1 f:0 0000000002373480, pos 0000000002373480, size: 275 file: 0, size: 0 2013/04/02 10:21:23 [debug] 26682#0: 6183 http write filter: l:1 f:0 s:275 2013/04/02 10:21:23 [debug] 26682#0: 6183 http write filter limit 0 2013/04/02 10:21:23 [debug] 26682#0: 6183 writev: 275 2013/04/02 10:21:23 [debug] 26682#0: 6183 http write filter 0000000000000000 2013/04/02 10:21:23 [debug] 26682#0: 6183 http finalize request: 0, "/modules/system/system.theme.css?mkmbil" a:1, c:1 2013/04/02 10:21:23 [debug] 26682#0: 6183 set http keepalive handler 2013/04/02 10:21:23 [debug] 26682#0: 6183 http close request 2013/04/02 10:21:23 [debug] 26682#0: 6183 http log handler 2013/04/02 10:21:23 [debug] 26682#0: 6183 http pinba handler 2013/04/02 10:21:23 [debug] 26682#0: 6183 run cleanup: 0000000002373250 2013/04/02 10:21:23 [debug] 26682#0: 6183 file cleanup: fd:30 2013/04/02 10:21:23 [debug] 26682#0: 6183 run cleanup: 00000000023731F0 2013/04/02 10:21:23 [debug] 26682#0: 6183 free: 00000000023722A0, unused: 8 2013/04/02 10:21:23 [debug] 26682#0: 6183 free: 00000000023732B0, unused: 3338 2013/04/02 10:21:23 [debug] 26682#0: 6183 event timer add: 29: 5000:1364890888468 2013/04/02 10:21:23 [debug] 26682#0: 6183 free: 00000000022A4D20 2013/04/02 10:21:23 [debug] 26682#0: 6183 free: 00000000022A5250 2013/04/02 10:21:23 [debug] 26682#0: 6183 hc free: 0000000000000000 0 2013/04/02 10:21:23 [debug] 26682#0: 6183 hc busy: 0000000000000000 0 2013/04/02 10:21:23 [debug] 26682#0: 6183 reusable connection: 1 2013/04/02 10:21:23 [debug] 26682#0: 6183 post event 00007FC0A74186F8 2013/04/02 10:21:23 [debug] 26682#0: 6183 delete posted event 00007FC0A74186F8 2013/04/02 10:21:23 [debug] 26682#0: 6183 http keepalive handler 2013/04/02 10:21:23 [debug] 26682#0: 6183 malloc: 00000000022A4D20:1024 2013/04/02 10:21:23 [debug] 26682#0: 6183 recv: fd:29 -1 of 1024 2013/04/02 10:21:23 [debug] 26682#0: 6183 recv() not ready (11: Resource temporarily unavailable) 2013/04/02 10:21:23 [debug] 26682#0: 6183 free: 00000000022A4D20 2013/04/02 10:21:23 [debug] 26682#0: 6185 event timer del: 30: 1364890913492 2013/04/02 10:21:23 [debug] 26682#0: 6185 generic phase: 0 2013/04/02 10:21:23 [debug] 26682#0: 6185 rewrite phase: 1 2013/04/02 10:21:23 [debug] 26682#0: 6185 http script var 2013/04/02 10:21:23 [debug] 26682#0: 6185 http map started 2013/04/02 10:21:23 [debug] 26682#0: 6185 http script var: "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.22 (KHTML, like Gecko) Ubuntu Chromium/25.0.1364.160 Chrome/25.0.1364.160 Safari/537.22" 2013/04/02 10:21:23 [debug] 26682#0: 6185 http map: "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.22 (KHTML, like Gecko) Ubuntu Chromium/25.0.1364.160 Chrome/25.0.1364.160 Safari/537.22" "0" 2013/04/02 10:21:23 [debug] 26682#0: 6185 http script var: "0" 2013/04/02 10:21:23 [debug] 26682#0: 6185 http script if 2013/04/02 10:21:23 [debug] 26682#0: 6185 http script if: false 2013/04/02 10:21:23 [debug] 26682#0: 6185 http script var 2013/04/02 10:21:23 [debug] 26682#0: 6185 http geo started: 172.19.32.67 2013/04/02 10:21:23 [debug] 26682#0: 6185 http geo: 2013/04/02 10:21:23 [debug] 26682#0: 6185 http script var: "" 2013/04/02 10:21:23 [debug] 26682#0: 6185 http script if 2013/04/02 10:21:23 [debug] 26682#0: 6185 http script if: false 2013/04/02 10:21:23 [debug] 26682#0: 6185 http script var 2013/04/02 10:21:23 [debug] 26682#0: 6185 http map started 2013/04/02 10:21:23 [debug] 26682#0: 6185 http script var: "GET" 2013/04/02 10:21:23 [debug] 26682#0: 6185 http map: "GET" "0" 2013/04/02 10:21:23 [debug] 26682#0: 6185 http script var: "0" 2013/04/02 10:21:23 [debug] 26682#0: 6185 http script if 2013/04/02 10:21:23 [debug] 26682#0: 6185 http script if: false 2013/04/02 10:21:23 [debug] 26682#0: 6185 test location: "/" 2013/04/02 10:21:23 [debug] 26682#0: 6185 test location: "patches" 2013/04/02 10:21:23 [debug] 26682#0: 6185 test location: "fpm-status" 2013/04/02 10:21:23 [debug] 26682#0: 6185 test location: "fpm-status-zwei" 2013/04/02 10:21:23 [debug] 26682#0: 6185 test location: "nginx_status" 2013/04/02 10:21:23 [debug] 26682#0: 6185 test location: "/sites/172.19.65.71/files/audio/ogg" 2013/04/02 10:21:23 [debug] 26682#0: 6185 test location: "/sites/172.19.65.71/files/advagg_js/" 2013/04/02 10:21:23 [debug] 26682#0: 6185 test location: "/sites/172.19.65.71/files/advagg_css/" 2013/04/02 10:21:23 [debug] 26682#0: 6185 test location: "/help/" 2013/04/02 10:21:23 [debug] 26682#0: 6185 test location: ~ "/imagecache/" 2013/04/02 10:21:23 [debug] 26682#0: 6185 test location: ~ "/files/styles/" 2013/04/02 10:21:23 [debug] 26682#0: 6185 test location: ~ "^.+.(?:css|cur|js|jpg|jpeg|gif|ico|png|html|xml)$" 2013/04/02 10:21:23 [debug] 26682#0: 6185 using configuration "^.+.(?:css|cur|js|jpg|jpeg|gif|ico|png|html|xml)$" 2013/04/02 10:21:23 [debug] 26682#0: 6185 http cl:-1 max:10485760 2013/04/02 10:21:23 [debug] 26682#0: 6185 rewrite phase: 3 2013/04/02 10:21:23 [debug] 26682#0: 6185 rewrite phase: 4 2013/04/02 10:21:23 [debug] 26682#0: 6185 post rewrite phase: 5 2013/04/02 10:21:23 [debug] 26682#0: 6185 generic phase: 6 2013/04/02 10:21:23 [debug] 26682#0: 6185 generic phase: 7 2013/04/02 10:21:23 [debug] 26682#0: 6185 generic phase: 8 2013/04/02 10:21:23 [debug] 26682#0: 6185 limit conn: 42C85000 1 2013/04/02 10:21:23 [debug] 26682#0: 6185 add cleanup: 00000000023731F0 2013/04/02 10:21:23 [debug] 26682#0: 6185 access phase: 9 2013/04/02 10:21:23 [debug] 26682#0: 6185 access phase: 10 2013/04/02 10:21:23 [debug] 26682#0: 6185 access phase: 11 2013/04/02 10:21:23 [debug] 26682#0: 6185 access phase: 12 2013/04/02 10:21:23 [debug] 26682#0: 6185 post access phase: 13 2013/04/02 10:21:23 [debug] 26682#0: 6185 try files phase: 14 2013/04/02 10:21:23 [debug] 26682#0: 6185 content phase: 15 2013/04/02 10:21:23 [debug] 26682#0: 6185 content phase: 16 2013/04/02 10:21:23 [debug] 26682#0: 6185 content phase: 17 2013/04/02 10:21:23 [debug] 26682#0: 6185 content phase: 18 2013/04/02 10:21:23 [debug] 26682#0: 6185 content phase: 19 2013/04/02 10:21:23 [debug] 26682#0: 6185 content phase: 20 2013/04/02 10:21:23 [debug] 26682#0: 6185 content phase: 21 2013/04/02 10:21:23 [debug] 26682#0: 6185 http filename: "/var/www/drupalair/modules/comment/comment.css" 2013/04/02 10:21:23 [debug] 26682#0: 6185 add cleanup: 0000000002373248 2013/04/02 10:21:23 [debug] 26682#0: 6185 http static fd: 32 2013/04/02 10:21:23 [debug] 26682#0: 6185 http set discard body 2013/04/02 10:21:23 [debug] 26682#0: 6185 posix_memalign: 00000000023732B0:4096 @16 2013/04/02 10:21:23 [debug] 26682#0: 6185 http ims:1364391700 lm:1364391700 2013/04/02 10:21:23 [debug] 26682#0: 6185 uploadprogress error-tracker error: 0 2013/04/02 10:21:23 [debug] 26682#0: 6185 xslt filter header 2013/04/02 10:21:23 [debug] 26682#0: *6185 HTTP/1.1 304 Not Modified Server: nginx Date: Tue, 02 Apr 2013 08:21:23 GMT Last-Modified: Wed, 27 Mar 2013 13:41:40 GMT Connection: keep-alive Keep-Alive: timeout=5 Expires: Thu, 02 May 2013 08:21:23 GMT Cache-Control: max-age=2592000 X-Frame-Options: SAMEORIGIN

2013/04/02 10:21:23 [debug] 26682#0: 6185 write new buf t:1 f:0 0000000002373460, pos 0000000002373460, size: 275 file: 0, size: 0 2013/04/02 10:21:23 [debug] 26682#0: 6185 http write filter: l:1 f:0 s:275 2013/04/02 10:21:23 [debug] 26682#0: 6185 http write filter limit 0 2013/04/02 10:21:23 [debug] 26682#0: 6185 writev: 275 2013/04/02 10:21:23 [debug] 26682#0: 6185 http write filter 0000000000000000 2013/04/02 10:21:23 [debug] 26682#0: 6185 http finalize request: 0, "/modules/comment/comment.css?mkmbil" a:1, c:1 2013/04/02 10:21:23 [debug] 26682#0: 6185 set http keepalive handler 2013/04/02 10:21:23 [debug] 26682#0: 6185 http close request 2013/04/02 10:21:23 [debug] 26682#0: 6185 http log handler 2013/04/02 10:21:23 [debug] 26682#0: 6185 http pinba handler 2013/04/02 10:21:23 [debug] 26682#0: 6185 run cleanup: 0000000002373248 2013/04/02 10:21:23 [debug] 26682#0: 6185 file cleanup: fd:32 2013/04/02 10:21:23 [debug] 26682#0: 6185 run cleanup: 00000000023731F0 2013/04/02 10:21:23 [debug] 26682#0: 6185 free: 00000000023722A0, unused: 2 2013/04/02 10:21:23 [debug] 26682#0: 6185 free: 00000000023732B0, unused: 3352 2013/04/02 10:21:23 [debug] 26682#0: 6185 event timer add: 30: 5000:1364890888499 2013/04/02 10:21:23 [debug] 26682#0: 6185 free: 00000000022A4E30 2013/04/02 10:21:23 [debug] 26682#0: 6185 free: 00000000022A5470 2013/04/02 10:21:23 [debug] 26682#0: 6185 hc free: 0000000000000000 0 2013/04/02 10:21:23 [debug] 26682#0: 6185 hc busy: 0000000000000000 0 2013/04/02 10:21:23 [debug] 26682#0: 6185 reusable connection: 1 2013/04/02 10:21:23 [debug] 26682#0: 6185 post event 00007FC0A7418488 2013/04/02 10:21:23 [debug] 26682#0: 6185 delete posted event 00007FC0A7418488 2013/04/02 10:21:23 [debug] 26682#0: 6185 http keepalive handler 2013/04/02 10:21:23 [debug] 26682#0: 6185 malloc: 00000000022A4E30:1024 2013/04/02 10:21:23 [debug] 26682#0: 6185 recv: fd:30 -1 of 1024 2013/04/02 10:21:23 [debug] 26682#0: 6185 recv() not ready (11: Resource temporarily unavailable) 2013/04/02 10:21:23 [debug] 26682#0: 6185 free: 00000000022A4E30 2013/04/02 10:21:23 [debug] 26682#0: 6186 event timer del: 31: 1364890913492 2013/04/02 10:21:23 [debug] 26682#0: 6186 generic phase: 0 2013/04/02 10:21:23 [debug] 26682#0: 6186 rewrite phase: 1 2013/04/02 10:21:23 [debug] 26682#0: 6186 http script var 2013/04/02 10:21:23 [debug] 26682#0: 6186 http map started 2013/04/02 10:21:23 [debug] 26682#0: 6186 http script var: "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.22 (KHTML, like Gecko) Ubuntu Chromium/25.0.1364.160 Chrome/25.0.1364.160 Safari/537.22" 2013/04/02 10:21:23 [debug] 26682#0: 6186 http map: "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.22 (KHTML, like Gecko) Ubuntu Chromium/25.0.1364.160 Chrome/25.0.1364.160 Safari/537.22" "0" 2013/04/02 10:21:23 [debug] 26682#0: 6186 http script var: "0" 2013/04/02 10:21:23 [debug] 26682#0: 6186 http script if 2013/04/02 10:21:23 [debug] 26682#0: 6186 http script if: false 2013/04/02 10:21:23 [debug] 26682#0: 6186 http script var 2013/04/02 10:21:23 [debug] 26682#0: 6186 http geo started: 172.19.32.67 2013/04/02 10:21:23 [debug] 26682#0: 6186 http geo: 2013/04/02 10:21:23 [debug] 26682#0: 6186 http script var: "" 2013/04/02 10:21:23 [debug] 26682#0: 6186 http script if 2013/04/02 10:21:23 [debug] 26682#0: 6186 http script if: false 2013/04/02 10:21:23 [debug] 26682#0: 6186 http script var 2013/04/02 10:21:23 [debug] 26682#0: 6186 http map started 2013/04/02 10:21:23 [debug] 26682#0: 6186 http script var: "GET" 2013/04/02 10:21:23 [debug] 26682#0: 6186 http map: "GET" "0" 2013/04/02 10:21:23 [debug] 26682#0: 6186 http script var: "0" 2013/04/02 10:21:23 [debug] 26682#0: 6186 http script if 2013/04/02 10:21:23 [debug] 26682#0: 6186 http script if: false 2013/04/02 10:21:23 [debug] 26682#0: 6186 test location: "/" 2013/04/02 10:21:23 [debug] 26682#0: 6186 test location: "patches" 2013/04/02 10:21:23 [debug] 26682#0: 6186 test location: "progress" 2013/04/02 10:21:23 [debug] 26682#0: 6186 test location: "rss.xml" 2013/04/02 10:21:23 [debug] 26682#0: 6186 test location: "sitemap.xml" 2013/04/02 10:21:23 [debug] 26682#0: 6186 test location: "/sites/172.19.65.71/files/audio/ogg" 2013/04/02 10:21:23 [debug] 26682#0: 6186 test location: "/sites/172.19.65.71/files/video/mp4" 2013/04/02 10:21:23 [debug] 26682#0: 6186 test location: "/system/files/" 2013/04/02 10:21:23 [debug] 26682#0: 6186 test location: ~ "/imagecache/" 2013/04/02 10:21:23 [debug] 26682#0: 6186 test location: ~ "/files/styles/" 2013/04/02 10:21:23 [debug] 26682#0: 6186 test location: ~ "^.+.(?:css|cur|js|jpg|jpeg|gif|ico|png|html|xml)$" 2013/04/02 10:21:23 [debug] 26682#0: 6186 using configuration "^.+.(?:css|cur|js|jpg|jpeg|gif|ico|png|html|xml)$" 2013/04/02 10:21:23 [debug] 26682#0: 6186 http cl:-1 max:10485760 2013/04/02 10:21:23 [debug] 26682#0: 6186 rewrite phase: 3 2013/04/02 10:21:23 [debug] 26682#0: 6186 rewrite phase: 4 2013/04/02 10:21:23 [debug] 26682#0: 6186 post rewrite phase: 5 2013/04/02 10:21:23 [debug] 26682#0: 6186 generic phase: 6 2013/04/02 10:21:23 [debug] 26682#0: 6186 generic phase: 7 2013/04/02 10:21:23 [debug] 26682#0: 6186 generic phase: 8 2013/04/02 10:21:23 [debug] 26682#0: 6186 limit conn: 42C85000 1 2013/04/02 10:21:23 [debug] 26682#0: 6186 add cleanup: 00000000023731F0 2013/04/02 10:21:23 [debug] 26682#0: 6186 access phase: 9 2013/04/02 10:21:23 [debug] 26682#0: 6186 access phase: 10 2013/04/02 10:21:23 [debug] 26682#0: 6186 access phase: 11 2013/04/02 10:21:23 [debug] 26682#0: 6186 access phase: 12 2013/04/02 10:21:23 [debug] 26682#0: 6186 post access phase: 13 2013/04/02 10:21:23 [debug] 26682#0: 6186 try files phase: 14 2013/04/02 10:21:23 [debug] 26682#0: 6186 content phase: 15 2013/04/02 10:21:23 [debug] 26682#0: 6186 content phase: 16 2013/04/02 10:21:23 [debug] 26682#0: 6186 content phase: 17 2013/04/02 10:21:23 [debug] 26682#0: 6186 content phase: 18 2013/04/02 10:21:23 [debug] 26682#0: 6186 content phase: 19 2013/04/02 10:21:23 [debug] 26682#0: 6186 content phase: 20 2013/04/02 10:21:23 [debug] 26682#0: 6186 content phase: 21 2013/04/02 10:21:23 [debug] 26682#0: 6186 http filename: "/var/www/drupalair/sites/all/modules/date/date_api/date.css" 2013/04/02 10:21:23 [debug] 26682#0: 6186 add cleanup: 0000000002373258 2013/04/02 10:21:23 [debug] 26682#0: 6186 http static fd: 33 2013/04/02 10:21:23 [debug] 26682#0: 6186 http set discard body 2013/04/02 10:21:23 [debug] 26682#0: 6186 posix_memalign: 00000000023732B0:4096 @16 2013/04/02 10:21:23 [debug] 26682#0: 6186 http ims:1364391700 lm:1364391700 2013/04/02 10:21:23 [debug] 26682#0: 6186 uploadprogress error-tracker error: 0 2013/04/02 10:21:23 [debug] 26682#0: 6186 xslt filter header 2013/04/02 10:21:23 [debug] 26682#0: 6186 HTTP/1.1 304 Not Modified Server: nginx Date: Tue, 02 Apr 2013 08:21:23 GMT Last-Modified: Wed, 27 Mar 2013 13:41:40 GMT Connection: keep-alive Keep-Alive: timeout=5 Expires: Thu, 02 May 2013 08:21:23 GMT Cache-Control: max-age=2592000 X-Frame-Options: SAMEORIGIN

2013/04/02 10:21:23 [debug] 26682#0: 6186 write new buf t:1 f:0 0000000002373480, pos 0000000002373480, size: 275 file: 0, size: 0 2013/04/02 10:21:23 [debug] 26682#0: 6186 http write filter: l:1 f:0 s:275 2013/04/02 10:21:23 [debug] 26682#0: 6186 http write filter limit 0 2013/04/02 10:21:23 [debug] 26682#0: 6186 writev: 275 2013/04/02 10:21:23 [debug] 26682#0: 6186 http write filter 0000000000000000 2013/04/02 10:21:23 [debug] 26682#0: 6186 http finalize request: 0, "/sites/all/modules/date/date_api/date.css?mkmbil" a:1, c:1 2013/04/02 10:21:23 [debug] 26682#0: 6186 set http keepalive handler 2013/04/02 10:21:23 [debug] 26682#0: 6186 http close request 2013/04/02 10:21:23 [debug] 26682#0: 6186 http log handler 2013/04/02 10:21:23 [debug] 26682#0: 6186 http pinba handler 2013/04/02 10:21:23 [debug] 26682#0: *6186 run cleanup: 0000000002373258 2013/04/02 10:21:23 [debug] 26

[ghost]

Hello,

I still have the file containing the log. Maybe there is a better way to send you it or to help you understanding it ?

Thanks.

[ghost]

Hello,

I took some screenshost from my firebug and release a new log. You can see the logo and the favicon which give a forbidden access. Unfortunately, I don't know how to upload the log file properly.

[perusio]

There's nothing in the above debug log. Create a Gist with the debug log ( copy & paste) when trying to access the files that generate the 403.

[ghost]

https://gist.github.com/Lengronne/974cefbbff5fb41bac74

Here is the gist containing the log.

Thanks.

[perusio]

The 403 is returned by drupal. I think you have some sort of problem in the private file configuration. I suggest you install the nginx_accel_redirect it will give you better performance and will help doing a better diagnostic.

[ghost]

Hello,

I don't have any 403 forbidden error anymore but the logo and favicon don't display if they are in the private filesystem. I have xmlsitemap in the private filesystem and I can access it via http. Is it the normal behavior ?

Thanks.

[perusio]

The sitemap is served by an exact location and that bypasses the private files location.

Comment out the /sitemap.xml location. Ditto for the /favicon.ico location.

[ghost]

Ok, I commented out sitemap.xml, as expected I had a 404 by accessing directly. I rebuild it and it worked so I don't know if it is a good test.

For the favicon, what do you specifically mean ?

[perusio]

Comment out the /favicon.ico location. Probably right now is sending you the 1x1 transparent GIF as a fallback.

What's the output of:

curl -I http://yoursite/favicon.ico

[ghost]

The output is the same if I set the image in the public or private folder:

HTTP/1.1 200 OK Server: nginx Date: Mon, 08 Apr 2013 13:58:32 GMT Content-Type: image/gif Content-Length: 43 Last-Modified: Mon, 28 Sep 1970 06:00:00 GMT Connection: keep-alive Keep-Alive: timeout=5 Expires: Wed, 08 May 2013 13:58:32 GMT Cache-Control: max-age=2592000 X-Frame-Options: SAMEORIGIN

If I comment out the '/favicon.ico' I have the following when set on private folder:

HTTP/1.1 404 Not Found Server: nginx Date: Mon, 08 Apr 2013 14:00:23 GMT Content-Type: text/html Content-Length: 162 Connection: keep-alive Keep-Alive: timeout=5 Vary: Accept-Encoding

[ghost]

When I attach a file in privatemsg, the file is processed in the private folder but doesn't cause any problem for being uploaded or downloaded.

[perusio]

It's because the favicon is not at the root. Can you create a gist of the debug log for the curl of the favicon above?

[ghost]

I don't know what happened but the favicon works except for the admin theme. Here is my gists:

https://gist.github.com/Lengronne/581edb3001c79b6e263b

[ghost]

Ok, spoken too fast. It doesn't work on firefox but works on chromium.

[ghost]

Actually, it doesnt' work at all. Except for the favicon on chromium. I tried to upload an avatar but it doesn't display.

[ghost]

Hello,

Do you have any idea what could be wrong ?

Or do you have any suggestions to do otherwise ?

[ghost]

I have also an image which is the icon of an og group and it is displayed. the only difference as far as I can see is that image is stored directly in the private folder and the avatars are stored in the private/pictures folder.

[perusio]

Can you post the debug log just for the the icons/images not displaying on a Gist?

[ghost]

Here is the gist:

https://gist.github.com/Lengronne/e011f79268f67e5ca2c1

The same image is viewed in the modify page by system/files/styles/thumbnail/private/ai_bann_0.png and gives a denied access and on the other pages by system/files/ai_bann_0.png and well displayed.

That's wird and very annoying.

The folder files/styles/thumbnail/private doesn't even exist. There is only the public one.

[ghost]

When I set a default image for an og group image field, I had this value:

https://gist.github.com/Lengronne/745c35ca551842e6f80a

The image is in system/files/default_images/logo_air_052012_kmi.png and consequently not shown in the interface.

I think there is something terribly wrong with the subfolders in private.

[ghost]

Bonjour Perusio,

j'ai vu que travaillant à Paris, tu dois certainement parler français. Le français étant ma langue maternelle, cela me permettrait d'être plus précis. Es-tu d'accord ?

Je pense que le problème vient des sous-dossiers au sein du dossier privé. Quand je charge un fichier dans un de ces sous-dossiers il est parfois affiché par son chemin d’origine, parfois par la redirection du système privé. Et, le problème bien sûr, c'est que quand il est affiché par son chemin d'origine on tombe sous les restrictions de type 404 ou 403. Je ne sais pas pourquoi en fonction du type de sous-dossier on peut tomber sur un 403 ou un 404.

Je ne sais pas quelles infos je peux te donner en plus. C'est vraiment un bug ennuyeux car je ne peux pas afficher d'avatars choisis par les utilisateurs. J'ai bidouillé un emplacement pour le favicon dont je ne suis pas drupalistiquement satisfait. Je l'ai mis à la racine de Drupal ainsi il apparaît.

Quelles infos te manquent ? Comment puis-je aider ?

Merci.

[ghost]

Par exemple, dans le cas de l'avatar, il appelle l'image à system/files/styles/thumbnail/private/pictures/picture-341-1365759632.gif alors qu'elle est accessible à system/files/pictures/picture-341-1365759632.gif. Il y a donc ce bout de chemin styles/thumbnail/private/ qui s'intercale sans qu'on lui demande son avis.

[ghost]

J'ai voulu créer un alias entre ces deux urls avec le système interne à Drupal mais ça ne fonctionne pas.

[ghost]

J'ai recréé un Gist avec les deux types d'erreurs:

https://gist.github.com/Lengronne/bddd7ba0202e88e53460

[ghost]

En regardant de plus près cela ressemble à ces erreurs:

http://drupal.org/node/931540

http://drupal.org/node/1825818

Cela n'est peut-être donc pas du à la configuration nginx. Désolé pour le temps perdu.

[ghost]

Il y a peut être quelque chose à voir avec cette directive:

## Drupal 7 generated image handling, i.e., imagecache in core. See:
## https://drupal.org/node/371374.
location ~* /files/styles/ {
    access_log off;
    expires 30d;
    try_files $uri @drupal;
}

[perusio]

Il faut que j’aie le debug log complet et pas seulement les en têtes. Est-ce que le dossier en question existe ?

[ghost]

Pour le 404, le dossier default_images existe dans le dossier privé avec l'image dedans. Pour le 403, le dossier pictures existe aussi avec l'image.

Comment fait-on pour avoir le debug complet ? Désolé, je ne suis pas un grand utilisateur de curl. Le mode verbose ne donne aussi que l'entête.

[perusio]

http://nginx.org/en/docs/debugging_log.html. C'est le log qu'intéresse.

[ghost]

Je viens de faire la bêtise la plus c.. du monde. J'ai lancé un test d'injections SQL et mon ip a été bannie par Drupal. Je te donne le log dés que j'aurais réussi à trouver comment enlever le ban.

[ghost]

Ma table IP_blocked est vide dans MySQL. C'est bizarre.

[ghost]

C'est bon, trouvé. C'est la table flood.

Voilà un debug de la page contenant le 403:

https://gist.github.com/Lengronne/1408734b50e7155e01c0

[perusio]

Il rentre bien dans le bon endroit de la config. Le problème vient de Drupal. Le cookie de session n'est pas la. Les fichiers privés sont accessibles seulement aux utilisateurs authentifiés.

[ghost]

Ah ok. As-tu une idée de comment débugger et résoudre ça ?

Merci.

[ghost]

C'est bizarre que je puisse voir certaines images du dossier privé et pas d'autres. ça devrait être tout ou rien, non ?

[ghost]

Pour info, voici mes paramètres dans php.ini relatifs aux cookies: session.use_cookies = 1 session.use_only_cookies = 1 session.name = PHPSESSID session.auto_start = 0 session.cookie_lifetime = 0 session.cookie_path = / session.cookie_domain = session.cookie_httponly = 1

Les sessions sont stockées dans un repcache.

[ghost]

Et ce qui est préoccupant c'est que l'image soit accessible sur le chemin system/files/pictures/picture-341-1365759632.gif?itok=5aFTt17p.

[ghost]

Et ce même pour les utilisateurs anonymes.

[ghost]

Sur ce gists, j'ai mis les différents problèmes recensés.

https://gist.github.com/Lengronne/c64d67fac80ed251b0e2

[perusio]

C'est bizarre. Apparemment ces images la n'on pas the cookie, donc pour drupal tu n'est pas authentifié. Pour les images accessibles il y doit avoir le cookie. S'il n'y a pas et si les images sont acessibles il y a un problème la.

[ghost]

J'ai vidée les cookies du navigateur et les images sont toujours accessibles. Il y a un problème ^^

[ghost]

J'avoue ne pas comprendre.

[ghost]

Voici la liste des modules installés:

https://gist.github.com/Lengronne/c38bd1374483e3879d9d