search

magento / devdocs

[Deprecated] Magento Developer Documentation
Open Software License 3.0
674 stars 1.76k forks source link

Securing cron.php is misleading or not sufficiently explained #875

Closed pantaoran closed 7 years ago

pantaoran commented 8 years ago

On this page there is the following documentation:

Step 2: Modify the nginx configuration

Add the following to your nginx.conf:

location cron\.php {
    auth_basic "Cron Authentication";
    auth_basic_user_file <path to password file>;
}

Restart nginx and continue with the next section.

This is not clear at all. If I follow this literally, what happens is that every time I point my browser to cron.php it will attempt to download that file rather than executing it.

Could you please expand that to include the fact that that block still needs lots of additional lines to work with php-fpm? I had to duplicate many lines from the location block below to get this to work.

ghost commented 8 years ago

Would you mind providing that info here?

pantaoran commented 8 years ago

The Magento 2.1 nginx sample config contains the following block:

# PHP entry point for main application
location ~ (index|get|static|report|404|503)\.php$ {
    try_files $uri =404;
    fastcgi_pass   fastcgi_backend;
    fastcgi_buffers 1024 4k;

    fastcgi_param  PHP_FLAG  "session.auto_start=off \n suhosin.session.cryptua=off";
    fastcgi_param  PHP_VALUE "memory_limit=768M \n max_execution_time=18000";
    fastcgi_read_timeout 600s;
    fastcgi_connect_timeout 600s;

    fastcgi_index  index.php;
    fastcgi_param  SCRIPT_FILENAME  $document_root$fastcgi_script_name;
    include        fastcgi_params;
}

I used all the lines from inside that block in addition to the two lines about auth_basic that I mentioned above.

I have no idea if that is good/recommended because I'm not very good with nginx. As a developer I hate to see that code duplication, but I don't know how to avoid it.

My final working block looks like this (also added tilde character on first line compared to documentation):

location ~ cron\.php {
    auth_basic "Cron Authentication";
    auth_basic_user_file <path to password file>;

    try_files $uri =404;
    fastcgi_pass   fastcgi_backend;
    fastcgi_buffers 1024 4k;

    fastcgi_param  PHP_FLAG  "session.auto_start=off \n suhosin.session.cryptua=off";
    fastcgi_param  PHP_VALUE "memory_limit=768M \n max_execution_time=18000";
    fastcgi_read_timeout 600s;
    fastcgi_connect_timeout 600s;

    fastcgi_index  index.php;
    fastcgi_param  SCRIPT_FILENAME  $document_root$fastcgi_script_name;
    include        fastcgi_params;
}
ghost commented 8 years ago

Created MAGETWO-60158 to track.

ghost commented 8 years ago

@pantaoran I'm trying to set up a system but I cannot get nginx to work with Magento 2.1.2 at all. In what file is your server block located?

pantaoran commented 8 years ago

Firstly, I'm working with Magento 2.1.0 here, haven't made it to 2.1.2 yet, but I'll just assume that it shouldn't be a huge difference.

However, your question confuses me. The server block is in the nginx config file. In my last post I linked to Magento2's own sample config, which contains the server block in a comment near the top.

Specifically, what I do is uncomment lines 8 - 13 and move the closing bracket on line 13 to the end of the file so that the server block contains all the rest.

ghost commented 8 years ago

Thanks, that's the same thing I did. I get a 500 when I try to access the web server and the logs are confusing. I'll try it again later this week.

pantaoran commented 8 years ago

Post your confusing logs, I might have some ideas, I have accumulated quite a bit of experience in debugging nginx configs by now...

ghost commented 8 years ago

error.log set at debug; nothing is logged if I set it for info:

2016/10/28 09:53:03 [debug] 15747#0: epoll: fd:6 ev:0001 d:00007F7F72B3D010 2016/10/28 09:53:03 [debug] 15747#0: accept on 0.0.0.0:80, ready: 0 2016/10/28 09:53:03 [debug] 15747#0: posix_memalign: 0000000000FCB2E0:512 @16 2016/10/28 09:53:03 [debug] 15747#0: _29 accept: 10.235.34.14:51165 fd:4 2016/10/28 09:53:03 [debug] 15747#0: 29 event timer add: 4: 60000:1477666443273 2016/10/28 09:53:03 [debug] 15747#0: 29 reusable connection: 1 2016/10/28 09:53:03 [debug] 15747#0: 29 epoll add event: fd:4 op:1 ev:80002001 2016/10/28 09:53:03 [debug] 15747#0: timer delta: 82554 2016/10/28 09:53:03 [debug] 15747#0: worker cycle 2016/10/28 09:53:03 [debug] 15747#0: epoll timer: 60000 2016/10/28 09:53:03 [debug] 15747#0: epoll: fd:6 ev:0001 d:00007F7F72B3D010 2016/10/28 09:53:03 [debug] 15747#0: accept on 0.0.0.0:80, ready: 0 2016/10/28 09:53:03 [debug] 15747#0: posix_memalign: 0000000000FCD3B0:512 @16 2016/10/28 09:53:03 [debug] 15747#0: 30 accept: 10.235.34.14:51166 fd:11 2016/10/28 09:53:03 [debug] 15747#0: 30 event timer add: 11: 60000:1477666443273 2016/10/28 09:53:03 [debug] 15747#0: 30 reusable connection: 1 2016/10/28 09:53:03 [debug] 15747#0: 30 epoll add event: fd:11 op:1 ev:80002001 2016/10/28 09:53:03 [debug] 15747#0: timer delta: 0 2016/10/28 09:53:03 [debug] 15747#0: worker cycle 2016/10/28 09:53:03 [debug] 15747#0: epoll timer: 60000 2016/10/28 09:53:03 [debug] 15747#0: epoll: fd:6 ev:0001 d:00007F7F72B3D010 2016/10/28 09:53:03 [debug] 15747#0: accept on 0.0.0.0:80, ready: 0 2016/10/28 09:53:03 [debug] 15747#0: posix_memalign: 0000000000FD0E80:512 @16 2016/10/28 09:53:03 [debug] 15747#0: 31 accept: 10.235.34.14:51167 fd:12 2016/10/28 09:53:03 [debug] 15747#0: 31 event timer add: 12: 60000:1477666443273 2016/10/28 09:53:03 [debug] 15747#0: 31 reusable connection: 1 2016/10/28 09:53:03 [debug] 15747#0: 31 epoll add event: fd:12 op:1 ev:80002001 2016/10/28 09:53:03 [debug] 15747#0: timer delta: 0 2016/10/28 09:53:03 [debug] 15747#0: worker cycle 2016/10/28 09:53:03 [debug] 15747#0: epoll timer: 60000 2016/10/28 09:53:03 [debug] 15747#0: epoll: fd:4 ev:0001 d:00007F7F72B3D390 2016/10/28 09:53:03 [debug] 15747#0: 29 http wait request handler 2016/10/28 09:53:03 [debug] 15747#0: 29 malloc: 0000000000F3C2F0:1024 2016/10/28 09:53:03 [debug] 15747#0: 29 recv: fd:4 411 of 1024 2016/10/28 09:53:03 [debug] 15747#0: 29 reusable connection: 0 2016/10/28 09:53:03 [debug] 15747#0: 29 posix_memalign: 0000000000F46F60:4096 @16 2016/10/28 09:53:03 [debug] 15747#0: 29 http process request line 2016/10/28 09:53:03 [debug] 15747#0: 29 http request line: "GET /index.html HTTP/1.1" 2016/10/28 09:53:03 [debug] 15747#0: 29 http uri: "/index.html" 2016/10/28 09:53:03 [debug] 15747#0: 29 http args: "" 2016/10/28 09:53:03 [debug] 15747#0: 29 http exten: "html" 2016/10/28 09:53:03 [debug] 15747#0: 29 posixmemalign: 0000000000FCD7C0:4096 @16 2016/10/28 09:53:03 [debug] 15747#0: 29 http process request header line 2016/10/28 09:53:03 [debug] 15747#0: 29 http header: "Host: 10.235.32.10" 2016/10/28 09:53:03 [debug] 15747#0: 29 http header: "Connection: keep-alive" 2016/10/28 09:53:03 [debug] 15747#0: 29 http header: "Cache-Control: max-age=0" 2016/10/28 09:53:03 [debug] 15747#0: 29 http header: "Upgrade-Insecure-Requests: 1" 2016/10/28 09:53:03 [debug] 15747#0: 29 http header: "User-Agent: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/54.0.2840.71 Safari/537.36" 2016/10/28 09:53:03 [debug] 15747#0: *29 http header: "Accept: text/html,application/xhtml+xml,application/xml;q=0.9,image/webp,/_;q=0.8" 2016/10/28 09:53:03 [debug] 15747#0: 29 http header: "Accept-Encoding: gzip, deflate, sdch" 2016/10/28 09:53:03 [debug] 15747#0: 29 http header: "Accept-Language: en-US,en;q=0.8" 2016/10/28 09:53:03 [debug] 15747#0: 29 http header done 2016/10/28 09:53:03 [debug] 15747#0: 29 event timer del: 4: 1477666443273 2016/10/28 09:53:03 [debug] 15747#0: 29 generic phase: 0 2016/10/28 09:53:03 [debug] 15747#0: 29 rewrite phase: 1 2016/10/28 09:53:03 [debug] 15747#0: 29 http script value: "/var/www/html/magento2" 2016/10/28 09:53:03 [debug] 15747#0: 29 http script set $mage_root 2016/10/28 09:53:03 [debug] 15747#0: 29 http script value: "developer" 2016/10/28 09:53:03 [debug] 15747#0: 29 http script set $mage_mode 2016/10/28 09:53:03 [debug] 15747#0: 29 test location: "/" 2016/10/28 09:53:03 [debug] 15747#0: 29 test location: "pub/" 2016/10/28 09:53:03 [debug] 15747#0: 29 test location: "media/" 2016/10/28 09:53:03 [debug] 15747#0: 29 test location: ~ "^/setup($|/)" 2016/10/28 09:53:03 [debug] 15747#0: 29 test location: ~ "^/update($|/)" 2016/10/28 09:53:03 [debug] 15747#0: 29 test location: ~ "(index|get|static|report|404|503).php$" 2016/10/28 09:53:03 [debug] 15747#0: 29 test location: ~ "(.php$|.htaccess$|.git)" 2016/10/28 09:53:03 [debug] 15747#0: 29 using configuration "/" 2016/10/28 09:53:03 [debug] 15747#0: 29 http cl:-1 max:1048576 2016/10/28 09:53:03 [debug] 15747#0: 29 rewrite phase: 3 2016/10/28 09:53:03 [debug] 15747#0: 29 post rewrite phase: 4 2016/10/28 09:53:03 [debug] 15747#0: 29 generic phase: 5 2016/10/28 09:53:03 [debug] 15747#0: 29 generic phase: 6 2016/10/28 09:53:03 [debug] 15747#0: 29 generic phase: 7 2016/10/28 09:53:03 [debug] 15747#0: 29 generic phase: 8 2016/10/28 09:53:03 [debug] 15747#0: 29 access phase: 9 2016/10/28 09:53:03 [debug] 15747#0: 29 access phase: 10 2016/10/28 09:53:03 [debug] 15747#0: 29 post access phase: 11 2016/10/28 09:53:03 [debug] 15747#0: 29 try files phase: 12 2016/10/28 09:53:03 [debug] 15747#0: 29 http script var: "/var/www/html/magento2" 2016/10/28 09:53:03 [debug] 15747#0: 29 http script copy: "/pub" 2016/10/28 09:53:03 [debug] 15747#0: 29 http script var: "/index.html" 2016/10/28 09:53:03 [debug] 15747#0: 29 trying to use file: "/index.html" "/var/www/html/magento2/pub/index.html" 2016/10/28 09:53:03 [debug] 15747#0: 29 http script var: "/index.html" 2016/10/28 09:53:03 [debug] 15747#0: 29 trying to use dir: "/index.html" "/var/www/html/magento2/pub/index.html" 2016/10/28 09:53:03 [debug] 15747#0: 29 http script copy: "/index.php?" 2016/10/28 09:53:03 [debug] 15747#0: 29 trying to use file: "/index.php?" "/var/www/html/magento2/pub/index.php?" 2016/10/28 09:53:03 [debug] 15747#0: 29 internal redirect: "/index.php?" 2016/10/28 09:53:03 [debug] 15747#0: 29 rewrite phase: 1 2016/10/28 09:53:03 [debug] 15747#0: 29 http script value: "/var/www/html/magento2" 2016/10/28 09:53:03 [debug] 15747#0: 29 http script set $mage_root 2016/10/28 09:53:03 [debug] 15747#0: 29 http script value: "developer" 2016/10/28 09:53:03 [debug] 15747#0: 29 http script set $mage_mode 2016/10/28 09:53:03 [debug] 15747#0: 29 test location: "/" 2016/10/28 09:53:03 [debug] 15747#0: 29 test location: "pub/" 2016/10/28 09:53:03 [debug] 15747#0: 29 test location: "media/" 2016/10/28 09:53:03 [debug] 15747#0: 29 test location: ~ "^/setup($|/)" 2016/10/28 09:53:03 [debug] 15747#0: 29 test location: ~ "^/update($|/)" 2016/10/28 09:53:03 [debug] 15747#0: 29 test location: ~ "(index|get|static|report|404|503).php$" 2016/10/28 09:53:03 [debug] 15747#0: 29 using configuration "(index|get|static|report|404|503).php$" 2016/10/28 09:53:03 [debug] 15747#0: 29 http cl:-1 max:1048576 2016/10/28 09:53:03 [debug] 15747#0: 29 rewrite phase: 3 2016/10/28 09:53:03 [debug] 15747#0: 29 post rewrite phase: 4 2016/10/28 09:53:03 [debug] 15747#0: 29 generic phase: 5 2016/10/28 09:53:03 [debug] 15747#0: 29 generic phase: 6 2016/10/28 09:53:03 [debug] 15747#0: 29 generic phase: 7 2016/10/28 09:53:03 [debug] 15747#0: 29 generic phase: 8 2016/10/28 09:53:03 [debug] 15747#0: 29 access phase: 9 2016/10/28 09:53:03 [debug] 15747#0: 29 access phase: 10 2016/10/28 09:53:03 [debug] 15747#0: 29 post access phase: 11 2016/10/28 09:53:03 [debug] 15747#0: 29 try files phase: 12 2016/10/28 09:53:03 [debug] 15747#0: 29 http script var: "/var/www/html/magento2" 2016/10/28 09:53:03 [debug] 15747#0: 29 http script copy: "/pub" 2016/10/28 09:53:03 [debug] 15747#0: 29 http script var: "/index.php" 2016/10/28 09:53:03 [debug] 15747#0: 29 trying to use file: "/index.php" "/var/www/html/magento2/pub/index.php" 2016/10/28 09:53:03 [debug] 15747#0: 29 try file uri: "/index.php" 2016/10/28 09:53:03 [debug] 15747#0: 29 http init upstream, client timer: 0 2016/10/28 09:53:03 [debug] 15747#0: 29 epoll add event: fd:4 op:3 ev:80002005 2016/10/28 09:53:03 [debug] 15747#0: 29 http script var: "/var/www/html/magento2" 2016/10/28 09:53:03 [debug] 15747#0: 29 http script copy: "/pub" 2016/10/28 09:53:03 [debug] 15747#0: 29 http script copy: "PHP_FLAG" 2016/10/28 09:53:03 [debug] 15747#0: 29 http script copy: "session.auto_start=off suhosin.session.cryptua=off" 2016/10/28 09:53:03 [debug] 15747#0: 29 fastcgi param: "PHP_FLAG: session.auto_start=off suhosin.session.cryptua=off" 2016/10/28 09:53:03 [debug] 15747#0: 29 http script copy: "PHP_VALUE" 2016/10/28 09:53:03 [debug] 15747#0: 29 http script copy: "memory_limit=768M max_execution_time=600" 2016/10/28 09:53:03 [debug] 15747#0: 29 fastcgi param: "PHP_VALUE: memory_limit=768M max_execution_time=600" 2016/10/28 09:53:03 [debug] 15747#0: 29 http script copy: "SCRIPT_FILENAME" 2016/10/28 09:53:03 [debug] 15747#0: 29 http script var: "/var/www/html/magento2/pub" 2016/10/28 09:53:03 [debug] 15747#0: 29 http script var: "/index.php" 2016/10/28 09:53:03 [debug] 15747#0: 29 fastcgi param: "SCRIPT_FILENAME: /var/www/html/magento2/pub/index.php" 2016/10/28 09:53:03 [debug] 15747#0: 29 http script copy: "QUERY_STRING" 2016/10/28 09:53:03 [debug] 15747#0: 29 http script var: "" 2016/10/28 09:53:03 [debug] 15747#0: 29 fastcgi param: "QUERY_STRING: " 2016/10/28 09:53:03 [debug] 15747#0: 29 http script copy: "REQUEST_METHOD" 2016/10/28 09:53:03 [debug] 15747#0: 29 http script var: "GET" 2016/10/28 09:53:03 [debug] 15747#0: 29 fastcgi param: "REQUEST_METHOD: GET" 2016/10/28 09:53:03 [debug] 15747#0: 29 http script copy: "CONTENT_TYPE" 2016/10/28 09:53:03 [debug] 15747#0: 29 fastcgi param: "CONTENT_TYPE: " 2016/10/28 09:53:03 [debug] 15747#0: 29 http script copy: "CONTENT_LENGTH" 2016/10/28 09:53:03 [debug] 15747#0: 29 fastcgi param: "CONTENT_LENGTH: " 2016/10/28 09:53:03 [debug] 15747#0: 29 http script copy: "SCRIPT_NAME" 2016/10/28 09:53:03 [debug] 15747#0: 29 http script var: "/index.php" 2016/10/28 09:53:03 [debug] 15747#0: 29 fastcgi param: "SCRIPT_NAME: /index.php" 2016/10/28 09:53:03 [debug] 15747#0: 29 http script copy: "REQUEST_URI" 2016/10/28 09:53:03 [debug] 15747#0: 29 http script var: "/index.html" 2016/10/28 09:53:03 [debug] 15747#0: 29 fastcgi param: "REQUEST_URI: /index.html" 2016/10/28 09:53:03 [debug] 15747#0: 29 http script copy: "DOCUMENT_URI" 2016/10/28 09:53:03 [debug] 15747#0: 29 http script var: "/index.php" 2016/10/28 09:53:03 [debug] 15747#0: 29 fastcgi param: "DOCUMENT_URI: /index.php" 2016/10/28 09:53:03 [debug] 15747#0: 29 http script copy: "DOCUMENT_ROOT" 2016/10/28 09:53:03 [debug] 15747#0: 29 http script var: "/var/www/html/magento2/pub" 2016/10/28 09:53:03 [debug] 15747#0: 29 fastcgi param: "DOCUMENT_ROOT: /var/www/html/magento2/pub" 2016/10/28 09:53:03 [debug] 15747#0: 29 http script copy: "SERVER_PROTOCOL" 2016/10/28 09:53:03 [debug] 15747#0: 29 http script var: "HTTP/1.1" 2016/10/28 09:53:03 [debug] 15747#0: 29 fastcgi param: "SERVER_PROTOCOL: HTTP/1.1" 2016/10/28 09:53:03 [debug] 15747#0: 29 http script copy: "REQUEST_SCHEME" 2016/10/28 09:53:03 [debug] 15747#0: 29 http script var: "http" 2016/10/28 09:53:03 [debug] 15747#0: 29 fastcgi param: "REQUEST_SCHEME: http" 2016/10/28 09:53:03 [debug] 15747#0: 29 http script copy: "" 2016/10/28 09:53:03 [debug] 15747#0: 29 http script copy: "GATEWAY_INTERFACE" 2016/10/28 09:53:03 [debug] 15747#0: 29 http script copy: "CGI/1.1" 2016/10/28 09:53:03 [debug] 15747#0: 29 fastcgi param: "GATEWAY_INTERFACE: CGI/1.1" 2016/10/28 09:53:03 [debug] 15747#0: 29 http script copy: "SERVER_SOFTWARE" 2016/10/28 09:53:03 [debug] 15747#0: 29 http script copy: "nginx/" 2016/10/28 09:53:03 [debug] 15747#0: 29 http script var: "1.10.1" 2016/10/28 09:53:03 [debug] 15747#0: 29 fastcgi param: "SERVER_SOFTWARE: nginx/1.10.1" 2016/10/28 09:53:03 [debug] 15747#0: 29 http script copy: "REMOTE_ADDR" 2016/10/28 09:53:03 [debug] 15747#0: 29 http script var: "10.235.34.14" 2016/10/28 09:53:03 [debug] 15747#0: 29 fastcgi param: "REMOTE_ADDR: 10.235.34.14" 2016/10/28 09:53:03 [debug] 15747#0: 29 http script copy: "REMOTE_PORT" 2016/10/28 09:53:03 [debug] 15747#0: 29 http script var: "51165" 2016/10/28 09:53:03 [debug] 15747#0: 29 fastcgi param: "REMOTE_PORT: 51165" 2016/10/28 09:53:03 [debug] 15747#0: 29 http script copy: "SERVER_ADDR" 2016/10/28 09:53:03 [debug] 15747#0: 29 http script var: "10.235.32.10" 2016/10/28 09:53:03 [debug] 15747#0: 29 fastcgi param: "SERVER_ADDR: 10.235.32.10" 2016/10/28 09:53:03 [debug] 15747#0: 29 http script copy: "SERVER_PORT" 2016/10/28 09:53:03 [debug] 15747#0: 29 http script var: "80" 2016/10/28 09:53:03 [debug] 15747#0: 29 fastcgi param: "SERVER_PORT: 80" 2016/10/28 09:53:03 [debug] 15747#0: 29 http script copy: "SERVER_NAME" 2016/10/28 09:53:03 [debug] 15747#0: 29 http script var: "mage.dev" 2016/10/28 09:53:03 [debug] 15747#0: 29 fastcgi param: "SERVER_NAME: mage.dev" 2016/10/28 09:53:03 [debug] 15747#0: 29 http script copy: "REDIRECT_STATUS" 2016/10/28 09:53:03 [debug] 15747#0: 29 http script copy: "200" 2016/10/28 09:53:03 [debug] 15747#0: 29 fastcgi param: "REDIRECT_STATUS: 200" 2016/10/28 09:53:03 [debug] 15747#0: 29 fastcgi param: "HTTP_HOST: 10.235.32.10" 2016/10/28 09:53:03 [debug] 15747#0: 29 fastcgi param: "HTTP_CONNECTION: keep-alive" 2016/10/28 09:53:03 [debug] 15747#0: 29 fastcgi param: "HTTP_CACHE_CONTROL: max-age=0" 2016/10/28 09:53:03 [debug] 15747#0: 29 fastcgi param: "HTTP_UPGRADE_INSECURE_REQUESTS: 1" 2016/10/28 09:53:03 [debug] 15747#0: 29 fastcgi param: "HTTP_USER_AGENT: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/54.0.2840.71 Safari/537.36" 2016/10/28 09:53:03 [debug] 15747#0: 29 fastcgi param: "HTTPACCEPT: text/html,application/xhtml+xml,application/xml;q=0.9,image/webp,/;q=0.8" 2016/10/28 09:53:03 [debug] 15747#0: 29 fastcgi param: "HTTP_ACCEPT_ENCODING: gzip, deflate, sdch" 2016/10/28 09:53:03 [debug] 15747#0: 29 fastcgi param: "HTTP_ACCEPT_LANGUAGE: en-US,en;q=0.8" 2016/10/28 09:53:03 [debug] 15747#0: 29 http cleanup add: 0000000000FCE6A0 2016/10/28 09:53:03 [debug] 15747#0: 29 get rr peer, try: 1 2016/10/28 09:53:03 [debug] 15747#0: 29 stream socket 13 2016/10/28 09:53:03 [debug] 15747#0: 29 epoll add connection: fd:13 ev:80002005 2016/10/28 09:53:03 [debug] 15747#0: 29 connect to 127.0.0.1:9000, fd:13 #32 2016/10/28 09:53:03 [debug] 15747#0: 29 http upstream connect: -2 2016/10/28 09:53:03 [debug] 15747#0: 29 posix_memalign: 0000000000FF2E50:128 @16 2016/10/28 09:53:03 [debug] 15747#0: 29 event timer add: 13: 600000:1477666983274 2016/10/28 09:53:03 [debug] 15747#0: 29 http finalize request: -4, "/index.php?" a:1, c:3 2016/10/28 09:53:03 [debug] 15747#0: 29 http request count:3 blk:0 2016/10/28 09:53:03 [debug] 15747#0: 29 http finalize request: -4, "/index.php?" a:1, c:2 2016/10/28 09:53:03 [debug] 15747#0: 29 http request count:2 blk:0 2016/10/28 09:53:03 [debug] 15747#0: timer delta: 1 2016/10/28 09:53:03 [debug] 15747#0: worker cycle 2016/10/28 09:53:03 [debug] 15747#0: epoll timer: 59999 2016/10/28 09:53:03 [debug] 15747#0: epoll: fd:4 ev:0004 d:00007F7F72B3D390 2016/10/28 09:53:03 [debug] 15747#0: 29 http run request: "/index.php?" 2016/10/28 09:53:03 [debug] 15747#0: 29 http upstream check client, write event:1, "/index.php" 2016/10/28 09:53:03 [debug] 15747#0: 29 http upstream recv(): -1 (11: Resource temporarily unavailable) 2016/10/28 09:53:03 [debug] 15747#0: epoll: fd:13 ev:0004 d:00007F7F72B3D1D0 2016/10/28 09:53:03 [debug] 15747#0: 29 http upstream request: "/index.php?" 2016/10/28 09:53:03 [debug] 15747#0: 29 http upstream send request handler 2016/10/28 09:53:03 [debug] 15747#0: 29 http upstream send request 2016/10/28 09:53:03 [debug] 15747#0: 29 http upstream send request body 2016/10/28 09:53:03 [debug] 15747#0: 29 chain writer buf fl:0 s:1016 2016/10/28 09:53:03 [debug] 15747#0: 29 chain writer in: 0000000000FCE6D8 2016/10/28 09:53:03 [debug] 15747#0: 29 writev: 1016 of 1016 2016/10/28 09:53:03 [debug] 15747#0: 29 chain writer out: 0000000000000000 2016/10/28 09:53:03 [debug] 15747#0: 29 event timer del: 13: 1477666983274 2016/10/28 09:53:03 [debug] 15747#0: 29 event timer add: 13: 600000:1477666983274 2016/10/28 09:53:03 [debug] 15747#0: timer delta: 0 2016/10/28 09:53:03 [debug] 15747#0: worker cycle 2016/10/28 09:53:03 [debug] 15747#0: epoll timer: 59999 2016/10/28 09:53:03 [debug] 15747#0: epoll: fd:6 ev:0001 d:00007F7F72B3D010 2016/10/28 09:53:03 [debug] 15747#0: accept on 0.0.0.0:80, ready: 0 2016/10/28 09:53:03 [debug] 15747#0: posix_memalign: 0000000000FF5010:512 @16 2016/10/28 09:53:03 [debug] 15747#0: 33 accept: 10.235.34.14:51168 fd:14 2016/10/28 09:53:03 [debug] 15747#0: 33 event timer add: 14: 60000:1477666443276 2016/10/28 09:53:03 [debug] 15747#0: 33 reusable connection: 1 2016/10/28 09:53:03 [debug] 15747#0: 33 epoll add event: fd:14 op:1 ev:80002001 2016/10/28 09:53:03 [debug] 15747#0: timer delta: 2 2016/10/28 09:53:03 [debug] 15747#0: worker cycle 2016/10/28 09:53:03 [debug] 15747#0: epoll timer: 59997 2016/10/28 09:53:03 [debug] 15747#0: epoll: fd:6 ev:0001 d:00007F7F72B3D010 2016/10/28 09:53:03 [debug] 15747#0: accept on 0.0.0.0:80, ready: 0 2016/10/28 09:53:03 [debug] 15747#0: posix_memalign: 0000000000FD0670:512 @16 2016/10/28 09:53:03 [debug] 15747#0: 34 accept: 10.235.34.14:51169 fd:15 2016/10/28 09:53:03 [debug] 15747#0: 34 event timer add: 15: 60000:1477666443276 2016/10/28 09:53:03 [debug] 15747#0: 34 reusable connection: 1 2016/10/28 09:53:03 [debug] 15747#0: 34 epoll add event: fd:15 op:1 ev:80002001 2016/10/28 09:53:03 [debug] 15747#0: timer delta: 0 2016/10/28 09:53:03 [debug] 15747#0: worker cycle 2016/10/28 09:53:03 [debug] 15747#0: epoll timer: 59997 2016/10/28 09:53:03 [debug] 15747#0: epoll: fd:6 ev:0001 d:00007F7F72B3D010 2016/10/28 09:53:03 [debug] 15747#0: accept on 0.0.0.0:80, ready: 0 2016/10/28 09:53:03 [debug] 15747#0: posix_memalign: 0000000000FCE7D0:512 @16 2016/10/28 09:53:03 [debug] 15747#0: 35 accept: 10.235.34.14:51170 fd:16 2016/10/28 09:53:03 [debug] 15747#0: 35 event timer add: 16: 60000:1477666443276 2016/10/28 09:53:03 [debug] 15747#0: 35 reusable connection: 1 2016/10/28 09:53:03 [debug] 15747#0: 35 epoll add event: fd:16 op:1 ev:80002001 2016/10/28 09:53:03 [debug] 15747#0: timer delta: 0 2016/10/28 09:53:03 [debug] 15747#0: worker cycle 2016/10/28 09:53:03 [debug] 15747#0: epoll timer: 59997 2016/10/28 09:53:03 [debug] 15747#0: epoll: fd:13 ev:0005 d:00007F7F72B3D1D0 2016/10/28 09:53:03 [debug] 15747#0: 29 http upstream request: "/index.php?" 2016/10/28 09:53:03 [debug] 15747#0: 29 http upstream process header 2016/10/28 09:53:03 [debug] 15747#0: 29 malloc: 0000000000FCB970:4096 2016/10/28 09:53:03 [debug] 15747#0: 29 posix_memalign: 0000000000F40870:4096 @16 2016/10/28 09:53:03 [debug] 15747#0: 29 recv: fd:13 128 of 4096 2016/10/28 09:53:03 [debug] 15747#0: 29 http fastcgi record byte: 01 2016/10/28 09:53:03 [debug] 15747#0: 29 http fastcgi record byte: 06 2016/10/28 09:53:03 [debug] 15747#0: 29 http fastcgi record byte: 00 2016/10/28 09:53:03 [debug] 15747#0: 29 http fastcgi record byte: 01 2016/10/28 09:53:03 [debug] 15747#0: 29 http fastcgi record byte: 00 2016/10/28 09:53:03 [debug] 15747#0: 29 http fastcgi record byte: 67 2016/10/28 09:53:03 [debug] 15747#0: 29 http fastcgi record byte: 01 2016/10/28 09:53:03 [debug] 15747#0: 29 http fastcgi record byte: 00 2016/10/28 09:53:03 [debug] 15747#0: 29 http fastcgi record length: 103 2016/10/28 09:53:03 [debug] 15747#0: 29 http fastcgi parser: 0 2016/10/28 09:53:03 [debug] 15747#0: 29 http fastcgi header: "Status: 500 Internal Server Error" 2016/10/28 09:53:03 [debug] 15747#0: 29 http fastcgi parser: 0 2016/10/28 09:53:03 [debug] 15747#0: 29 http fastcgi header: "X-Powered-By: PHP/5.6.26" 2016/10/28 09:53:03 [debug] 15747#0: 29 http fastcgi parser: 0 2016/10/28 09:53:03 [debug] 15747#0: 29 http fastcgi header: "Content-type: text/html; charset=UTF-8" 2016/10/28 09:53:03 [debug] 15747#0: 29 http fastcgi parser: 1 2016/10/28 09:53:03 [debug] 15747#0: 29 http fastcgi header done 2016/10/28 09:53:03 [debug] 15747#0: 29 xslt filter header 2016/10/28 09:53:03 [debug] 15747#0: 29 HTTP/1.1 500 Internal Server Error Server: nginx/1.10.1 Date: Fri, 28 Oct 2016 14:53:03 GMT Content-Type: text/html; charset=UTF-8 Transfer-Encoding: chunked Connection: keep-alive X-Powered-By: PHP/5.6.26

2016/10/28 09:53:03 [debug] 15747#0: _29 write new buf t:1 f:0 0000000000F40A60, pos 0000000000F40A60, size: 215 file: 0, size: 0 2016/10/28 09:53:03 [debug] 15747#0: 29 http write filter: l:0 f:0 s:215 2016/10/28 09:53:03 [debug] 15747#0: 29 http cacheable: 0 2016/10/28 09:53:03 [debug] 15747#0: 29 http upstream process upstream 2016/10/28 09:53:03 [debug] 15747#0: 29 pipe read upstream: 1 2016/10/28 09:53:03 [debug] 15747#0: 29 pipe preread: 17 2016/10/28 09:53:03 [debug] 15747#0: 29 readv: 1, last:3968 2016/10/28 09:53:03 [debug] 15747#0: 29 readv() not ready (11: Resource temporarily unavailable) 2016/10/28 09:53:03 [debug] 15747#0: 29 pipe recv chain: -2 2016/10/28 09:53:03 [debug] 15747#0: 29 pipe buf free s:0 t:1 f:0 0000000000FCB970, pos 0000000000FCB9DF, size: 17 file: 0, size: 0 2016/10/28 09:53:03 [debug] 15747#0: 29 pipe length: -1 2016/10/28 09:53:03 [debug] 15747#0: 29 pipe write downstream: 1 2016/10/28 09:53:03 [debug] 15747#0: 29 pipe write busy: 0 2016/10/28 09:53:03 [debug] 15747#0: 29 pipe write: out:0000000000000000, f:0 2016/10/28 09:53:03 [debug] 15747#0: 29 pipe read upstream: 0 2016/10/28 09:53:03 [debug] 15747#0: 29 pipe buf free s:0 t:1 f:0 0000000000FCB970, pos 0000000000FCB9DF, size: 17 file: 0, size: 0 2016/10/28 09:53:03 [debug] 15747#0: 29 pipe length: -1 2016/10/28 09:53:03 [debug] 15747#0: 29 event timer: 13, old: 1477666983274, new: 1477666983408 2016/10/28 09:53:03 [debug] 15747#0: 29 http upstream request: "/index.php?" 2016/10/28 09:53:03 [debug] 15747#0: 29 http upstream dummy handler 2016/10/28 09:53:03 [debug] 15747#0: timer delta: 132 2016/10/28 09:53:03 [debug] 15747#0: worker cycle 2016/10/28 09:53:03 [debug] 15747#0: epoll timer: 59865 2016/10/28 09:53:03 [debug] 15747#0: epoll: fd:13 ev:2005 d:00007F7F72B3D1D0 2016/10/28 09:53:03 [debug] 15747#0: 29 http upstream request: "/index.php?" 2016/10/28 09:53:03 [debug] 15747#0: 29 http upstream process upstream 2016/10/28 09:53:03 [debug] 15747#0: 29 pipe read upstream: 1 2016/10/28 09:53:03 [debug] 15747#0: 29 readv: 1, last:3968 2016/10/28 09:53:03 [debug] 15747#0: 29 pipe recv chain: 0 2016/10/28 09:53:03 [debug] 15747#0: 29 pipe buf free s:0 t:1 f:0 0000000000FCB970, pos 0000000000FCB9DF, size: 17 file: 0, size: 0 2016/10/28 09:53:03 [debug] 15747#0: 29 pipe length: -1 2016/10/28 09:53:03 [debug] 15747#0: 29 http fastcgi record byte: 01 2016/10/28 09:53:03 [debug] 15747#0: 29 http fastcgi record byte: 03 2016/10/28 09:53:03 [debug] 15747#0: 29 http fastcgi record byte: 00 2016/10/28 09:53:03 [debug] 15747#0: 29 http fastcgi record byte: 01 2016/10/28 09:53:03 [debug] 15747#0: 29 http fastcgi record byte: 00 2016/10/28 09:53:03 [debug] 15747#0: 29 http fastcgi record byte: 08 2016/10/28 09:53:03 [debug] 15747#0: 29 http fastcgi record byte: 00 2016/10/28 09:53:03 [debug] 15747#0: 29 http fastcgi record byte: 00 2016/10/28 09:53:03 [debug] 15747#0: 29 http fastcgi record length: 8 2016/10/28 09:53:03 [debug] 15747#0: 29 http fastcgi sent end request 2016/10/28 09:53:03 [debug] 15747#0: 29 free: 0000000000FCB970 2016/10/28 09:53:03 [debug] 15747#0: 29 pipe write downstream: 1 2016/10/28 09:53:03 [debug] 15747#0: 29 pipe write downstream done 2016/10/28 09:53:03 [debug] 15747#0: 29 event timer: 13, old: 1477666983274, new: 1477666983411 2016/10/28 09:53:03 [debug] 15747#0: 29 http upstream exit: 0000000000000000 2016/10/28 09:53:03 [debug] 15747#0: 29 finalize http upstream request: 0 2016/10/28 09:53:03 [debug] 15747#0: 29 finalize http fastcgi request 2016/10/28 09:53:03 [debug] 15747#0: 29 free rr peer 1 0 2016/10/28 09:53:03 [debug] 15747#0: 29 close http upstream connection: 13 2016/10/28 09:53:03 [debug] 15747#0: 29 free: 0000000000FF2E50, unused: 48 2016/10/28 09:53:03 [debug] 15747#0: 29 event timer del: 13: 1477666983274 2016/10/28 09:53:03 [debug] 15747#0: 29 reusable connection: 0 2016/10/28 09:53:03 [debug] 15747#0: 29 http upstream temp fd: -1 2016/10/28 09:53:03 [debug] 15747#0: 29 http output filter "/index.php?" 2016/10/28 09:53:03 [debug] 15747#0: 29 http copy filter: "/index.php?" 2016/10/28 09:53:03 [debug] 15747#0: 29 image filter 2016/10/28 09:53:03 [debug] 15747#0: 29 xslt filter body 2016/10/28 09:53:03 [debug] 15747#0: 29 http postpone filter "/index.php?" 00007FFF15557D90 2016/10/28 09:53:03 [debug] 15747#0: 29 http chunk: 0 2016/10/28 09:53:03 [debug] 15747#0: 29 write old buf t:1 f:0 0000000000F40A60, pos 0000000000F40A60, size: 215 file: 0, size: 0 2016/10/28 09:53:03 [debug] 15747#0: 29 write new buf t:0 f:0 0000000000000000, pos 00000000004BA603, size: 5 file: 0, size: 0 2016/10/28 09:53:03 [debug] 15747#0: 29 http write filter: l:1 f:0 s:220 2016/10/28 09:53:03 [debug] 15747#0: 29 http write filter limit 0 2016/10/28 09:53:03 [debug] 15747#0: 29 writev: 220 of 220 2016/10/28 09:53:03 [debug] 15747#0: 29 http write filter 0000000000000000 2016/10/28 09:53:03 [debug] 15747#0: 29 http copy filter: 0 "/index.php?" 2016/10/28 09:53:03 [debug] 15747#0: 29 http finalize request: 0, "/index.php?" a:1, c:1 2016/10/28 09:53:03 [debug] 15747#0: 29 set http keepalive handler 2016/10/28 09:53:03 [debug] 15747#0: 29 http close request 2016/10/28 09:53:03 [debug] 15747#0: 29 http log handler 2016/10/28 09:53:03 [debug] 15747#0: 29 free: 0000000000000000 2016/10/28 09:53:03 [debug] 15747#0: 29 free: 0000000000F46F60, unused: 0 2016/10/28 09:53:03 [debug] 15747#0: 29 free: 0000000000FCD7C0, unused: 8 2016/10/28 09:53:03 [debug] 15747#0: 29 free: 0000000000F40870, unused: 2600 2016/10/28 09:53:03 [debug] 15747#0: 29 free: 0000000000F3C2F0 2016/10/28 09:53:03 [debug] 15747#0: 29 hc free: 0000000000000000 0 2016/10/28 09:53:03 [debug] 15747#0: 29 hc busy: 0000000000000000 0 2016/10/28 09:53:03 [debug] 15747#0: 29 tcp_nodelay 2016/10/28 09:53:03 [debug] 15747#0: 29 reusable connection: 1 2016/10/28 09:53:03 [debug] 15747#0: 29 event timer add: 4: 65000:1477666448411 2016/10/28 09:53:03 [debug] 15747#0: 29 post event 000000000103F2E0 2016/10/28 09:53:03 [debug] 15747#0: timer delta: 3 2016/10/28 09:53:03 [debug] 15747#0: posted event 000000000103F2E0 2016/10/28 09:53:03 [debug] 15747#0: 29 delete posted event 000000000103F2E0 2016/10/28 09:53:03 [debug] 15747#0: 29 http keepalive handler 2016/10/28 09:53:03 [debug] 15747#0: 29 malloc: 0000000000F3C2F0:1024 2016/10/28 09:53:03 [debug] 15747#0: 29 recv: fd:4 -1 of 1024 2016/10/28 09:53:03 [debug] 15747#0: 29 recv() not ready (11: Resource temporarily unavailable) 2016/10/28 09:53:03 [debug] 15747#0: 29 free: 0000000000F3C2F0 2016/10/28 09:53:03 [debug] 15747#0: worker cycle 2016/10/28 09:53:03 [debug] 15747#0: epoll timer: 59862 2016/10/28 09:53:04 [debug] 15747#0: epoll: fd:4 ev:0005 d:00007F7F72B3D390 2016/10/28 09:53:04 [debug] 15747#0: 29 http keepalive handler 2016/10/28 09:53:04 [debug] 15747#0: 29 malloc: 0000000000F3C2F0:1024 2016/10/28 09:53:04 [debug] 15747#0: 29 recv: fd:4 411 of 1024 2016/10/28 09:53:04 [debug] 15747#0: 29 reusable connection: 0 2016/10/28 09:53:04 [debug] 15747#0: 29 posix_memalign: 0000000000FCD7C0:4096 @16 2016/10/28 09:53:04 [debug] 15747#0: 29 event timer del: 4: 1477666448411 2016/10/28 09:53:04 [debug] 15747#0: 29 http process request line 2016/10/28 09:53:04 [debug] 15747#0: 29 http request line: "GET /index.html HTTP/1.1" 2016/10/28 09:53:04 [debug] 15747#0: 29 http uri: "/index.html" 2016/10/28 09:53:04 [debug] 15747#0: 29 http args: "" 2016/10/28 09:53:04 [debug] 15747#0: 29 http exten: "html" 2016/10/28 09:53:04 [debug] 15747#0: 29 posix_memalign: 0000000000F46F60:4096 @16 2016/10/28 09:53:04 [debug] 15747#0: 29 http process request header line 2016/10/28 09:53:04 [debug] 15747#0: 29 http header: "Host: 10.235.32.10" 2016/10/28 09:53:04 [debug] 15747#0: 29 http header: "Connection: keep-alive" 2016/10/28 09:53:04 [debug] 15747#0: 29 http header: "Cache-Control: max-age=0" 2016/10/28 09:53:04 [debug] 15747#0: 29 http header: "Upgrade-Insecure-Requests: 1" 2016/10/28 09:53:04 [debug] 15747#0: 29 http header: "User-Agent: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/54.0.2840.71 Safari/537.36" 2016/10/28 09:53:04 [debug] 15747#0: 29 http header: "Accept: text/html,application/xhtml+xml,application/xml;q=0.9,image/webp,/;q=0.8" 2016/10/28 09:53:04 [debug] 15747#0: 29 http header: "Accept-Encoding: gzip, deflate, sdch" 2016/10/28 09:53:04 [debug] 15747#0: 29 http header: "Accept-Language: en-US,en;q=0.8" 2016/10/28 09:53:04 [debug] 15747#0: 29 http header done 2016/10/28 09:53:04 [debug] 15747#0: 29 generic phase: 0 2016/10/28 09:53:04 [debug] 15747#0: 29 rewrite phase: 1 2016/10/28 09:53:04 [debug] 15747#0: 29 http script value: "/var/www/html/magento2" 2016/10/28 09:53:04 [debug] 15747#0: 29 http script set $mage_root 2016/10/28 09:53:04 [debug] 15747#0: 29 http script value: "developer" 2016/10/28 09:53:04 [debug] 15747#0: 29 http script set $mage_mode 2016/10/28 09:53:04 [debug] 15747#0: 29 test location: "/" 2016/10/28 09:53:04 [debug] 15747#0: 29 test location: "pub/" 2016/10/28 09:53:04 [debug] 15747#0: 29 test location: "media/" 2016/10/28 09:53:04 [debug] 15747#0: 29 test location: ~ "^/setup($|/)" 2016/10/28 09:53:04 [debug] 15747#0: 29 test location: ~ "^/update($|/)" 2016/10/28 09:53:04 [debug] 15747#0: 29 test location: ~ "(index|get|static|report|404|503).php$" 2016/10/28 09:53:04 [debug] 15747#0: 29 test location: ~ "(.php$|.htaccess$|.git)" 2016/10/28 09:53:04 [debug] 15747#0: 29 using configuration "/" 2016/10/28 09:53:04 [debug] 15747#0: 29 http cl:-1 max:1048576 2016/10/28 09:53:04 [debug] 15747#0: 29 rewrite phase: 3 2016/10/28 09:53:04 [debug] 15747#0: 29 post rewrite phase: 4 2016/10/28 09:53:04 [debug] 15747#0: 29 generic phase: 5 2016/10/28 09:53:04 [debug] 15747#0: 29 generic phase: 6 2016/10/28 09:53:04 [debug] 15747#0: 29 generic phase: 7 2016/10/28 09:53:04 [debug] 15747#0: 29 generic phase: 8 2016/10/28 09:53:04 [debug] 15747#0: 29 access phase: 9 2016/10/28 09:53:04 [debug] 15747#0: 29 access phase: 10 2016/10/28 09:53:04 [debug] 15747#0: 29 post access phase: 11 2016/10/28 09:53:04 [debug] 15747#0: 29 try files phase: 12 2016/10/28 09:53:04 [debug] 15747#0: 29 http script var: "/var/www/html/magento2" 2016/10/28 09:53:04 [debug] 15747#0: 29 http script copy: "/pub" 2016/10/28 09:53:04 [debug] 15747#0: 29 http script var: "/index.html" 2016/10/28 09:53:04 [debug] 15747#0: 29 trying to use file: "/index.html" "/var/www/html/magento2/pub/index.html" 2016/10/28 09:53:04 [debug] 15747#0: 29 http script var: "/index.html" 2016/10/28 09:53:04 [debug] 15747#0: 29 trying to use dir: "/index.html" "/var/www/html/magento2/pub/index.html" 2016/10/28 09:53:04 [debug] 15747#0: 29 http script copy: "/index.php?" 2016/10/28 09:53:04 [debug] 15747#0: 29 trying to use file: "/index.php?" "/var/www/html/magento2/pub/index.php?" 2016/10/28 09:53:04 [debug] 15747#0: 29 internal redirect: "/index.php?" 2016/10/28 09:53:04 [debug] 15747#0: 29 rewrite phase: 1 2016/10/28 09:53:04 [debug] 15747#0: 29 http script value: "/var/www/html/magento2" 2016/10/28 09:53:04 [debug] 15747#0: 29 http script set $mage_root 2016/10/28 09:53:04 [debug] 15747#0: 29 http script value: "developer" 2016/10/28 09:53:04 [debug] 15747#0: 29 http script set $mage_mode 2016/10/28 09:53:04 [debug] 15747#0: 29 test location: "/" 2016/10/28 09:53:04 [debug] 15747#0: 29 test location: "pub/" 2016/10/28 09:53:04 [debug] 15747#0: 29 test location: "media/" 2016/10/28 09:53:04 [debug] 15747#0: 29 test location: ~ "^/setup($|/)" 2016/10/28 09:53:04 [debug] 15747#0: 29 test location: ~ "^/update($|/)" 2016/10/28 09:53:04 [debug] 15747#0: 29 test location: ~ "(index|get|static|report|404|503).php$" 2016/10/28 09:53:04 [debug] 15747#0: 29 using configuration "(index|get|static|report|404|503).php$" 2016/10/28 09:53:04 [debug] 15747#0: 29 http cl:-1 max:1048576 2016/10/28 09:53:04 [debug] 15747#0: 29 rewrite phase: 3 2016/10/28 09:53:04 [debug] 15747#0: 29 post rewrite phase: 4 2016/10/28 09:53:04 [debug] 15747#0: 29 generic phase: 5 2016/10/28 09:53:04 [debug] 15747#0: 29 generic phase: 6 2016/10/28 09:53:04 [debug] 15747#0: 29 generic phase: 7 2016/10/28 09:53:04 [debug] 15747#0: 29 generic phase: 8 2016/10/28 09:53:04 [debug] 15747#0: 29 access phase: 9 2016/10/28 09:53:04 [debug] 15747#0: 29 access phase: 10 2016/10/28 09:53:04 [debug] 15747#0: 29 post access phase: 11 2016/10/28 09:53:04 [debug] 15747#0: 29 try files phase: 12 2016/10/28 09:53:04 [debug] 15747#0: 29 http script var: "/var/www/html/magento2" 2016/10/28 09:53:04 [debug] 15747#0: 29 http script copy: "/pub" 2016/10/28 09:53:04 [debug] 15747#0: 29 http script var: "/index.php" 2016/10/28 09:53:04 [debug] 15747#0: 29 trying to use file: "/index.php" "/var/www/html/magento2/pub/index.php" 2016/10/28 09:53:04 [debug] 15747#0: 29 try file uri: "/index.php" 2016/10/28 09:53:04 [debug] 15747#0: 29 http init upstream, client timer: 0 2016/10/28 09:53:04 [debug] 15747#0: 29 http script var: "/var/www/html/magento2" 2016/10/28 09:53:04 [debug] 15747#0: 29 http script copy: "/pub" 2016/10/28 09:53:04 [debug] 15747#0: 29 http script copy: "PHP_FLAG" 2016/10/28 09:53:04 [debug] 15747#0: 29 http script copy: "session.auto_start=off suhosin.session.cryptua=off" 2016/10/28 09:53:04 [debug] 15747#0: 29 fastcgi param: "PHP_FLAG: session.auto_start=off suhosin.session.cryptua=off" 2016/10/28 09:53:04 [debug] 15747#0: 29 http script copy: "PHP_VALUE" 2016/10/28 09:53:04 [debug] 15747#0: 29 http script copy: "memory_limit=768M max_execution_time=600" 2016/10/28 09:53:04 [debug] 15747#0: 29 fastcgi param: "PHP_VALUE: memory_limit=768M max_execution_time=600" 2016/10/28 09:53:04 [debug] 15747#0: 29 http script copy: "SCRIPT_FILENAME" 2016/10/28 09:53:04 [debug] 15747#0: 29 http script var: "/var/www/html/magento2/pub" 2016/10/28 09:53:04 [debug] 15747#0: 29 http script var: "/index.php" 2016/10/28 09:53:04 [debug] 15747#0: 29 fastcgi param: "SCRIPT_FILENAME: /var/www/html/magento2/pub/index.php" 2016/10/28 09:53:04 [debug] 15747#0: 29 http script copy: "QUERY_STRING" 2016/10/28 09:53:04 [debug] 15747#0: 29 http script var: "" 2016/10/28 09:53:04 [debug] 15747#0: 29 fastcgi param: "QUERY_STRING: " 2016/10/28 09:53:04 [debug] 15747#0: 29 http script copy: "REQUEST_METHOD" 2016/10/28 09:53:04 [debug] 15747#0: 29 http script var: "GET" 2016/10/28 09:53:04 [debug] 15747#0: 29 fastcgi param: "REQUEST_METHOD: GET" 2016/10/28 09:53:04 [debug] 15747#0: 29 http script copy: "CONTENT_TYPE" 2016/10/28 09:53:04 [debug] 15747#0: 29 fastcgi param: "CONTENT_TYPE: " 2016/10/28 09:53:04 [debug] 15747#0: 29 http script copy: "CONTENT_LENGTH" 2016/10/28 09:53:04 [debug] 15747#0: 29 fastcgi param: "CONTENT_LENGTH: " 2016/10/28 09:53:04 [debug] 15747#0: 29 http script copy: "SCRIPT_NAME" 2016/10/28 09:53:04 [debug] 15747#0: 29 http script var: "/index.php" 2016/10/28 09:53:04 [debug] 15747#0: 29 fastcgi param: "SCRIPT_NAME: /index.php" 2016/10/28 09:53:04 [debug] 15747#0: 29 http script copy: "REQUEST_URI" 2016/10/28 09:53:04 [debug] 15747#0: 29 http script var: "/index.html" 2016/10/28 09:53:04 [debug] 15747#0: 29 fastcgi param: "REQUEST_URI: /index.html" 2016/10/28 09:53:04 [debug] 15747#0: 29 http script copy: "DOCUMENT_URI" 2016/10/28 09:53:04 [debug] 15747#0: 29 http script var: "/index.php" 2016/10/28 09:53:04 [debug] 15747#0: 29 fastcgi param: "DOCUMENT_URI: /index.php" 2016/10/28 09:53:04 [debug] 15747#0: 29 http script copy: "DOCUMENT_ROOT" 2016/10/28 09:53:04 [debug] 15747#0: 29 http script var: "/var/www/html/magento2/pub" 2016/10/28 09:53:04 [debug] 15747#0: 29 fastcgi param: "DOCUMENT_ROOT: /var/www/html/magento2/pub" 2016/10/28 09:53:04 [debug] 15747#0: 29 http script copy: "SERVER_PROTOCOL" 2016/10/28 09:53:04 [debug] 15747#0: 29 http script var: "HTTP/1.1" 2016/10/28 09:53:04 [debug] 15747#0: 29 fastcgi param: "SERVER_PROTOCOL: HTTP/1.1" 2016/10/28 09:53:04 [debug] 15747#0: 29 http script copy: "REQUEST_SCHEME" 2016/10/28 09:53:04 [debug] 15747#0: 29 http script var: "http" 2016/10/28 09:53:04 [debug] 15747#0: 29 fastcgi param: "REQUEST_SCHEME: http" 2016/10/28 09:53:04 [debug] 15747#0: 29 http script copy: "" 2016/10/28 09:53:04 [debug] 15747#0: 29 http script copy: "GATEWAY_INTERFACE" 2016/10/28 09:53:04 [debug] 15747#0: 29 http script copy: "CGI/1.1" 2016/10/28 09:53:04 [debug] 15747#0: 29 fastcgi param: "GATEWAY_INTERFACE: CGI/1.1" 2016/10/28 09:53:04 [debug] 15747#0: 29 http script copy: "SERVER_SOFTWARE" 2016/10/28 09:53:04 [debug] 15747#0: 29 http script copy: "nginx/" 2016/10/28 09:53:04 [debug] 15747#0: 29 http script var: "1.10.1" 2016/10/28 09:53:04 [debug] 15747#0: 29 fastcgi param: "SERVER_SOFTWARE: nginx/1.10.1" 2016/10/28 09:53:04 [debug] 15747#0: 29 http script copy: "REMOTE_ADDR" 2016/10/28 09:53:04 [debug] 15747#0: 29 http script var: "10.235.34.14" 2016/10/28 09:53:04 [debug] 15747#0: 29 fastcgi param: "REMOTE_ADDR: 10.235.34.14" 2016/10/28 09:53:04 [debug] 15747#0: 29 http script copy: "REMOTE_PORT" 2016/10/28 09:53:04 [debug] 15747#0: 29 http script var: "51165" 2016/10/28 09:53:04 [debug] 15747#0: 29 fastcgi param: "REMOTE_PORT: 51165" 2016/10/28 09:53:04 [debug] 15747#0: 29 http script copy: "SERVER_ADDR" 2016/10/28 09:53:04 [debug] 15747#0: 29 http script var: "10.235.32.10" 2016/10/28 09:53:04 [debug] 15747#0: 29 fastcgi param: "SERVER_ADDR: 10.235.32.10" 2016/10/28 09:53:04 [debug] 15747#0: 29 http script copy: "SERVER_PORT" 2016/10/28 09:53:04 [debug] 15747#0: 29 http script var: "80" 2016/10/28 09:53:04 [debug] 15747#0: 29 fastcgi param: "SERVER_PORT: 80" 2016/10/28 09:53:04 [debug] 15747#0: 29 http script copy: "SERVER_NAME" 2016/10/28 09:53:04 [debug] 15747#0: 29 http script var: "mage.dev" 2016/10/28 09:53:04 [debug] 15747#0: 29 fastcgi param: "SERVER_NAME: mage.dev" 2016/10/28 09:53:04 [debug] 15747#0: 29 http script copy: "REDIRECT_STATUS" 2016/10/28 09:53:04 [debug] 15747#0: 29 http script copy: "200" 2016/10/28 09:53:04 [debug] 15747#0: 29 fastcgi param: "REDIRECT_STATUS: 200" 2016/10/28 09:53:04 [debug] 15747#0: 29 fastcgi param: "HTTP_HOST: 10.235.32.10" 2016/10/28 09:53:04 [debug] 15747#0: 29 fastcgi param: "HTTP_CONNECTION: keep-alive" 2016/10/28 09:53:04 [debug] 15747#0: 29 fastcgi param: "HTTP_CACHE_CONTROL: max-age=0" 2016/10/28 09:53:04 [debug] 15747#0: 29 fastcgi param: "HTTP_UPGRADE_INSECURE_REQUESTS: 1" 2016/10/28 09:53:04 [debug] 15747#0: 29 fastcgi param: "HTTP_USER_AGENT: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/54.0.2840.71 Safari/537.36" 2016/10/28 09:53:04 [debug] 15747#0: 29 fastcgi param: "HTTPACCEPT: text/html,application/xhtml+xml,application/xml;q=0.9,image/webp,/;q=0.8" 2016/10/28 09:53:04 [debug] 15747#0: 29 fastcgi param: "HTTP_ACCEPT_ENCODING: gzip, deflate, sdch" 2016/10/28 09:53:04 [debug] 15747#0: 29 fastcgi param: "HTTP_ACCEPT_LANGUAGE: en-US,en;q=0.8" 2016/10/28 09:53:04 [debug] 15747#0: 29 http cleanup add: 0000000000F47E40 2016/10/28 09:53:04 [debug] 15747#0: 29 get rr peer, try: 1 2016/10/28 09:53:04 [debug] 15747#0: 29 stream socket 13 2016/10/28 09:53:04 [debug] 15747#0: 29 epoll add connection: fd:13 ev:80002005 2016/10/28 09:53:04 [debug] 15747#0: 29 connect to 127.0.0.1:9000, fd:13 #36 2016/10/28 09:53:04 [debug] 15747#0: 29 http upstream connect: -2 2016/10/28 09:53:04 [debug] 15747#0: 29 posix_memalign: 0000000000FF2E50:128 @16 2016/10/28 09:53:04 [debug] 15747#0: 29 event timer add: 13: 600000:1477666984693 2016/10/28 09:53:04 [debug] 15747#0: 29 http finalize request: -4, "/index.php?" a:1, c:3 2016/10/28 09:53:04 [debug] 15747#0: 29 http request count:3 blk:0 2016/10/28 09:53:04 [debug] 15747#0: 29 http finalize request: -4, "/index.php?" a:1, c:2 2016/10/28 09:53:04 [debug] 15747#0: 29 http request count:2 blk:0 2016/10/28 09:53:04 [debug] 15747#0: 29 http run request: "/index.php?" 2016/10/28 09:53:04 [debug] 15747#0: 29 http upstream check client, write event:1, "/index.php" 2016/10/28 09:53:04 [debug] 15747#0: 29 http upstream recv(): -1 (11: Resource temporarily unavailable) 2016/10/28 09:53:04 [debug] 15747#0: timer delta: 1282 2016/10/28 09:53:04 [debug] 15747#0: worker cycle 2016/10/28 09:53:04 [debug] 15747#0: epoll timer: 58580 2016/10/28 09:53:04 [debug] 15747#0: epoll: fd:13 ev:0004 d:00007F7F72B3D1D1 2016/10/28 09:53:04 [debug] 15747#0: 29 http upstream request: "/index.php?" 2016/10/28 09:53:04 [debug] 15747#0: 29 http upstream send request handler 2016/10/28 09:53:04 [debug] 15747#0: 29 http upstream send request 2016/10/28 09:53:04 [debug] 15747#0: 29 http upstream send request body 2016/10/28 09:53:04 [debug] 15747#0: 29 chain writer buf fl:0 s:1016 2016/10/28 09:53:04 [debug] 15747#0: 29 chain writer in: 0000000000F47E78 2016/10/28 09:53:04 [debug] 15747#0: 29 writev: 1016 of 1016 2016/10/28 09:53:04 [debug] 15747#0: 29 chain writer out: 0000000000000000 2016/10/28 09:53:04 [debug] 15747#0: 29 event timer del: 13: 1477666984693 2016/10/28 09:53:04 [debug] 15747#0: 29 event timer add: 13: 600000:1477666984694 2016/10/28 09:53:04 [debug] 15747#0: timer delta: 1 2016/10/28 09:53:04 [debug] 15747#0: worker cycle 2016/10/28 09:53:04 [debug] 15747#0: epoll timer: 58579 2016/10/28 09:53:04 [debug] 15747#0: epoll: fd:13 ev:0005 d:00007F7F72B3D1D1 2016/10/28 09:53:04 [debug] 15747#0: 29 http upstream request: "/index.php?" 2016/10/28 09:53:04 [debug] 15747#0: 29 http upstream process header 2016/10/28 09:53:04 [debug] 15747#0: 29 malloc: 0000000000FCB970:4096 2016/10/28 09:53:04 [debug] 15747#0: 29 posix_memalign: 0000000000F40870:4096 @16 2016/10/28 09:53:04 [debug] 15747#0: 29 recv: fd:13 128 of 4096 2016/10/28 09:53:04 [debug] 15747#0: 29 http fastcgi record byte: 01 2016/10/28 09:53:04 [debug] 15747#0: 29 http fastcgi record byte: 06 2016/10/28 09:53:04 [debug] 15747#0: 29 http fastcgi record byte: 00 2016/10/28 09:53:04 [debug] 15747#0: 29 http fastcgi record byte: 01 2016/10/28 09:53:04 [debug] 15747#0: 29 http fastcgi record byte: 00 2016/10/28 09:53:04 [debug] 15747#0: 29 http fastcgi record byte: 67 2016/10/28 09:53:04 [debug] 15747#0: 29 http fastcgi record byte: 01 2016/10/28 09:53:04 [debug] 15747#0: 29 http fastcgi record byte: 00 2016/10/28 09:53:04 [debug] 15747#0: 29 http fastcgi record length: 103 2016/10/28 09:53:04 [debug] 15747#0: 29 http fastcgi parser: 0 2016/10/28 09:53:04 [debug] 15747#0: 29 http fastcgi header: "Status: 500 Internal Server Error" 2016/10/28 09:53:04 [debug] 15747#0: 29 http fastcgi parser: 0 2016/10/28 09:53:04 [debug] 15747#0: 29 http fastcgi header: "X-Powered-By: PHP/5.6.26" 2016/10/28 09:53:04 [debug] 15747#0: 29 http fastcgi parser: 0 2016/10/28 09:53:04 [debug] 15747#0: 29 http fastcgi header: "Content-type: text/html; charset=UTF-8" 2016/10/28 09:53:04 [debug] 15747#0: 29 http fastcgi parser: 1 2016/10/28 09:53:04 [debug] 15747#0: 29 http fastcgi header done 2016/10/28 09:53:04 [debug] 15747#0: 29 xslt filter header 2016/10/28 09:53:04 [debug] 15747#0: 29 HTTP/1.1 500 Internal Server Error

ghost commented 8 years ago

access.log:

10.235.34.14 - - [28/Oct/2016:09:53:53 -0500] "GET /index.html HTTP/1.1" 500 5 "-" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/54.0.2840.71 Safari/537.36" "-"

pantaoran commented 8 years ago

In that case I'm going to have to disappoint you, I never had to go down to debug level from what I can remember. Is php-fpm getting called (is it executing any code)? If nginx info doesn't show anything then I would look more at php to find problems...

ghost commented 8 years ago

Don't worry about it... For whatever reason, if I set log level to info, nothing is logged. Sat with a developer yesterday, he came to the same conclusion you did about php-fpm.

The above was using CentOS 6 and nginx 1.10. What are you using?

I'm trying now on Ubuntu 16 with nginx 1.4.

pantaoran commented 8 years ago

I'm running this in Ubuntu 14.04 based docker containers, the host is running Debian jessie.

Nginx is mostly 1.8, sometimes 1.10, your 1.4 sounds really old.

php-fpm 7.0.12

ghost commented 8 years ago

I'm getting tantalizingly close. Using an internal Vagrant image to get nginx working and the default nginx.conf.sample, I first got a 404 running cron.php in the browser. Now I'm getting an exception. I'll let you know if I can get it working.

jeff-matthews commented 7 years ago

The previous author (ghost) digressed from the original issue and focused instead on documenting how to get a Magento + nginx instance up and running. That documentation was also incomplete.

I created PR 1047 in the devdocs_internal/ repo, which includes complete instructions for setting up magento on nginx (see issue #460).

I'll create a separate branch to address the reported issue related to configuring the location block for securing cron.php.

jeff-matthews commented 7 years ago

Doc updates are live: http://devdocs.magento.com/guides/v2.2/config-guide/secy/secy-cron.html