Strange issue after nginx update

classic Classic list List threaded Threaded
14 messages Options
Reply | Threaded
Open this post in threaded view
|

Strange issue after nginx update

Andrea Soracchi-2
Hi,
could you please help me solve this issue? I'm getting crazy!

Before the nginx update my client worked perfectly: it posted files to my website without any delay.

How, after nginx update (ubuntu 16.04 LTS) I've got this issue:

- the client posts files successfully but the answer of the post is delayed. The more the file is bigger, the more the answer is delayed.

I put a sniffer into the website' server and I noticed that the nginx receives the post but it waits to transfer the file to php-fpm process, so also the answer to the client is delayed

The nginx server is:

nginx/1.10.0 (Ubuntu) and its conf is:

-----
user www-data;
worker_processes auto;
pid /run/nginx.pid;

events {
        worker_connections 768;
        # multi_accept on;
}

http {
        sendfile on;
        tcp_nodelay on;
        keepalive_timeout 65;
        types_hash_max_size 2048;
        client_max_body_size 0;
        log_not_found off;
        server_name_in_redirect off;
        client_body_timeout 120s;
        autoindex off;
        include /etc/nginx/mime.types;
        default_type application/octet-stream;
        ssl_protocols TLSv1 TLSv1.1 TLSv1.2; # Dropping SSLv3, ref: POODLE
        ssl_prefer_server_ciphers on;
        access_log /var/log/nginx/access.log;
        error_log /var/log/nginx/error.log info;
        gzip on;
        gzip_disable "msie6";
        gzip_types text/plain text/css application/json application/javascript text/xml application/xml application/xml+rss text/javascript;
        include /etc/nginx/conf.d/*.conf;
        include /etc/nginx/sites-enabled/*;
---

and website's php-fpm conf is:

server {
  listen                    80;
  server_name               test.it;
  server_name_in_redirect   off;
  autoindex                 off;
  client_max_body_size      500m;
  index                     index.html;
  root                      /home/test/test;
  location ~ \.(php|html|htm|php3)$ {
    try_files     $uri 404;
    fastcgi_pass  unix:/run/php/mdtest-fpm.sock;
    include       fastcgi_params;
  }
}

fastcgi_params config:

fastcgi_param  QUERY_STRING       $query_string;
fastcgi_param  REQUEST_METHOD     $request_method;
fastcgi_param  CONTENT_TYPE       $content_type;
fastcgi_param  CONTENT_LENGTH     $content_length;

fastcgi_param  SCRIPT_NAME        $fastcgi_script_name;
fastcgi_param  REQUEST_URI        $request_uri;
fastcgi_param  DOCUMENT_URI       $document_uri;
fastcgi_param  DOCUMENT_ROOT      $document_root;
fastcgi_param  SERVER_PROTOCOL    $server_protocol;
fastcgi_param  REQUEST_SCHEME     $scheme;
fastcgi_param  HTTPS              $https if_not_empty;

fastcgi_param  GATEWAY_INTERFACE  CGI/1.1;
fastcgi_param  SERVER_SOFTWARE    nginx/$nginx_version;

fastcgi_param  REMOTE_ADDR        $remote_addr;
fastcgi_param  REMOTE_PORT        $remote_port;
fastcgi_param  SERVER_ADDR        $server_addr;
fastcgi_param  SERVER_PORT        $server_port;
#fastcgi_param  SERVER_NAME        $server_name;
fastcgi_param  SERVER_NAME       $http_host;

# PHP only, required if PHP was built with --enable-force-cgi-redirect
fastcgi_param  REDIRECT_STATUS    200;

fastcgi_param SCRIPT_FILENAME     $document_root$fastcgi_script_name;


Thanks a lot,
Andrea

ANDREA SORACCHI
<a href="tel:+393290512702" style="text-decoration: none; color: rgb(17, 37, 75);" data-mce-href="tel:+393290512702" data-mce-style="text-decoration: none; color: #11254b;">+39 329 0512704
System Engineer

+39 0521 24 77 91
[hidden email]



_______________________________________________
nginx mailing list
[hidden email]
http://mailman.nginx.org/mailman/listinfo/nginx
Reply | Threaded
Open this post in threaded view
|

Re: Strange issue after nginx update

Payam Chychi

On Wed, Jun 28, 2017 at 8:41 AM Andrea Soracchi <[hidden email]> wrote:
Hi,
could you please help me solve this issue? I'm getting crazy!

Before the nginx update my client worked perfectly: it posted files to my website without any delay.

How, after nginx update (ubuntu 16.04 LTS) I've got this issue:

- the client posts files successfully but the answer of the post is delayed. The more the file is bigger, the more the answer is delayed.

I put a sniffer into the website' server and I noticed that the nginx receives the post but it waits to transfer the file to php-fpm process, so also the answer to the client is delayed

The nginx server is:

nginx/1.10.0 (Ubuntu) and its conf is:

-----
user www-data;
worker_processes auto;
pid /run/nginx.pid;

events {
        worker_connections 768;
        # multi_accept on;
}

http {
        sendfile on;
        tcp_nodelay on;
        keepalive_timeout 65;
        types_hash_max_size 2048;
        client_max_body_size 0;
        log_not_found off;
        server_name_in_redirect off;
        client_body_timeout 120s;
        autoindex off;
        include /etc/nginx/mime.types;
        default_type application/octet-stream;
        ssl_protocols TLSv1 TLSv1.1 TLSv1.2; # Dropping SSLv3, ref: POODLE
        ssl_prefer_server_ciphers on;
        access_log /var/log/nginx/access.log;
        error_log /var/log/nginx/error.log info;
        gzip on;
        gzip_disable "msie6";
        gzip_types text/plain text/css application/json application/javascript text/xml application/xml application/xml+rss text/javascript;
        include /etc/nginx/conf.d/*.conf;
        include /etc/nginx/sites-enabled/*;
---

and website's php-fpm conf is:

server {
  listen                    80;
  server_name               test.it;
  server_name_in_redirect   off;
  autoindex                 off;
  client_max_body_size      500m;
  index                     index.html;
  root                      /home/test/test;
  location ~ \.(php|html|htm|php3)$ {
    try_files     $uri 404;
    fastcgi_pass  unix:/run/php/mdtest-fpm.sock;
    include       fastcgi_params;
  }
}

fastcgi_params config:

fastcgi_param  QUERY_STRING       $query_string;
fastcgi_param  REQUEST_METHOD     $request_method;
fastcgi_param  CONTENT_TYPE       $content_type;
fastcgi_param  CONTENT_LENGTH     $content_length;

fastcgi_param  SCRIPT_NAME        $fastcgi_script_name;
fastcgi_param  REQUEST_URI        $request_uri;
fastcgi_param  DOCUMENT_URI       $document_uri;
fastcgi_param  DOCUMENT_ROOT      $document_root;
fastcgi_param  SERVER_PROTOCOL    $server_protocol;
fastcgi_param  REQUEST_SCHEME     $scheme;
fastcgi_param  HTTPS              $https if_not_empty;

fastcgi_param  GATEWAY_INTERFACE  CGI/1.1;
fastcgi_param  SERVER_SOFTWARE    nginx/$nginx_version;

fastcgi_param  REMOTE_ADDR        $remote_addr;
fastcgi_param  REMOTE_PORT        $remote_port;
fastcgi_param  SERVER_ADDR        $server_addr;
fastcgi_param  SERVER_PORT        $server_port;
#fastcgi_param  SERVER_NAME        $server_name;
fastcgi_param  SERVER_NAME       $http_host;

# PHP only, required if PHP was built with --enable-force-cgi-redirect
fastcgi_param  REDIRECT_STATUS    200;

fastcgi_param SCRIPT_FILENAME     $document_root$fastcgi_script_name;


Thanks a lot,
Andrea

ANDREA SORACCHI
<a href="tel:+393290512702" style="text-decoration:none;color:rgb(17,37,75)" target="_blank">+39 329 0512704
System Engineer

+39 0521 24 77 91
[hidden email]


_______________________________________________
nginx mailing list
[hidden email]
http://mailman.nginx.org/mailman/listinfo/nginx

hi,

can you show the related wireshark data, how long is the response delayed by? and anything else like retransmits or anything else?

any SElinux security throtelling taking place? anything in dmesg?

--
Payam Tarverdyan Chychi
Network Security Specialist / Network Engineer

_______________________________________________
nginx mailing list
[hidden email]
http://mailman.nginx.org/mailman/listinfo/nginx
Reply | Threaded
Open this post in threaded view
|

Re: Strange issue after nginx update

Andrea Soracchi-2
In reply to this post by Andrea Soracchi-2
Hi,

I have attached part of the ettercap log.

I have posted a test file of 40MB.

The delay  is 29 second:

 from the last file's chunk at 23:56:06
 
 to the response of  index2.php at 23:56:35

The nginx's log show:

192.168.18.18 - - [28/Jun/2017:23:56:35 +0200] "POST /index2.php HTTP/1.1" 200 37 "-" "Generic Client"

Nothing retransmits, SElinux isn't installed and apparmor is stopped.

Nothing in dmesg...

Thanks a lot,


ANDREA SORACCHI
<a href="tel:+393290512702" style="text-decoration: none; color: #11254b;" data-mce-href="tel:+393290512702" data-mce-style="text-decoration: none; color: #11254b;">+39 329 0512704
System Engineer

+39 0521 24 77 91
[hidden email]



Da: "Payam Chychi" <[hidden email]>
A: "nginx" <[hidden email]>
Inviato: Mercoledì, 28 giugno 2017 19:56:04
Oggetto: Re: Strange issue after nginx update


On Wed, Jun 28, 2017 at 8:41 AM Andrea Soracchi <[hidden email]> wrote:
Hi,
could you please help me solve this issue? I'm getting crazy!

Before the nginx update my client worked perfectly: it posted files to my website without any delay.

How, after nginx update (ubuntu 16.04 LTS) I've got this issue:

- the client posts files successfully but the answer of the post is delayed. The more the file is bigger, the more the answer is delayed.

I put a sniffer into the website' server and I noticed that the nginx receives the post but it waits to transfer the file to php-fpm process, so also the answer to the client is delayed

The nginx server is:

nginx/1.10.0 (Ubuntu) and its conf is:

-----
user www-data;
worker_processes auto;
pid /run/nginx.pid;

events {
        worker_connections 768;
        # multi_accept on;
}

http {
        sendfile on;
        tcp_nodelay on;
        keepalive_timeout 65;
        types_hash_max_size 2048;
        client_max_body_size 0;
        log_not_found off;
        server_name_in_redirect off;
        client_body_timeout 120s;
        autoindex off;
        include /etc/nginx/mime.types;
        default_type application/octet-stream;
        ssl_protocols TLSv1 TLSv1.1 TLSv1.2; # Dropping SSLv3, ref: POODLE
        ssl_prefer_server_ciphers on;
        access_log /var/log/nginx/access.log;
        error_log /var/log/nginx/error.log info;
        gzip on;
        gzip_disable "msie6";
        gzip_types text/plain text/css application/json application/javascript text/xml application/xml application/xml+rss text/javascript;
        include /etc/nginx/conf.d/*.conf;
        include /etc/nginx/sites-enabled/*;
---

and website's php-fpm conf is:

server {
  listen                    80;
  server_name               test.it;
  server_name_in_redirect   off;
  autoindex                 off;
  client_max_body_size      500m;
  index                     index.html;
  root                      /home/test/test;
  location ~ \.(php|html|htm|php3)$ {
    try_files     $uri 404;
    fastcgi_pass  unix:/run/php/mdtest-fpm.sock;
    include       fastcgi_params;
  }
}

fastcgi_params config:

fastcgi_param  QUERY_STRING       $query_string;
fastcgi_param  REQUEST_METHOD     $request_method;
fastcgi_param  CONTENT_TYPE       $content_type;
fastcgi_param  CONTENT_LENGTH     $content_length;

fastcgi_param  SCRIPT_NAME        $fastcgi_script_name;
fastcgi_param  REQUEST_URI        $request_uri;
fastcgi_param  DOCUMENT_URI       $document_uri;
fastcgi_param  DOCUMENT_ROOT      $document_root;
fastcgi_param  SERVER_PROTOCOL    $server_protocol;
fastcgi_param  REQUEST_SCHEME     $scheme;
fastcgi_param  HTTPS              $https if_not_empty;

fastcgi_param  GATEWAY_INTERFACE  CGI/1.1;
fastcgi_param  SERVER_SOFTWARE    nginx/$nginx_version;

fastcgi_param  REMOTE_ADDR        $remote_addr;
fastcgi_param  REMOTE_PORT        $remote_port;
fastcgi_param  SERVER_ADDR        $server_addr;
fastcgi_param  SERVER_PORT        $server_port;
#fastcgi_param  SERVER_NAME        $server_name;
fastcgi_param  SERVER_NAME       $http_host;

# PHP only, required if PHP was built with --enable-force-cgi-redirect
fastcgi_param  REDIRECT_STATUS    200;

fastcgi_param SCRIPT_FILENAME     $document_root$fastcgi_script_name;


Thanks a lot,
Andrea


ANDREA SORACCHI
<a href="tel:+393290512702" style="text-decoration: none; color: #11254b;" target="_blank" data-mce-href="tel:+393290512702" data-mce-style="text-decoration: none; color: #11254b;">+39 329 0512704
System Engineer

+39 0521 24 77 91
[hidden email]


_______________________________________________
nginx mailing list
[hidden email]
http://mailman.nginx.org/mailman/listinfo/nginx

hi,

can you show the related wireshark data, how long is the response delayed by? and anything else like retransmits or anything else?

any SElinux security throtelling taking place? anything in dmesg?

--
Payam Tarverdyan Chychi
Network Security Specialist / Network Engineer

_______________________________________________
nginx mailing list
[hidden email]
http://mailman.nginx.org/mailman/listinfo/nginx

_______________________________________________
nginx mailing list
[hidden email]
http://mailman.nginx.org/mailman/listinfo/nginx

ettercap_dump.txt (9K) Download Attachment
Reply | Threaded
Open this post in threaded view
|

Re: Strange issue after nginx update

Anoop Alias
give a try changing the nameservers in /etc/resolv.conf 

On Thu, Jun 29, 2017 at 3:51 AM, Andrea Soracchi <[hidden email]> wrote:
Hi,

I have attached part of the ettercap log.

I have posted a test file of 40MB.

The delay  is 29 second:

 from the last file's chunk at 23:56:06
 
 to the response of  index2.php at 23:56:35

The nginx's log show:

192.168.18.18 - - [28/Jun/2017:23:56:35 +0200] "POST /index2.php HTTP/1.1" 200 37 "-" "Generic Client"

Nothing retransmits, SElinux isn't installed and apparmor is stopped.

Nothing in dmesg...

Thanks a lot,


ANDREA SORACCHI
<a href="tel:+393290512702" style="text-decoration:none;color:#11254b" target="_blank">+39 329 0512704
System Engineer

+39 0521 24 77 91
[hidden email]



Da: "Payam Chychi" <[hidden email]>
A: "nginx" <[hidden email]>
Inviato: Mercoledì, 28 giugno 2017 19:56:04
Oggetto: Re: Strange issue after nginx update


On Wed, Jun 28, 2017 at 8:41 AM Andrea Soracchi <[hidden email]> wrote:
Hi,
could you please help me solve this issue? I'm getting crazy!

Before the nginx update my client worked perfectly: it posted files to my website without any delay.

How, after nginx update (ubuntu 16.04 LTS) I've got this issue:

- the client posts files successfully but the answer of the post is delayed. The more the file is bigger, the more the answer is delayed.

I put a sniffer into the website' server and I noticed that the nginx receives the post but it waits to transfer the file to php-fpm process, so also the answer to the client is delayed

The nginx server is:

nginx/1.10.0 (Ubuntu) and its conf is:

-----
user www-data;
worker_processes auto;
pid /run/nginx.pid;

events {
        worker_connections 768;
        # multi_accept on;
}

http {
        sendfile on;
        tcp_nodelay on;
        keepalive_timeout 65;
        types_hash_max_size 2048;
        client_max_body_size 0;
        log_not_found off;
        server_name_in_redirect off;
        client_body_timeout 120s;
        autoindex off;
        include /etc/nginx/mime.types;
        default_type application/octet-stream;
        ssl_protocols TLSv1 TLSv1.1 TLSv1.2; # Dropping SSLv3, ref: POODLE
        ssl_prefer_server_ciphers on;
        access_log /var/log/nginx/access.log;
        error_log /var/log/nginx/error.log info;
        gzip on;
        gzip_disable "msie6";
        gzip_types text/plain text/css application/json application/javascript text/xml application/xml application/xml+rss text/javascript;
        include /etc/nginx/conf.d/*.conf;
        include /etc/nginx/sites-enabled/*;
---

and website's php-fpm conf is:

server {
  listen                    80;
  server_name               test.it;
  server_name_in_redirect   off;
  autoindex                 off;
  client_max_body_size      500m;
  index                     index.html;
  root                      /home/test/test;
  location ~ \.(php|html|htm|php3)$ {
    try_files     $uri 404;
    fastcgi_pass  unix:/run/php/mdtest-fpm.sock;
    include       fastcgi_params;
  }
}

fastcgi_params config:

fastcgi_param  QUERY_STRING       $query_string;
fastcgi_param  REQUEST_METHOD     $request_method;
fastcgi_param  CONTENT_TYPE       $content_type;
fastcgi_param  CONTENT_LENGTH     $content_length;

fastcgi_param  SCRIPT_NAME        $fastcgi_script_name;
fastcgi_param  REQUEST_URI        $request_uri;
fastcgi_param  DOCUMENT_URI       $document_uri;
fastcgi_param  DOCUMENT_ROOT      $document_root;
fastcgi_param  SERVER_PROTOCOL    $server_protocol;
fastcgi_param  REQUEST_SCHEME     $scheme;
fastcgi_param  HTTPS              $https if_not_empty;

fastcgi_param  GATEWAY_INTERFACE  CGI/1.1;
fastcgi_param  SERVER_SOFTWARE    nginx/$nginx_version;

fastcgi_param  REMOTE_ADDR        $remote_addr;
fastcgi_param  REMOTE_PORT        $remote_port;
fastcgi_param  SERVER_ADDR        $server_addr;
fastcgi_param  SERVER_PORT        $server_port;
#fastcgi_param  SERVER_NAME        $server_name;
fastcgi_param  SERVER_NAME       $http_host;

# PHP only, required if PHP was built with --enable-force-cgi-redirect
fastcgi_param  REDIRECT_STATUS    200;

fastcgi_param SCRIPT_FILENAME     $document_root$fastcgi_script_name;


Thanks a lot,
Andrea


ANDREA SORACCHI
<a href="tel:+393290512702" style="text-decoration:none;color:#11254b" target="_blank">+39 329 0512704
System Engineer

+39 0521 24 77 91
[hidden email]


_______________________________________________
nginx mailing list
[hidden email]
http://mailman.nginx.org/mailman/listinfo/nginx

hi,

can you show the related wireshark data, how long is the response delayed by? and anything else like retransmits or anything else?

any SElinux security throtelling taking place? anything in dmesg?

--
Payam Tarverdyan Chychi
Network Security Specialist / Network Engineer

_______________________________________________
nginx mailing list
[hidden email]
http://mailman.nginx.org/mailman/listinfo/nginx

_______________________________________________
nginx mailing list
[hidden email]
http://mailman.nginx.org/mailman/listinfo/nginx



--
Anoop P Alias 


_______________________________________________
nginx mailing list
[hidden email]
http://mailman.nginx.org/mailman/listinfo/nginx
Reply | Threaded
Open this post in threaded view
|

Re: Strange issue after nginx update

Payam Chychi
Are you seeing any errors in your php log?
are you connecting to the hostname or ip?

Also, make sure your interface is connected at full duplex. whats the output of "ethtool eth0" replace eth0 with your nic in use.

not sure what else really...
id say to check dns but its all local to you

- Payam


On Wed, Jun 28, 2017 at 9:01 PM Anoop Alias <[hidden email]> wrote:
give a try changing the nameservers in /etc/resolv.conf 

On Thu, Jun 29, 2017 at 3:51 AM, Andrea Soracchi <[hidden email]> wrote:
Hi,

I have attached part of the ettercap log.

I have posted a test file of 40MB.

The delay  is 29 second:

 from the last file's chunk at 23:56:06
 
 to the response of  index2.php at 23:56:35

The nginx's log show:

192.168.18.18 - - [28/Jun/2017:23:56:35 +0200] "POST /index2.php HTTP/1.1" 200 37 "-" "Generic Client"

Nothing retransmits, SElinux isn't installed and apparmor is stopped.

Nothing in dmesg...

Thanks a lot,


ANDREA SORACCHI
<a href="tel:+393290512702" style="text-decoration:none;color:#11254b" target="_blank">+39 329 0512704
System Engineer

+39 0521 24 77 91
[hidden email]



Da: "Payam Chychi" <[hidden email]>
A: "nginx" <[hidden email]>
Inviato: Mercoledì, 28 giugno 2017 19:56:04
Oggetto: Re: Strange issue after nginx update


On Wed, Jun 28, 2017 at 8:41 AM Andrea Soracchi <[hidden email]> wrote:
Hi,
could you please help me solve this issue? I'm getting crazy!

Before the nginx update my client worked perfectly: it posted files to my website without any delay.

How, after nginx update (ubuntu 16.04 LTS) I've got this issue:

- the client posts files successfully but the answer of the post is delayed. The more the file is bigger, the more the answer is delayed.

I put a sniffer into the website' server and I noticed that the nginx receives the post but it waits to transfer the file to php-fpm process, so also the answer to the client is delayed

The nginx server is:

nginx/1.10.0 (Ubuntu) and its conf is:

-----
user www-data;
worker_processes auto;
pid /run/nginx.pid;

events {
        worker_connections 768;
        # multi_accept on;
}

http {
        sendfile on;
        tcp_nodelay on;
        keepalive_timeout 65;
        types_hash_max_size 2048;
        client_max_body_size 0;
        log_not_found off;
        server_name_in_redirect off;
        client_body_timeout 120s;
        autoindex off;
        include /etc/nginx/mime.types;
        default_type application/octet-stream;
        ssl_protocols TLSv1 TLSv1.1 TLSv1.2; # Dropping SSLv3, ref: POODLE
        ssl_prefer_server_ciphers on;
        access_log /var/log/nginx/access.log;
        error_log /var/log/nginx/error.log info;
        gzip on;
        gzip_disable "msie6";
        gzip_types text/plain text/css application/json application/javascript text/xml application/xml application/xml+rss text/javascript;
        include /etc/nginx/conf.d/*.conf;
        include /etc/nginx/sites-enabled/*;
---

and website's php-fpm conf is:

server {
  listen                    80;
  server_name               test.it;
  server_name_in_redirect   off;
  autoindex                 off;
  client_max_body_size      500m;
  index                     index.html;
  root                      /home/test/test;
  location ~ \.(php|html|htm|php3)$ {
    try_files     $uri 404;
    fastcgi_pass  unix:/run/php/mdtest-fpm.sock;
    include       fastcgi_params;
  }
}

fastcgi_params config:

fastcgi_param  QUERY_STRING       $query_string;
fastcgi_param  REQUEST_METHOD     $request_method;
fastcgi_param  CONTENT_TYPE       $content_type;
fastcgi_param  CONTENT_LENGTH     $content_length;

fastcgi_param  SCRIPT_NAME        $fastcgi_script_name;
fastcgi_param  REQUEST_URI        $request_uri;
fastcgi_param  DOCUMENT_URI       $document_uri;
fastcgi_param  DOCUMENT_ROOT      $document_root;
fastcgi_param  SERVER_PROTOCOL    $server_protocol;
fastcgi_param  REQUEST_SCHEME     $scheme;
fastcgi_param  HTTPS              $https if_not_empty;

fastcgi_param  GATEWAY_INTERFACE  CGI/1.1;
fastcgi_param  SERVER_SOFTWARE    nginx/$nginx_version;

fastcgi_param  REMOTE_ADDR        $remote_addr;
fastcgi_param  REMOTE_PORT        $remote_port;
fastcgi_param  SERVER_ADDR        $server_addr;
fastcgi_param  SERVER_PORT        $server_port;
#fastcgi_param  SERVER_NAME        $server_name;
fastcgi_param  SERVER_NAME       $http_host;

# PHP only, required if PHP was built with --enable-force-cgi-redirect
fastcgi_param  REDIRECT_STATUS    200;

fastcgi_param SCRIPT_FILENAME     $document_root$fastcgi_script_name;


Thanks a lot,
Andrea


ANDREA SORACCHI
<a href="tel:+393290512702" style="text-decoration:none;color:#11254b" target="_blank">+39 329 0512704
System Engineer

+39 0521 24 77 91
[hidden email]


_______________________________________________
nginx mailing list
[hidden email]
http://mailman.nginx.org/mailman/listinfo/nginx

hi,

can you show the related wireshark data, how long is the response delayed by? and anything else like retransmits or anything else?

any SElinux security throtelling taking place? anything in dmesg?

--
Payam Tarverdyan Chychi
Network Security Specialist / Network Engineer

_______________________________________________
nginx mailing list
[hidden email]
http://mailman.nginx.org/mailman/listinfo/nginx

_______________________________________________
nginx mailing list
[hidden email]
http://mailman.nginx.org/mailman/listinfo/nginx



--
Anoop P Alias 

_______________________________________________
nginx mailing list
[hidden email]
http://mailman.nginx.org/mailman/listinfo/nginx
--
Payam Tarverdyan Chychi
Network Security Specialist / Network Engineer

_______________________________________________
nginx mailing list
[hidden email]
http://mailman.nginx.org/mailman/listinfo/nginx
Reply | Threaded
Open this post in threaded view
|

Re: Strange issue after nginx update

Andrea Soracchi-2
Hi Payam,

the problem is between Nginx and Php-fpm, but

I have set the debug level log to nginx and php-fpm.

Nginx:

2017/06/29 10:05:14 [warn] 5252#5252: *1613 a client request body is buffered to a temporary file /var/lib/nginx/body/0000000044, client: 192.168.18.18, server: andrea.eoraptor3.netbuilder.it, request: "POST /index2.php HTTP/1.1", host: "andrea.eoraptor3.netbuilder.it"
2017/06/29 10:05:14 [debug] 5252#5252: *1613 write: 9, 0000560D636FBE70, 8192, 0
2017/06/29 10:05:14 [debug] 5252#5252: *1613 recv: fd:3 5488 of 8192
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http client request body recv 5488
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http client request body rest 54606013
2017/06/29 10:05:14 [debug] 5252#5252: *1613 recv: fd:3 -1 of 2704
2017/06/29 10:05:14 [debug] 5252#5252: *1613 recv() not ready (11: Resource temporarily unavailable)
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http client request body recv -2
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http client request body rest 54606013
2017/06/29 10:05:14 [debug] 5252#5252: *1613 event timer: 3, old: 1498723634292, new: 1498723634292
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http run request: "/index2.php?"
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http read client request body
2017/06/29 10:05:14 [debug] 5252#5252: *1613 recv: fd:3 1368 of 2704
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http client request body recv 1368
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http client request body rest 54606013
2017/06/29 10:05:14 [debug] 5252#5252: *1613 recv: fd:3 -1 of 1336
2017/06/29 10:05:14 [debug] 5252#5252: *1613 recv() not ready (11: Resource temporarily unavailable)
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http client request body recv -2
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http client request body rest 54606013
2017/06/29 10:05:14 [debug] 5252#5252: *1613 event timer: 3, old: 1498723634292, new: 1498723634293
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http run request: "/index2.php?"
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http read client request body
2017/06/29 10:05:14 [debug] 5252#5252: *1613 recv: fd:3 1336 of 1336
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http client request body recv 1336
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http body new buf t:1 f:0 0000560D636FBE70, pos 0000560D636FBE70, size: 8192 file: 0, size: 0
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http write client request body, bufs 0000560D636F92C0
2017/06/29 10:05:14 [debug] 5252#5252: *1613 write: 9, 0000560D636FBE70, 8192, 8192
2017/06/29 10:05:14 [debug] 5252#5252: *1613 recv: fd:3 1400 of 8192
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http client request body recv 1400
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http client request body rest 54597821
2017/06/29 10:05:14 [debug] 5252#5252: *1613 recv: fd:3 -1 of 6792
2017/06/29 10:05:14 [debug] 5252#5252: *1613 recv() not ready (11: Resource temporarily unavailable)
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http client request body recv -2
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http client request body rest 54597821
2017/06/29 10:05:14 [debug] 5252#5252: *1613 event timer: 3, old: 1498723634292, new: 1498723634293
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http run request: "/index2.php?"
...
Repeated several times
...
...
2017/06/29 10:05:15 [debug] 5252#5252: *1613 writev() not ready (11: Resource temporarily unavailable)
2017/06/29 10:05:15 [debug] 5252#5252: *1613 chain writer out: 0000560D637FE780
2017/06/29 10:05:15 [debug] 5252#5252: *1613 event timer: 10, old: 1498723575096, new: 1498723575151
2017/06/29 10:05:15 [debug] 5252#5252: *1613 http upstream request: "/index2.php?"
2017/06/29 10:05:15 [debug] 5252#5252: *1613 http upstream send request handler
2017/06/29 10:05:15 [debug] 5252#5252: *1613 http upstream send request
2017/06/29 10:05:15 [debug] 5252#5252: *1613 http upstream send request body
2017/06/29 10:05:15 [debug] 5252#5252: *1613 chain writer in: 0000560D637FE780
2017/06/29 10:05:15 [debug] 5252#5252: *1613 writev: 8 of 8
2017/06/29 10:05:15 [debug] 5252#5252: *1613 sendfile: @54591488 22717
2017/06/29 10:05:15 [debug] 5252#5252: *1613 sendfile: 22717 of 22717 @54591488
2017/06/29 10:05:15 [debug] 5252#5252: *1613 writev: 11 of 11
2017/06/29 10:05:15 [debug] 5252#5252: *1613 chain writer out: 0000000000000000
2017/06/29 10:05:15 [debug] 5252#5252: *1613 event timer del: 10: 1498723575096
2017/06/29 10:05:15 [debug] 5252#5252: *1613 event timer add: 10: 300000:1498723815151
2017/06/29 10:05:15 [debug] 5252#5252: *1613 http upstream request: "/index2.php?"
2017/06/29 10:05:15 [debug] 5252#5252: *1613 http upstream dummy handler
2017/06/29 10:05:15 [debug] 5252#5252: *1613 http upstream request: "/index2.php?"
2017/06/29 10:05:15 [debug] 5252#5252: *1613 http upstream dummy handler
2017/06/29 10:05:40 [debug] 5252#5252: *1613 http upstream request: "/index2.php?"
2017/06/29 10:05:40 [debug] 5252#5252: *1613 http upstream process header
2017/06/29 10:05:40 [debug] 5252#5252: *1613 malloc: 0000560D637FF560:4096
2017/06/29 10:05:40 [debug] 5252#5252: *1613 recv: fd:10 56 of 4096
2017/06/29 10:05:40 [debug] 5252#5252: *1613 http fastcgi record byte: 01
2017/06/29 10:05:40 [debug] 5252#5252: *1613 http fastcgi record byte: 06
2017/06/29 10:05:40 [debug] 5252#5252: *1613 http fastcgi record byte: 00
2017/06/29 10:05:40 [debug] 5252#5252: *1613 http fastcgi record byte: 01
2017/06/29 10:05:40 [debug] 5252#5252: *1613 http fastcgi record byte: 00
2017/06/29 10:05:40 [debug] 5252#5252: *1613 http fastcgi record byte: 1D
2017/06/29 10:05:40 [debug] 5252#5252: *1613 http fastcgi record byte: 03
2017/06/29 10:05:40 [debug] 5252#5252: *1613 http fastcgi record byte: 00
2017/06/29 10:05:40 [debug] 5252#5252: *1613 http fastcgi record length: 29
2017/06/29 10:05:40 [debug] 5252#5252: *1613 http fastcgi parser: 0
2017/06/29 10:05:40 [debug] 5252#5252: *1613 http fastcgi header: "Content-type: text/html"
2017/06/29 10:05:40 [debug] 5252#5252: *1613 http fastcgi parser: 1
2017/06/29 10:05:40 [debug] 5252#5252: *1613 http fastcgi header done
2017/06/29 10:05:40 [debug] 5252#5252: *1613 xslt filter header
2017/06/29 10:05:40 [debug] 5252#5252: *1613 HTTP/1.1 200 OK^M


Php-fpm:

PHPFPM

[29-Jun-2017 10:05:14.699514] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 0 active children, 3 spare children, 3 running children. Spawning rate 1

[29-Jun-2017 10:05:16.700710] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:17.701773] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:18.702842] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:19.703778] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:20.705400] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:21.706471] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:22.707537] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:23.707779] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:24.708839] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:25.710378] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:26.710841] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:27.711798] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:28.712864] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:29.713932] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:30.715523] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:31.715785] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:32.716851] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:32.716851] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:33.717931] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:34.719001] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:35.720280] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:36.720662] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:37.721725] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:38.722791] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:39.723785] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1

[29-Jun-2017 10:05:40.725342] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 0 active children, 3 spare children, 3 running children. Spawning rate 1


Any idea?

Thanks a lot,
Andrea

ANDREA SORACCHI
<a href="tel:+393290512702" style="text-decoration: none; color: rgb(17, 37, 75);" data-mce-href="tel:+393290512702" data-mce-style="text-decoration: none; color: #11254b;">+39 329 0512704
System Engineer

+39 0521 24 77 91
[hidden email]



From: "Payam Chychi" <[hidden email]>
To: [hidden email]
Sent: Giovedì, 29 giugno 2017 6:38:09
Subject: Re: Strange issue after nginx update

Are you seeing any errors in your php log?
are you connecting to the hostname or ip?

Also, make sure your interface is connected at full duplex. whats the output of "ethtool eth0" replace eth0 with your nic in use.

not sure what else really...
id say to check dns but its all local to you

- Payam


On Wed, Jun 28, 2017 at 9:01 PM Anoop Alias <[hidden email]> wrote:
give a try changing the nameservers in /etc/resolv.conf 

On Thu, Jun 29, 2017 at 3:51 AM, Andrea Soracchi <[hidden email]> wrote:
Hi,

I have attached part of the ettercap log.

I have posted a test file of 40MB.

The delay  is 29 second:

 from the last file's chunk at 23:56:06
 
 to the response of  index2.php at 23:56:35

The nginx's log show:

192.168.18.18 - - [28/Jun/2017:23:56:35 +0200] "POST /index2.php HTTP/1.1" 200 37 "-" "Generic Client"

Nothing retransmits, SElinux isn't installed and apparmor is stopped.

Nothing in dmesg...

Thanks a lot,


ANDREA SORACCHI
<a href="tel:+393290512702" style="text-decoration: none; color: rgb(17, 37, 75);" target="_blank">+39 329 0512704
System Engineer

+39 0521 24 77 91
[hidden email]



Da: "Payam Chychi" <[hidden email]>
A: "nginx" <[hidden email]>
Inviato: Mercoledì, 28 giugno 2017 19:56:04
Oggetto: Re: Strange issue after nginx update


On Wed, Jun 28, 2017 at 8:41 AM Andrea Soracchi <[hidden email]> wrote:
Hi,
could you please help me solve this issue? I'm getting crazy!

Before the nginx update my client worked perfectly: it posted files to my website without any delay.

How, after nginx update (ubuntu 16.04 LTS) I've got this issue:

- the client posts files successfully but the answer of the post is delayed. The more the file is bigger, the more the answer is delayed.

I put a sniffer into the website' server and I noticed that the nginx receives the post but it waits to transfer the file to php-fpm process, so also the answer to the client is delayed

The nginx server is:

nginx/1.10.0 (Ubuntu) and its conf is:

-----
user www-data;
worker_processes auto;
pid /run/nginx.pid;

events {
        worker_connections 768;
        # multi_accept on;
}

http {
        sendfile on;
        tcp_nodelay on;
        keepalive_timeout 65;
        types_hash_max_size 2048;
        client_max_body_size 0;
        log_not_found off;
        server_name_in_redirect off;
        client_body_timeout 120s;
        autoindex off;
        include /etc/nginx/mime.types;
        default_type application/octet-stream;
        ssl_protocols TLSv1 TLSv1.1 TLSv1.2; # Dropping SSLv3, ref: POODLE
        ssl_prefer_server_ciphers on;
        access_log /var/log/nginx/access.log;
        error_log /var/log/nginx/error.log info;
        gzip on;
        gzip_disable "msie6";
        gzip_types text/plain text/css application/json application/javascript text/xml application/xml application/xml+rss text/javascript;
        include /etc/nginx/conf.d/*.conf;
        include /etc/nginx/sites-enabled/*;
---

and website's php-fpm conf is:

server {
  listen                    80;
  server_name               test.it;
  server_name_in_redirect   off;
  autoindex                 off;
  client_max_body_size      500m;
  index                     index.html;
  root                      /home/test/test;
  location ~ \.(php|html|htm|php3)$ {
    try_files     $uri 404;
    fastcgi_pass  unix:/run/php/mdtest-fpm.sock;
    include       fastcgi_params;
  }
}

fastcgi_params config:

fastcgi_param  QUERY_STRING       $query_string;
fastcgi_param  REQUEST_METHOD     $request_method;
fastcgi_param  CONTENT_TYPE       $content_type;
fastcgi_param  CONTENT_LENGTH     $content_length;

fastcgi_param  SCRIPT_NAME        $fastcgi_script_name;
fastcgi_param  REQUEST_URI        $request_uri;
fastcgi_param  DOCUMENT_URI       $document_uri;
fastcgi_param  DOCUMENT_ROOT      $document_root;
fastcgi_param  SERVER_PROTOCOL    $server_protocol;
fastcgi_param  REQUEST_SCHEME     $scheme;
fastcgi_param  HTTPS              $https if_not_empty;

fastcgi_param  GATEWAY_INTERFACE  CGI/1.1;
fastcgi_param  SERVER_SOFTWARE    nginx/$nginx_version;

fastcgi_param  REMOTE_ADDR        $remote_addr;
fastcgi_param  REMOTE_PORT        $remote_port;
fastcgi_param  SERVER_ADDR        $server_addr;
fastcgi_param  SERVER_PORT        $server_port;
#fastcgi_param  SERVER_NAME        $server_name;
fastcgi_param  SERVER_NAME       $http_host;

# PHP only, required if PHP was built with --enable-force-cgi-redirect
fastcgi_param  REDIRECT_STATUS    200;

fastcgi_param SCRIPT_FILENAME     $document_root$fastcgi_script_name;


Thanks a lot,
Andrea


ANDREA SORACCHI
<a href="tel:+393290512702" style="text-decoration: none; color: rgb(17, 37, 75);" target="_blank">+39 329 0512704
System Engineer

+39 0521 24 77 91
[hidden email]


_______________________________________________
nginx mailing list
[hidden email]
http://mailman.nginx.org/mailman/listinfo/nginx

hi,

can you show the related wireshark data, how long is the response delayed by? and anything else like retransmits or anything else?

any SElinux security throtelling taking place? anything in dmesg?

--
Payam Tarverdyan Chychi
Network Security Specialist / Network Engineer

_______________________________________________
nginx mailing list
[hidden email]
http://mailman.nginx.org/mailman/listinfo/nginx

_______________________________________________
nginx mailing list
[hidden email]
http://mailman.nginx.org/mailman/listinfo/nginx



--
Anoop P Alias 

_______________________________________________
nginx mailing list
[hidden email]
http://mailman.nginx.org/mailman/listinfo/nginx
--
Payam Tarverdyan Chychi
Network Security Specialist / Network Engineer

--
Questo messaggio e' stato analizzato ed e' risultato non infetto.
This message was scanned and is believed to be clean.


_______________________________________________
nginx mailing list
[hidden email]
http://mailman.nginx.org/mailman/listinfo/nginx


_______________________________________________
nginx mailing list
[hidden email]
http://mailman.nginx.org/mailman/listinfo/nginx
Reply | Threaded
Open this post in threaded view
|

Re: Strange issue after nginx update

Richard Stanway
If you want to stream the upload directly to your backend, you should consider fastcgi_request_buffering[1].

The problem is most likely with your PHP backend though, you should examine why it takes so long to process the request.


On Thu, Jun 29, 2017 at 12:01 PM, Andrea Soracchi <[hidden email]> wrote:
Hi Payam,

the problem is between Nginx and Php-fpm, but

I have set the debug level log to nginx and php-fpm.

Nginx:

2017/06/29 10:05:14 [warn] 5252#5252: *1613 a client request body is buffered to a temporary file /var/lib/nginx/body/0000000044, client: 192.168.18.18, server: andrea.eoraptor3.netbuilder.it, request: "POST /index2.php HTTP/1.1", host: "andrea.eoraptor3.netbuilder.it"
2017/06/29 10:05:14 [debug] 5252#5252: *1613 write: 9, 0000560D636FBE70, 8192, 0
2017/06/29 10:05:14 [debug] 5252#5252: *1613 recv: fd:3 5488 of 8192
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http client request body recv 5488
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http client request body rest 54606013
2017/06/29 10:05:14 [debug] 5252#5252: *1613 recv: fd:3 -1 of 2704
2017/06/29 10:05:14 [debug] 5252#5252: *1613 recv() not ready (11: Resource temporarily unavailable)
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http client request body recv -2
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http client request body rest 54606013
2017/06/29 10:05:14 [debug] 5252#5252: *1613 event timer: 3, old: 1498723634292, new: 1498723634292
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http run request: "/index2.php?"
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http read client request body
2017/06/29 10:05:14 [debug] 5252#5252: *1613 recv: fd:3 1368 of 2704
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http client request body recv 1368
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http client request body rest 54606013
2017/06/29 10:05:14 [debug] 5252#5252: *1613 recv: fd:3 -1 of 1336
2017/06/29 10:05:14 [debug] 5252#5252: *1613 recv() not ready (11: Resource temporarily unavailable)
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http client request body recv -2
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http client request body rest 54606013
2017/06/29 10:05:14 [debug] 5252#5252: *1613 event timer: 3, old: 1498723634292, new: 1498723634293
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http run request: "/index2.php?"
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http read client request body
2017/06/29 10:05:14 [debug] 5252#5252: *1613 recv: fd:3 1336 of 1336
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http client request body recv 1336
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http body new buf t:1 f:0 0000560D636FBE70, pos 0000560D636FBE70, size: 8192 file: 0, size: 0
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http write client request body, bufs 0000560D636F92C0
2017/06/29 10:05:14 [debug] 5252#5252: *1613 write: 9, 0000560D636FBE70, 8192, 8192
2017/06/29 10:05:14 [debug] 5252#5252: *1613 recv: fd:3 1400 of 8192
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http client request body recv 1400
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http client request body rest 54597821
2017/06/29 10:05:14 [debug] 5252#5252: *1613 recv: fd:3 -1 of 6792
2017/06/29 10:05:14 [debug] 5252#5252: *1613 recv() not ready (11: Resource temporarily unavailable)
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http client request body recv -2
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http client request body rest 54597821
2017/06/29 10:05:14 [debug] 5252#5252: *1613 event timer: 3, old: 1498723634292, new: 1498723634293
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http run request: "/index2.php?"
...
Repeated several times
...
...
2017/06/29 10:05:15 [debug] 5252#5252: *1613 writev() not ready (11: Resource temporarily unavailable)
2017/06/29 10:05:15 [debug] 5252#5252: *1613 chain writer out: 0000560D637FE780
2017/06/29 10:05:15 [debug] 5252#5252: *1613 event timer: 10, old: 1498723575096, new: 1498723575151
2017/06/29 10:05:15 [debug] 5252#5252: *1613 http upstream request: "/index2.php?"
2017/06/29 10:05:15 [debug] 5252#5252: *1613 http upstream send request handler
2017/06/29 10:05:15 [debug] 5252#5252: *1613 http upstream send request
2017/06/29 10:05:15 [debug] 5252#5252: *1613 http upstream send request body
2017/06/29 10:05:15 [debug] 5252#5252: *1613 chain writer in: 0000560D637FE780
2017/06/29 10:05:15 [debug] 5252#5252: *1613 writev: 8 of 8
2017/06/29 10:05:15 [debug] 5252#5252: *1613 sendfile: @54591488 22717
2017/06/29 10:05:15 [debug] 5252#5252: *1613 sendfile: 22717 of 22717 @54591488
2017/06/29 10:05:15 [debug] 5252#5252: *1613 writev: 11 of 11
2017/06/29 10:05:15 [debug] 5252#5252: *1613 chain writer out: 0000000000000000
2017/06/29 10:05:15 [debug] 5252#5252: *1613 event timer del: 10: 1498723575096
2017/06/29 10:05:15 [debug] 5252#5252: *1613 event timer add: 10: 300000:1498723815151
2017/06/29 10:05:15 [debug] 5252#5252: *1613 http upstream request: "/index2.php?"
2017/06/29 10:05:15 [debug] 5252#5252: *1613 http upstream dummy handler
2017/06/29 10:05:15 [debug] 5252#5252: *1613 http upstream request: "/index2.php?"
2017/06/29 10:05:15 [debug] 5252#5252: *1613 http upstream dummy handler
2017/06/29 10:05:40 [debug] 5252#5252: *1613 http upstream request: "/index2.php?"
2017/06/29 10:05:40 [debug] 5252#5252: *1613 http upstream process header
2017/06/29 10:05:40 [debug] 5252#5252: *1613 malloc: 0000560D637FF560:4096
2017/06/29 10:05:40 [debug] 5252#5252: *1613 recv: fd:10 56 of 4096
2017/06/29 10:05:40 [debug] 5252#5252: *1613 http fastcgi record byte: 01
2017/06/29 10:05:40 [debug] 5252#5252: *1613 http fastcgi record byte: 06
2017/06/29 10:05:40 [debug] 5252#5252: *1613 http fastcgi record byte: 00
2017/06/29 10:05:40 [debug] 5252#5252: *1613 http fastcgi record byte: 01
2017/06/29 10:05:40 [debug] 5252#5252: *1613 http fastcgi record byte: 00
2017/06/29 10:05:40 [debug] 5252#5252: *1613 http fastcgi record byte: 1D
2017/06/29 10:05:40 [debug] 5252#5252: *1613 http fastcgi record byte: 03
2017/06/29 10:05:40 [debug] 5252#5252: *1613 http fastcgi record byte: 00
2017/06/29 10:05:40 [debug] 5252#5252: *1613 http fastcgi record length: 29
2017/06/29 10:05:40 [debug] 5252#5252: *1613 http fastcgi parser: 0
2017/06/29 10:05:40 [debug] 5252#5252: *1613 http fastcgi header: "Content-type: text/html"
2017/06/29 10:05:40 [debug] 5252#5252: *1613 http fastcgi parser: 1
2017/06/29 10:05:40 [debug] 5252#5252: *1613 http fastcgi header done
2017/06/29 10:05:40 [debug] 5252#5252: *1613 xslt filter header
2017/06/29 10:05:40 [debug] 5252#5252: *1613 HTTP/1.1 200 OK^M


Php-fpm:

PHPFPM

[29-Jun-2017 10:05:14.699514] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 0 active children, 3 spare children, 3 running children. Spawning rate 1

[29-Jun-2017 10:05:16.700710] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:17.701773] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:18.702842] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:19.703778] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:20.705400] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:21.706471] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:22.707537] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:23.707779] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:24.708839] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:25.710378] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:26.710841] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:27.711798] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:28.712864] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:29.713932] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:30.715523] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:31.715785] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:32.716851] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:32.716851] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:33.717931] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:34.719001] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:35.720280] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:36.720662] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:37.721725] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:38.722791] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:39.723785] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1

[29-Jun-2017 10:05:40.725342] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 0 active children, 3 spare children, 3 running children. Spawning rate 1


Any idea?

Thanks a lot,
Andrea

ANDREA SORACCHI
<a href="tel:+393290512702" style="text-decoration:none;color:rgb(17,37,75)" target="_blank">+39 329 0512704
System Engineer

+39 0521 24 77 91
[hidden email]



From: "Payam Chychi" <[hidden email]>
To: [hidden email]
Sent: Giovedì, 29 giugno 2017 6:38:09
Subject: Re: Strange issue after nginx update


Are you seeing any errors in your php log?
are you connecting to the hostname or ip?

Also, make sure your interface is connected at full duplex. whats the output of "ethtool eth0" replace eth0 with your nic in use.

not sure what else really...
id say to check dns but its all local to you

- Payam


On Wed, Jun 28, 2017 at 9:01 PM Anoop Alias <[hidden email]> wrote:
give a try changing the nameservers in /etc/resolv.conf 

On Thu, Jun 29, 2017 at 3:51 AM, Andrea Soracchi <[hidden email]> wrote:
Hi,

I have attached part of the ettercap log.

I have posted a test file of 40MB.

The delay  is 29 second:

 from the last file's chunk at 23:56:06
 
 to the response of  index2.php at 23:56:35

The nginx's log show:

192.168.18.18 - - [28/Jun/2017:23:56:35 +0200] "POST /index2.php HTTP/1.1" 200 37 "-" "Generic Client"

Nothing retransmits, SElinux isn't installed and apparmor is stopped.

Nothing in dmesg...

Thanks a lot,


ANDREA SORACCHI
<a href="tel:+393290512702" style="text-decoration:none;color:rgb(17,37,75)" target="_blank">+39 329 0512704
System Engineer

+39 0521 24 77 91
[hidden email]



Da: "Payam Chychi" <[hidden email]>
A: "nginx" <[hidden email]>
Inviato: Mercoledì, 28 giugno 2017 19:56:04
Oggetto: Re: Strange issue after nginx update


On Wed, Jun 28, 2017 at 8:41 AM Andrea Soracchi <[hidden email]> wrote:
Hi,
could you please help me solve this issue? I'm getting crazy!

Before the nginx update my client worked perfectly: it posted files to my website without any delay.

How, after nginx update (ubuntu 16.04 LTS) I've got this issue:

- the client posts files successfully but the answer of the post is delayed. The more the file is bigger, the more the answer is delayed.

I put a sniffer into the website' server and I noticed that the nginx receives the post but it waits to transfer the file to php-fpm process, so also the answer to the client is delayed

The nginx server is:

nginx/1.10.0 (Ubuntu) and its conf is:

-----
user www-data;
worker_processes auto;
pid /run/nginx.pid;

events {
        worker_connections 768;
        # multi_accept on;
}

http {
        sendfile on;
        tcp_nodelay on;
        keepalive_timeout 65;
        types_hash_max_size 2048;
        client_max_body_size 0;
        log_not_found off;
        server_name_in_redirect off;
        client_body_timeout 120s;
        autoindex off;
        include /etc/nginx/mime.types;
        default_type application/octet-stream;
        ssl_protocols TLSv1 TLSv1.1 TLSv1.2; # Dropping SSLv3, ref: POODLE
        ssl_prefer_server_ciphers on;
        access_log /var/log/nginx/access.log;
        error_log /var/log/nginx/error.log info;
        gzip on;
        gzip_disable "msie6";
        gzip_types text/plain text/css application/json application/javascript text/xml application/xml application/xml+rss text/javascript;
        include /etc/nginx/conf.d/*.conf;
        include /etc/nginx/sites-enabled/*;
---

and website's php-fpm conf is:

server {
  listen                    80;
  server_name               test.it;
  server_name_in_redirect   off;
  autoindex                 off;
  client_max_body_size      500m;
  index                     index.html;
  root                      /home/test/test;
  location ~ \.(php|html|htm|php3)$ {
    try_files     $uri 404;
    fastcgi_pass  unix:/run/php/mdtest-fpm.sock;
    include       fastcgi_params;
  }
}

fastcgi_params config:

fastcgi_param  QUERY_STRING       $query_string;
fastcgi_param  REQUEST_METHOD     $request_method;
fastcgi_param  CONTENT_TYPE       $content_type;
fastcgi_param  CONTENT_LENGTH     $content_length;

fastcgi_param  SCRIPT_NAME        $fastcgi_script_name;
fastcgi_param  REQUEST_URI        $request_uri;
fastcgi_param  DOCUMENT_URI       $document_uri;
fastcgi_param  DOCUMENT_ROOT      $document_root;
fastcgi_param  SERVER_PROTOCOL    $server_protocol;
fastcgi_param  REQUEST_SCHEME     $scheme;
fastcgi_param  HTTPS              $https if_not_empty;

fastcgi_param  GATEWAY_INTERFACE  CGI/1.1;
fastcgi_param  SERVER_SOFTWARE    nginx/$nginx_version;

fastcgi_param  REMOTE_ADDR        $remote_addr;
fastcgi_param  REMOTE_PORT        $remote_port;
fastcgi_param  SERVER_ADDR        $server_addr;
fastcgi_param  SERVER_PORT        $server_port;
#fastcgi_param  SERVER_NAME        $server_name;
fastcgi_param  SERVER_NAME       $http_host;

# PHP only, required if PHP was built with --enable-force-cgi-redirect
fastcgi_param  REDIRECT_STATUS    200;

fastcgi_param SCRIPT_FILENAME     $document_root$fastcgi_script_name;


Thanks a lot,
Andrea


ANDREA SORACCHI
<a href="tel:+393290512702" style="text-decoration:none;color:rgb(17,37,75)" target="_blank">+39 329 0512704
System Engineer

+39 0521 24 77 91
[hidden email]


_______________________________________________
nginx mailing list
[hidden email]
http://mailman.nginx.org/mailman/listinfo/nginx

hi,

can you show the related wireshark data, how long is the response delayed by? and anything else like retransmits or anything else?

any SElinux security throtelling taking place? anything in dmesg?

--
Payam Tarverdyan Chychi
Network Security Specialist / Network Engineer

_______________________________________________
nginx mailing list
[hidden email]
http://mailman.nginx.org/mailman/listinfo/nginx

_______________________________________________
nginx mailing list
[hidden email]
http://mailman.nginx.org/mailman/listinfo/nginx



--
Anoop P Alias 

_______________________________________________
nginx mailing list
[hidden email]
http://mailman.nginx.org/mailman/listinfo/nginx
--
Payam Tarverdyan Chychi
Network Security Specialist / Network Engineer

--
Questo messaggio e' stato analizzato ed e' risultato non infetto.
This message was scanned and is believed to be clean.


_______________________________________________
nginx mailing list
[hidden email]
http://mailman.nginx.org/mailman/listinfo/nginx


_______________________________________________
nginx mailing list
[hidden email]
http://mailman.nginx.org/mailman/listinfo/nginx


_______________________________________________
nginx mailing list
[hidden email]
http://mailman.nginx.org/mailman/listinfo/nginx
Reply | Threaded
Open this post in threaded view
|

Re: Strange issue after nginx update

Payam Chychi
set your worker_process to 1 and try again

_______________________________________________
nginx mailing list
[hidden email]
http://mailman.nginx.org/mailman/listinfo/nginx
Reply | Threaded
Open this post in threaded view
|

Re: Strange issue after nginx update

Andrea Soracchi-2
In reply to this post by Richard Stanway
Hi Richard,

I have the same problem with fastcgi_request_buffering[1] set to off:

*21 http read client request body
2017/06/30 01:33:54 [debug] 19140#19140: *21 recv: fd:11 -1 of 1744
2017/06/30 01:33:54 [debug] 19140#19140: *21 recv() not ready (11: Resource temporarily unavailable)
2017/06/30 01:33:54 [debug] 19140#19140: *21 http client request body recv -2
2017/06/30 01:33:54 [debug] 19140#19140: *21 http client request body rest 8077
2017/06/30 01:33:54 [debug] 19140#19140: *21 event timer: 11, old: 1498779354309, new: 1498779354309
2017/06/30 01:33:54 [debug] 19140#19140: *21 http run request: "/index2.php?"
2017/06/30 01:33:54 [debug] 19140#19140: *21 http upstream check client, write event:1, "/index2.php"
2017/06/30 01:33:54 [debug] 19140#19140: *21 http upstream recv(): -1 (11: Resource temporarily unavailable)
2017/06/30 01:33:54 [debug] 19140#19140: *21 http upstream request: "/index2.php?"
2017/06/30 01:33:54 [debug] 19140#19140: *21 http upstream send request handler
2017/06/30 01:33:54 [debug] 19140#19140: *21 http upstream send request
2017/06/30 01:33:54 [debug] 19140#19140: *21 http upstream send request body
2017/06/30 01:33:54 [debug] 19140#19140: *21 fastcgi output filter
2017/06/30 01:33:54 [debug] 19140#19140: *21 chain writer in: 0000000000000000
2017/06/30 01:33:54 [debug] 19140#19140: *21 http read client request body
2017/06/30 01:33:54 [debug] 19140#19140: *21 recv: fd:11 -1 of 1744
2017/06/30 01:33:54 [debug] 19140#19140: *21 recv() not ready (11: Resource temporarily unavailable)
2017/06/30 01:33:54 [debug] 19140#19140: *21 http client request body recv -2
2017/06/30 01:33:54 [debug] 19140#19140: *21 http client request body rest 8077
2017/06/30 01:33:54 [debug] 19140#19140: *21 event timer: 11, old: 1498779354309, new: 1498779354309
2017/06/30 01:33:54 [debug] 19140#19140: *21 http run request: "/index2.php?"
2017/06/30 01:33:54 [debug] 19140#19140: *21 http upstream read request handler
2017/06/30 01:33:54 [debug] 19140#19140: *21 http upstream send request
2017/06/30 01:33:54 [debug] 19140#19140: *21 http upstream send request body
2017/06/30 01:33:54 [debug] 19140#19140: *21 http read client request body
2017/06/30 01:33:54 [debug] 19140#19140: *21 recv: fd:11 1744 of 1744
2017/06/30 01:33:54 [debug] 19140#19140: *21 http client request body recv 1744

@Payam I try worker_process to 1 but same result.

The php-fpm log is free of errors...




ANDREA SORACCHI
<a href="tel:+393290512702" style="text-decoration: none; color: #11254b;" data-mce-href="tel:+393290512702" data-mce-style="text-decoration: none; color: #11254b;">+39 329 0512704
System Engineer

+39 0521 24 77 91
[hidden email]



Da: "Richard Stanway" <[hidden email]>
A: "nginx" <[hidden email]>
Inviato: Giovedì, 29 giugno 2017 18:47:36
Oggetto: Re: Strange issue after nginx update

If you want to stream the upload directly to your backend, you should consider fastcgi_request_buffering[1].
The problem is most likely with your PHP backend though, you should examine why it takes so long to process the request.


On Thu, Jun 29, 2017 at 12:01 PM, Andrea Soracchi <[hidden email]> wrote:
Hi Payam,

the problem is between Nginx and Php-fpm, but

I have set the debug level log to nginx and php-fpm.

Nginx:

2017/06/29 10:05:14 [warn] 5252#5252: *1613 a client request body is buffered to a temporary file /var/lib/nginx/body/0000000044, client: 192.168.18.18, server: andrea.eoraptor3.netbuilder.it, request: "POST /index2.php HTTP/1.1", host: "andrea.eoraptor3.netbuilder.it"
2017/06/29 10:05:14 [debug] 5252#5252: *1613 write: 9, 0000560D636FBE70, 8192, 0
2017/06/29 10:05:14 [debug] 5252#5252: *1613 recv: fd:3 5488 of 8192
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http client request body recv 5488
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http client request body rest 54606013
2017/06/29 10:05:14 [debug] 5252#5252: *1613 recv: fd:3 -1 of 2704
2017/06/29 10:05:14 [debug] 5252#5252: *1613 recv() not ready (11: Resource temporarily unavailable)
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http client request body recv -2
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http client request body rest 54606013
2017/06/29 10:05:14 [debug] 5252#5252: *1613 event timer: 3, old: 1498723634292, new: 1498723634292
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http run request: "/index2.php?"
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http read client request body
2017/06/29 10:05:14 [debug] 5252#5252: *1613 recv: fd:3 1368 of 2704
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http client request body recv 1368
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http client request body rest 54606013
2017/06/29 10:05:14 [debug] 5252#5252: *1613 recv: fd:3 -1 of 1336
2017/06/29 10:05:14 [debug] 5252#5252: *1613 recv() not ready (11: Resource temporarily unavailable)
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http client request body recv -2
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http client request body rest 54606013
2017/06/29 10:05:14 [debug] 5252#5252: *1613 event timer: 3, old: 1498723634292, new: 1498723634293
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http run request: "/index2.php?"
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http read client request body
2017/06/29 10:05:14 [debug] 5252#5252: *1613 recv: fd:3 1336 of 1336
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http client request body recv 1336
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http body new buf t:1 f:0 0000560D636FBE70, pos 0000560D636FBE70, size: 8192 file: 0, size: 0
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http write client request body, bufs 0000560D636F92C0
2017/06/29 10:05:14 [debug] 5252#5252: *1613 write: 9, 0000560D636FBE70, 8192, 8192
2017/06/29 10:05:14 [debug] 5252#5252: *1613 recv: fd:3 1400 of 8192
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http client request body recv 1400
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http client request body rest 54597821
2017/06/29 10:05:14 [debug] 5252#5252: *1613 recv: fd:3 -1 of 6792
2017/06/29 10:05:14 [debug] 5252#5252: *1613 recv() not ready (11: Resource temporarily unavailable)
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http client request body recv -2
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http client request body rest 54597821
2017/06/29 10:05:14 [debug] 5252#5252: *1613 event timer: 3, old: 1498723634292, new: 1498723634293
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http run request: "/index2.php?"
...
Repeated several times
...
...
2017/06/29 10:05:15 [debug] 5252#5252: *1613 writev() not ready (11: Resource temporarily unavailable)
2017/06/29 10:05:15 [debug] 5252#5252: *1613 chain writer out: 0000560D637FE780
2017/06/29 10:05:15 [debug] 5252#5252: *1613 event timer: 10, old: 1498723575096, new: 1498723575151
2017/06/29 10:05:15 [debug] 5252#5252: *1613 http upstream request: "/index2.php?"
2017/06/29 10:05:15 [debug] 5252#5252: *1613 http upstream send request handler
2017/06/29 10:05:15 [debug] 5252#5252: *1613 http upstream send request
2017/06/29 10:05:15 [debug] 5252#5252: *1613 http upstream send request body
2017/06/29 10:05:15 [debug] 5252#5252: *1613 chain writer in: 0000560D637FE780
2017/06/29 10:05:15 [debug] 5252#5252: *1613 writev: 8 of 8
2017/06/29 10:05:15 [debug] 5252#5252: *1613 sendfile: @54591488 22717
2017/06/29 10:05:15 [debug] 5252#5252: *1613 sendfile: 22717 of 22717 @54591488
2017/06/29 10:05:15 [debug] 5252#5252: *1613 writev: 11 of 11
2017/06/29 10:05:15 [debug] 5252#5252: *1613 chain writer out: 0000000000000000
2017/06/29 10:05:15 [debug] 5252#5252: *1613 event timer del: 10: 1498723575096
2017/06/29 10:05:15 [debug] 5252#5252: *1613 event timer add: 10: 300000:1498723815151
2017/06/29 10:05:15 [debug] 5252#5252: *1613 http upstream request: "/index2.php?"
2017/06/29 10:05:15 [debug] 5252#5252: *1613 http upstream dummy handler
2017/06/29 10:05:15 [debug] 5252#5252: *1613 http upstream request: "/index2.php?"
2017/06/29 10:05:15 [debug] 5252#5252: *1613 http upstream dummy handler
2017/06/29 10:05:40 [debug] 5252#5252: *1613 http upstream request: "/index2.php?"
2017/06/29 10:05:40 [debug] 5252#5252: *1613 http upstream process header
2017/06/29 10:05:40 [debug] 5252#5252: *1613 malloc: 0000560D637FF560:4096
2017/06/29 10:05:40 [debug] 5252#5252: *1613 recv: fd:10 56 of 4096
2017/06/29 10:05:40 [debug] 5252#5252: *1613 http fastcgi record byte: 01
2017/06/29 10:05:40 [debug] 5252#5252: *1613 http fastcgi record byte: 06
2017/06/29 10:05:40 [debug] 5252#5252: *1613 http fastcgi record byte: 00
2017/06/29 10:05:40 [debug] 5252#5252: *1613 http fastcgi record byte: 01
2017/06/29 10:05:40 [debug] 5252#5252: *1613 http fastcgi record byte: 00
2017/06/29 10:05:40 [debug] 5252#5252: *1613 http fastcgi record byte: 1D
2017/06/29 10:05:40 [debug] 5252#5252: *1613 http fastcgi record byte: 03
2017/06/29 10:05:40 [debug] 5252#5252: *1613 http fastcgi record byte: 00
2017/06/29 10:05:40 [debug] 5252#5252: *1613 http fastcgi record length: 29
2017/06/29 10:05:40 [debug] 5252#5252: *1613 http fastcgi parser: 0
2017/06/29 10:05:40 [debug] 5252#5252: *1613 http fastcgi header: "Content-type: text/html"
2017/06/29 10:05:40 [debug] 5252#5252: *1613 http fastcgi parser: 1
2017/06/29 10:05:40 [debug] 5252#5252: *1613 http fastcgi header done
2017/06/29 10:05:40 [debug] 5252#5252: *1613 xslt filter header
2017/06/29 10:05:40 [debug] 5252#5252: *1613 HTTP/1.1 200 OK^M


Php-fpm:

PHPFPM

[29-Jun-2017 10:05:14.699514] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 0 active children, 3 spare children, 3 running children. Spawning rate 1

[29-Jun-2017 10:05:16.700710] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:17.701773] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:18.702842] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:19.703778] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:20.705400] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:21.706471] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:22.707537] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:23.707779] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:24.708839] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:25.710378] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:26.710841] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:27.711798] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:28.712864] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:29.713932] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:30.715523] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:31.715785] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:32.716851] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:32.716851] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:33.717931] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:34.719001] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:35.720280] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:36.720662] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:37.721725] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:38.722791] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:39.723785] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1

[29-Jun-2017 10:05:40.725342] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 0 active children, 3 spare children, 3 running children. Spawning rate 1


Any idea?

Thanks a lot,
Andrea

ANDREA SORACCHI
<a href="tel:+393290512702" style="text-decoration: none; color: #11254b;" target="_blank" data-mce-href="tel:+393290512702" data-mce-style="text-decoration: none; color: #11254b;">+39 329 0512704
System Engineer

+39 0521 24 77 91
[hidden email]



From: "Payam Chychi" <[hidden email]>
To: [hidden email]
Sent: Giovedì, 29 giugno 2017 6:38:09
Subject: Re: Strange issue after nginx update


Are you seeing any errors in your php log?
are you connecting to the hostname or ip?

Also, make sure your interface is connected at full duplex. whats the output of "ethtool eth0" replace eth0 with your nic in use.

not sure what else really...
id say to check dns but its all local to you

- Payam


On Wed, Jun 28, 2017 at 9:01 PM Anoop Alias <[hidden email]> wrote:
give a try changing the nameservers in /etc/resolv.conf 


On Thu, Jun 29, 2017 at 3:51 AM, Andrea Soracchi <[hidden email]> wrote:
Hi,

I have attached part of the ettercap log.

I have posted a test file of 40MB.

The delay  is 29 second:

 from the last file's chunk at 23:56:06
 
 to the response of  index2.php at 23:56:35

The nginx's log show:

192.168.18.18 - - [28/Jun/2017:23:56:35 +0200] "POST /index2.php HTTP/1.1" 200 37 "-" "Generic Client"

Nothing retransmits, SElinux isn't installed and apparmor is stopped.

Nothing in dmesg...

Thanks a lot,


ANDREA SORACCHI
<a href="tel:+393290512702" style="text-decoration: none; color: #11254b;" target="_blank" data-mce-href="tel:+393290512702" data-mce-style="text-decoration: none; color: #11254b;">+39 329 0512704
System Engineer

+39 0521 24 77 91
[hidden email]


Da: "Payam Chychi" <[hidden email]>
A: "nginx" <[hidden email]>
Inviato: Mercoledì, 28 giugno 2017 19:56:04
Oggetto: Re: Strange issue after nginx update


On Wed, Jun 28, 2017 at 8:41 AM Andrea Soracchi <[hidden email]> wrote:
Hi,
could you please help me solve this issue? I'm getting crazy!

Before the nginx update my client worked perfectly: it posted files to my website without any delay.

How, after nginx update (ubuntu 16.04 LTS) I've got this issue:

- the client posts files successfully but the answer of the post is delayed. The more the file is bigger, the more the answer is delayed.

I put a sniffer into the website' server and I noticed that the nginx receives the post but it waits to transfer the file to php-fpm process, so also the answer to the client is delayed

The nginx server is:

nginx/1.10.0 (Ubuntu) and its conf is:

-----
user www-data;
worker_processes auto;
pid /run/nginx.pid;

events {
        worker_connections 768;
        # multi_accept on;
}

http {
        sendfile on;
        tcp_nodelay on;
        keepalive_timeout 65;
        types_hash_max_size 2048;
        client_max_body_size 0;
        log_not_found off;
        server_name_in_redirect off;
        client_body_timeout 120s;
        autoindex off;
        include /etc/nginx/mime.types;
        default_type application/octet-stream;
        ssl_protocols TLSv1 TLSv1.1 TLSv1.2; # Dropping SSLv3, ref: POODLE
        ssl_prefer_server_ciphers on;
        access_log /var/log/nginx/access.log;
        error_log /var/log/nginx/error.log info;
        gzip on;
        gzip_disable "msie6";
        gzip_types text/plain text/css application/json application/javascript text/xml application/xml application/xml+rss text/javascript;
        include /etc/nginx/conf.d/*.conf;
        include /etc/nginx/sites-enabled/*;
---

and website's php-fpm conf is:

server {
  listen                    80;
  server_name               test.it;
  server_name_in_redirect   off;
  autoindex                 off;
  client_max_body_size      500m;
  index                     index.html;
  root                      /home/test/test;
  location ~ \.(php|html|htm|php3)$ {
    try_files     $uri 404;
    fastcgi_pass  unix:/run/php/mdtest-fpm.sock;
    include       fastcgi_params;
  }
}

fastcgi_params config:

fastcgi_param  QUERY_STRING       $query_string;
fastcgi_param  REQUEST_METHOD     $request_method;
fastcgi_param  CONTENT_TYPE       $content_type;
fastcgi_param  CONTENT_LENGTH     $content_length;

fastcgi_param  SCRIPT_NAME        $fastcgi_script_name;
fastcgi_param  REQUEST_URI        $request_uri;
fastcgi_param  DOCUMENT_URI       $document_uri;
fastcgi_param  DOCUMENT_ROOT      $document_root;
fastcgi_param  SERVER_PROTOCOL    $server_protocol;
fastcgi_param  REQUEST_SCHEME     $scheme;
fastcgi_param  HTTPS              $https if_not_empty;

fastcgi_param  GATEWAY_INTERFACE  CGI/1.1;
fastcgi_param  SERVER_SOFTWARE    nginx/$nginx_version;

fastcgi_param  REMOTE_ADDR        $remote_addr;
fastcgi_param  REMOTE_PORT        $remote_port;
fastcgi_param  SERVER_ADDR        $server_addr;
fastcgi_param  SERVER_PORT        $server_port;
#fastcgi_param  SERVER_NAME        $server_name;
fastcgi_param  SERVER_NAME       $http_host;

# PHP only, required if PHP was built with --enable-force-cgi-redirect
fastcgi_param  REDIRECT_STATUS    200;

fastcgi_param SCRIPT_FILENAME     $document_root$fastcgi_script_name;


Thanks a lot,
Andrea


ANDREA SORACCHI
<a href="tel:+393290512702" style="text-decoration: none; color: #11254b;" target="_blank" data-mce-href="tel:+393290512702" data-mce-style="text-decoration: none; color: #11254b;">+39 329 0512704
System Engineer

+39 0521 24 77 91
[hidden email]


_______________________________________________
nginx mailing list
[hidden email]
http://mailman.nginx.org/mailman/listinfo/nginx

hi,

can you show the related wireshark data, how long is the response delayed by? and anything else like retransmits or anything else?

any SElinux security throtelling taking place? anything in dmesg?

--
Payam Tarverdyan Chychi
Network Security Specialist / Network Engineer

_______________________________________________
nginx mailing list
[hidden email]
http://mailman.nginx.org/mailman/listinfo/nginx

_______________________________________________
nginx mailing list
[hidden email]
http://mailman.nginx.org/mailman/listinfo/nginx



--
Anoop P Alias 
_______________________________________________
nginx mailing list
[hidden email]
http://mailman.nginx.org/mailman/listinfo/nginx
--
Payam Tarverdyan Chychi
Network Security Specialist / Network Engineer

--
Questo messaggio e' stato analizzato ed e' risultato non infetto.
This message was scanned and is believed to be clean.


_______________________________________________
nginx mailing list
[hidden email]
http://mailman.nginx.org/mailman/listinfo/nginx



_______________________________________________
nginx mailing list
[hidden email]
http://mailman.nginx.org/mailman/listinfo/nginx

--
Questo messaggio e' stato analizzato ed e' risultato non infetto.
This message was scanned and is believed to be clean.


_______________________________________________
nginx mailing list
[hidden email]
http://mailman.nginx.org/mailman/listinfo/nginx

_______________________________________________
nginx mailing list
[hidden email]
http://mailman.nginx.org/mailman/listinfo/nginx
Reply | Threaded
Open this post in threaded view
|

Re: Strange issue after nginx update

Richard Stanway
Have you enabled the slowlog and request_slowlog_timeout directives in the php-fpm pool that this request is going to? These may provide a hint as to where the problem lies.

On Fri, Jun 30, 2017 at 1:46 AM, Andrea Soracchi <[hidden email]> wrote:
Hi Richard,

I have the same problem with fastcgi_request_buffering[1] set to off:

*21 http read client request body
2017/06/30 01:33:54 [debug] 19140#19140: *21 recv: fd:11 -1 of 1744
2017/06/30 01:33:54 [debug] 19140#19140: *21 recv() not ready (11: Resource temporarily unavailable)
2017/06/30 01:33:54 [debug] 19140#19140: *21 http client request body recv -2
2017/06/30 01:33:54 [debug] 19140#19140: *21 http client request body rest 8077
2017/06/30 01:33:54 [debug] 19140#19140: *21 event timer: 11, old: 1498779354309, new: 1498779354309
2017/06/30 01:33:54 [debug] 19140#19140: *21 http run request: "/index2.php?"
2017/06/30 01:33:54 [debug] 19140#19140: *21 http upstream check client, write event:1, "/index2.php"
2017/06/30 01:33:54 [debug] 19140#19140: *21 http upstream recv(): -1 (11: Resource temporarily unavailable)
2017/06/30 01:33:54 [debug] 19140#19140: *21 http upstream request: "/index2.php?"
2017/06/30 01:33:54 [debug] 19140#19140: *21 http upstream send request handler
2017/06/30 01:33:54 [debug] 19140#19140: *21 http upstream send request
2017/06/30 01:33:54 [debug] 19140#19140: *21 http upstream send request body
2017/06/30 01:33:54 [debug] 19140#19140: *21 fastcgi output filter
2017/06/30 01:33:54 [debug] 19140#19140: *21 chain writer in: 0000000000000000
2017/06/30 01:33:54 [debug] 19140#19140: *21 http read client request body
2017/06/30 01:33:54 [debug] 19140#19140: *21 recv: fd:11 -1 of 1744
2017/06/30 01:33:54 [debug] 19140#19140: *21 recv() not ready (11: Resource temporarily unavailable)
2017/06/30 01:33:54 [debug] 19140#19140: *21 http client request body recv -2
2017/06/30 01:33:54 [debug] 19140#19140: *21 http client request body rest 8077
2017/06/30 01:33:54 [debug] 19140#19140: *21 event timer: 11, old: 1498779354309, new: 1498779354309
2017/06/30 01:33:54 [debug] 19140#19140: *21 http run request: "/index2.php?"
2017/06/30 01:33:54 [debug] 19140#19140: *21 http upstream read request handler
2017/06/30 01:33:54 [debug] 19140#19140: *21 http upstream send request
2017/06/30 01:33:54 [debug] 19140#19140: *21 http upstream send request body
2017/06/30 01:33:54 [debug] 19140#19140: *21 http read client request body
2017/06/30 01:33:54 [debug] 19140#19140: *21 recv: fd:11 1744 of 1744
2017/06/30 01:33:54 [debug] 19140#19140: *21 http client request body recv 1744

@Payam I try worker_process to 1 but same result.

The php-fpm log is free of errors...




ANDREA SORACCHI
<a href="tel:+393290512702" style="text-decoration:none;color:#11254b" target="_blank">+39 329 0512704
System Engineer

+39 0521 24 77 91
[hidden email]



Da: "Richard Stanway" <[hidden email]>
A: "nginx" <[hidden email]>
Inviato: Giovedì, 29 giugno 2017 18:47:36

Oggetto: Re: Strange issue after nginx update

If you want to stream the upload directly to your backend, you should consider fastcgi_request_buffering[1].
The problem is most likely with your PHP backend though, you should examine why it takes so long to process the request.


On Thu, Jun 29, 2017 at 12:01 PM, Andrea Soracchi <[hidden email]> wrote:
Hi Payam,

the problem is between Nginx and Php-fpm, but

I have set the debug level log to nginx and php-fpm.

Nginx:

2017/06/29 10:05:14 [warn] 5252#5252: *1613 a client request body is buffered to a temporary file /var/lib/nginx/body/0000000044, client: 192.168.18.18, server: andrea.eoraptor3.netbuilder.it, request: "POST /index2.php HTTP/1.1", host: "andrea.eoraptor3.netbuilder.it"
2017/06/29 10:05:14 [debug] 5252#5252: *1613 write: 9, 0000560D636FBE70, 8192, 0
2017/06/29 10:05:14 [debug] 5252#5252: *1613 recv: fd:3 5488 of 8192
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http client request body recv 5488
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http client request body rest 54606013
2017/06/29 10:05:14 [debug] 5252#5252: *1613 recv: fd:3 -1 of 2704
2017/06/29 10:05:14 [debug] 5252#5252: *1613 recv() not ready (11: Resource temporarily unavailable)
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http client request body recv -2
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http client request body rest 54606013
2017/06/29 10:05:14 [debug] 5252#5252: *1613 event timer: 3, old: 1498723634292, new: 1498723634292
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http run request: "/index2.php?"
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http read client request body
2017/06/29 10:05:14 [debug] 5252#5252: *1613 recv: fd:3 1368 of 2704
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http client request body recv 1368
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http client request body rest 54606013
2017/06/29 10:05:14 [debug] 5252#5252: *1613 recv: fd:3 -1 of 1336
2017/06/29 10:05:14 [debug] 5252#5252: *1613 recv() not ready (11: Resource temporarily unavailable)
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http client request body recv -2
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http client request body rest 54606013
2017/06/29 10:05:14 [debug] 5252#5252: *1613 event timer: 3, old: 1498723634292, new: 1498723634293
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http run request: "/index2.php?"
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http read client request body
2017/06/29 10:05:14 [debug] 5252#5252: *1613 recv: fd:3 1336 of 1336
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http client request body recv 1336
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http body new buf t:1 f:0 0000560D636FBE70, pos 0000560D636FBE70, size: 8192 file: 0, size: 0
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http write client request body, bufs 0000560D636F92C0
2017/06/29 10:05:14 [debug] 5252#5252: *1613 write: 9, 0000560D636FBE70, 8192, 8192
2017/06/29 10:05:14 [debug] 5252#5252: *1613 recv: fd:3 1400 of 8192
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http client request body recv 1400
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http client request body rest 54597821
2017/06/29 10:05:14 [debug] 5252#5252: *1613 recv: fd:3 -1 of 6792
2017/06/29 10:05:14 [debug] 5252#5252: *1613 recv() not ready (11: Resource temporarily unavailable)
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http client request body recv -2
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http client request body rest 54597821
2017/06/29 10:05:14 [debug] 5252#5252: *1613 event timer: 3, old: 1498723634292, new: 1498723634293
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http run request: "/index2.php?"
...
Repeated several times
...
...
2017/06/29 10:05:15 [debug] 5252#5252: *1613 writev() not ready (11: Resource temporarily unavailable)
2017/06/29 10:05:15 [debug] 5252#5252: *1613 chain writer out: 0000560D637FE780
2017/06/29 10:05:15 [debug] 5252#5252: *1613 event timer: 10, old: 1498723575096, new: 1498723575151
2017/06/29 10:05:15 [debug] 5252#5252: *1613 http upstream request: "/index2.php?"
2017/06/29 10:05:15 [debug] 5252#5252: *1613 http upstream send request handler
2017/06/29 10:05:15 [debug] 5252#5252: *1613 http upstream send request
2017/06/29 10:05:15 [debug] 5252#5252: *1613 http upstream send request body
2017/06/29 10:05:15 [debug] 5252#5252: *1613 chain writer in: 0000560D637FE780
2017/06/29 10:05:15 [debug] 5252#5252: *1613 writev: 8 of 8
2017/06/29 10:05:15 [debug] 5252#5252: *1613 sendfile: @54591488 22717
2017/06/29 10:05:15 [debug] 5252#5252: *1613 sendfile: 22717 of 22717 @54591488
2017/06/29 10:05:15 [debug] 5252#5252: *1613 writev: 11 of 11
2017/06/29 10:05:15 [debug] 5252#5252: *1613 chain writer out: 0000000000000000
2017/06/29 10:05:15 [debug] 5252#5252: *1613 event timer del: 10: 1498723575096
2017/06/29 10:05:15 [debug] 5252#5252: *1613 event timer add: 10: 300000:1498723815151
2017/06/29 10:05:15 [debug] 5252#5252: *1613 http upstream request: "/index2.php?"
2017/06/29 10:05:15 [debug] 5252#5252: *1613 http upstream dummy handler
2017/06/29 10:05:15 [debug] 5252#5252: *1613 http upstream request: "/index2.php?"
2017/06/29 10:05:15 [debug] 5252#5252: *1613 http upstream dummy handler
2017/06/29 10:05:40 [debug] 5252#5252: *1613 http upstream request: "/index2.php?"
2017/06/29 10:05:40 [debug] 5252#5252: *1613 http upstream process header
2017/06/29 10:05:40 [debug] 5252#5252: *1613 malloc: 0000560D637FF560:4096
2017/06/29 10:05:40 [debug] 5252#5252: *1613 recv: fd:10 56 of 4096
2017/06/29 10:05:40 [debug] 5252#5252: *1613 http fastcgi record byte: 01
2017/06/29 10:05:40 [debug] 5252#5252: *1613 http fastcgi record byte: 06
2017/06/29 10:05:40 [debug] 5252#5252: *1613 http fastcgi record byte: 00
2017/06/29 10:05:40 [debug] 5252#5252: *1613 http fastcgi record byte: 01
2017/06/29 10:05:40 [debug] 5252#5252: *1613 http fastcgi record byte: 00
2017/06/29 10:05:40 [debug] 5252#5252: *1613 http fastcgi record byte: 1D
2017/06/29 10:05:40 [debug] 5252#5252: *1613 http fastcgi record byte: 03
2017/06/29 10:05:40 [debug] 5252#5252: *1613 http fastcgi record byte: 00
2017/06/29 10:05:40 [debug] 5252#5252: *1613 http fastcgi record length: 29
2017/06/29 10:05:40 [debug] 5252#5252: *1613 http fastcgi parser: 0
2017/06/29 10:05:40 [debug] 5252#5252: *1613 http fastcgi header: "Content-type: text/html"
2017/06/29 10:05:40 [debug] 5252#5252: *1613 http fastcgi parser: 1
2017/06/29 10:05:40 [debug] 5252#5252: *1613 http fastcgi header done
2017/06/29 10:05:40 [debug] 5252#5252: *1613 xslt filter header
2017/06/29 10:05:40 [debug] 5252#5252: *1613 HTTP/1.1 200 OK^M


Php-fpm:

PHPFPM

[29-Jun-2017 10:05:14.699514] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 0 active children, 3 spare children, 3 running children. Spawning rate 1

[29-Jun-2017 10:05:16.700710] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:17.701773] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:18.702842] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:19.703778] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:20.705400] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:21.706471] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:22.707537] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:23.707779] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:24.708839] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:25.710378] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:26.710841] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:27.711798] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:28.712864] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:29.713932] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:30.715523] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:31.715785] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:32.716851] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:32.716851] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:33.717931] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:34.719001] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:35.720280] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:36.720662] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:37.721725] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:38.722791] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:39.723785] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1

[29-Jun-2017 10:05:40.725342] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 0 active children, 3 spare children, 3 running children. Spawning rate 1


Any idea?

Thanks a lot,
Andrea

ANDREA SORACCHI
<a href="tel:+393290512702" style="text-decoration:none;color:#11254b" target="_blank">+39 329 0512704
System Engineer

+39 0521 24 77 91
[hidden email]



From: "Payam Chychi" <[hidden email]>
To: [hidden email]
Sent: Giovedì, 29 giugno 2017 6:38:09
Subject: Re: Strange issue after nginx update


Are you seeing any errors in your php log?
are you connecting to the hostname or ip?

Also, make sure your interface is connected at full duplex. whats the output of "ethtool eth0" replace eth0 with your nic in use.

not sure what else really...
id say to check dns but its all local to you

- Payam


On Wed, Jun 28, 2017 at 9:01 PM Anoop Alias <[hidden email]> wrote:
give a try changing the nameservers in /etc/resolv.conf 


On Thu, Jun 29, 2017 at 3:51 AM, Andrea Soracchi <[hidden email]> wrote:
Hi,

I have attached part of the ettercap log.

I have posted a test file of 40MB.

The delay  is 29 second:

 from the last file's chunk at 23:56:06
 
 to the response of  index2.php at 23:56:35

The nginx's log show:

192.168.18.18 - - [28/Jun/2017:23:56:35 +0200] "POST /index2.php HTTP/1.1" 200 37 "-" "Generic Client"

Nothing retransmits, SElinux isn't installed and apparmor is stopped.

Nothing in dmesg...

Thanks a lot,


ANDREA SORACCHI
<a href="tel:+393290512702" style="text-decoration:none;color:#11254b" target="_blank">+39 329 0512704
System Engineer

+39 0521 24 77 91
[hidden email]


Da: "Payam Chychi" <[hidden email]>
A: "nginx" <[hidden email]>
Inviato: Mercoledì, 28 giugno 2017 19:56:04
Oggetto: Re: Strange issue after nginx update


On Wed, Jun 28, 2017 at 8:41 AM Andrea Soracchi <[hidden email]> wrote:
Hi,
could you please help me solve this issue? I'm getting crazy!

Before the nginx update my client worked perfectly: it posted files to my website without any delay.

How, after nginx update (ubuntu 16.04 LTS) I've got this issue:

- the client posts files successfully but the answer of the post is delayed. The more the file is bigger, the more the answer is delayed.

I put a sniffer into the website' server and I noticed that the nginx receives the post but it waits to transfer the file to php-fpm process, so also the answer to the client is delayed

The nginx server is:

nginx/1.10.0 (Ubuntu) and its conf is:

-----
user www-data;
worker_processes auto;
pid /run/nginx.pid;

events {
        worker_connections 768;
        # multi_accept on;
}

http {
        sendfile on;
        tcp_nodelay on;
        keepalive_timeout 65;
        types_hash_max_size 2048;
        client_max_body_size 0;
        log_not_found off;
        server_name_in_redirect off;
        client_body_timeout 120s;
        autoindex off;
        include /etc/nginx/mime.types;
        default_type application/octet-stream;
        ssl_protocols TLSv1 TLSv1.1 TLSv1.2; # Dropping SSLv3, ref: POODLE
        ssl_prefer_server_ciphers on;
        access_log /var/log/nginx/access.log;
        error_log /var/log/nginx/error.log info;
        gzip on;
        gzip_disable "msie6";
        gzip_types text/plain text/css application/json application/javascript text/xml application/xml application/xml+rss text/javascript;
        include /etc/nginx/conf.d/*.conf;
        include /etc/nginx/sites-enabled/*;
---

and website's php-fpm conf is:

server {
  listen                    80;
  server_name               test.it;
  server_name_in_redirect   off;
  autoindex                 off;
  client_max_body_size      500m;
  index                     index.html;
  root                      /home/test/test;
  location ~ \.(php|html|htm|php3)$ {
    try_files     $uri 404;
    fastcgi_pass  unix:/run/php/mdtest-fpm.sock;
    include       fastcgi_params;
  }
}

fastcgi_params config:

fastcgi_param  QUERY_STRING       $query_string;
fastcgi_param  REQUEST_METHOD     $request_method;
fastcgi_param  CONTENT_TYPE       $content_type;
fastcgi_param  CONTENT_LENGTH     $content_length;

fastcgi_param  SCRIPT_NAME        $fastcgi_script_name;
fastcgi_param  REQUEST_URI        $request_uri;
fastcgi_param  DOCUMENT_URI       $document_uri;
fastcgi_param  DOCUMENT_ROOT      $document_root;
fastcgi_param  SERVER_PROTOCOL    $server_protocol;
fastcgi_param  REQUEST_SCHEME     $scheme;
fastcgi_param  HTTPS              $https if_not_empty;

fastcgi_param  GATEWAY_INTERFACE  CGI/1.1;
fastcgi_param  SERVER_SOFTWARE    nginx/$nginx_version;

fastcgi_param  REMOTE_ADDR        $remote_addr;
fastcgi_param  REMOTE_PORT        $remote_port;
fastcgi_param  SERVER_ADDR        $server_addr;
fastcgi_param  SERVER_PORT        $server_port;
#fastcgi_param  SERVER_NAME        $server_name;
fastcgi_param  SERVER_NAME       $http_host;

# PHP only, required if PHP was built with --enable-force-cgi-redirect
fastcgi_param  REDIRECT_STATUS    200;

fastcgi_param SCRIPT_FILENAME     $document_root$fastcgi_script_name;


Thanks a lot,
Andrea


ANDREA SORACCHI
<a href="tel:+393290512702" style="text-decoration:none;color:#11254b" target="_blank">+39 329 0512704
System Engineer

+39 0521 24 77 91
[hidden email]


_______________________________________________
nginx mailing list
[hidden email]
http://mailman.nginx.org/mailman/listinfo/nginx

hi,

can you show the related wireshark data, how long is the response delayed by? and anything else like retransmits or anything else?

any SElinux security throtelling taking place? anything in dmesg?

--
Payam Tarverdyan Chychi
Network Security Specialist / Network Engineer

_______________________________________________
nginx mailing list
[hidden email]
http://mailman.nginx.org/mailman/listinfo/nginx

_______________________________________________
nginx mailing list
[hidden email]
http://mailman.nginx.org/mailman/listinfo/nginx



--
Anoop P Alias 
_______________________________________________
nginx mailing list
[hidden email]
http://mailman.nginx.org/mailman/listinfo/nginx
--
Payam Tarverdyan Chychi
Network Security Specialist / Network Engineer

--
Questo messaggio e' stato analizzato ed e' risultato non infetto.
This message was scanned and is believed to be clean.


_______________________________________________
nginx mailing list
[hidden email]
http://mailman.nginx.org/mailman/listinfo/nginx



_______________________________________________
nginx mailing list
[hidden email]
http://mailman.nginx.org/mailman/listinfo/nginx

--
Questo messaggio e' stato analizzato ed e' risultato non infetto.
This message was scanned and is believed to be clean.


_______________________________________________
nginx mailing list
[hidden email]
http://mailman.nginx.org/mailman/listinfo/nginx

_______________________________________________
nginx mailing list
[hidden email]
http://mailman.nginx.org/mailman/listinfo/nginx


_______________________________________________
nginx mailing list
[hidden email]
http://mailman.nginx.org/mailman/listinfo/nginx
Reply | Threaded
Open this post in threaded view
|

Re: Strange issue after nginx update

Andrea Soracchi-2
Hi Richard,

I have enabled the
slowlog but nothing is written in the log.

When nginx successfully transfers to php-fpm, execution of the latter is fast.

Another log?


ANDREA SORACCHI
<a href="tel:+393290512702" style="text-decoration: none; color: rgb(17, 37, 75);" data-mce-href="tel:+393290512702" data-mce-style="text-decoration: none; color: #11254b;">+39 329 0512704
System Engineer

+39 0521 24 77 91
[hidden email]



From: "Richard Stanway" <[hidden email]>
To: [hidden email]
Sent: Venerdì, 30 giugno 2017 2:17:08
Subject: Re: Strange issue after nginx update

Have you enabled the slowlog and request_slowlog_timeout directives in the php-fpm pool that this request is going to? These may provide a hint as to where the problem lies.

On Fri, Jun 30, 2017 at 1:46 AM, Andrea Soracchi <[hidden email]> wrote:
Hi Richard,

I have the same problem with fastcgi_request_buffering[1] set to off:

*21 http read client request body
2017/06/30 01:33:54 [debug] 19140#19140: *21 recv: fd:11 -1 of 1744
2017/06/30 01:33:54 [debug] 19140#19140: *21 recv() not ready (11: Resource temporarily unavailable)
2017/06/30 01:33:54 [debug] 19140#19140: *21 http client request body recv -2
2017/06/30 01:33:54 [debug] 19140#19140: *21 http client request body rest 8077
2017/06/30 01:33:54 [debug] 19140#19140: *21 event timer: 11, old: 1498779354309, new: 1498779354309
2017/06/30 01:33:54 [debug] 19140#19140: *21 http run request: "/index2.php?"
2017/06/30 01:33:54 [debug] 19140#19140: *21 http upstream check client, write event:1, "/index2.php"
2017/06/30 01:33:54 [debug] 19140#19140: *21 http upstream recv(): -1 (11: Resource temporarily unavailable)
2017/06/30 01:33:54 [debug] 19140#19140: *21 http upstream request: "/index2.php?"
2017/06/30 01:33:54 [debug] 19140#19140: *21 http upstream send request handler
2017/06/30 01:33:54 [debug] 19140#19140: *21 http upstream send request
2017/06/30 01:33:54 [debug] 19140#19140: *21 http upstream send request body
2017/06/30 01:33:54 [debug] 19140#19140: *21 fastcgi output filter
2017/06/30 01:33:54 [debug] 19140#19140: *21 chain writer in: 0000000000000000
2017/06/30 01:33:54 [debug] 19140#19140: *21 http read client request body
2017/06/30 01:33:54 [debug] 19140#19140: *21 recv: fd:11 -1 of 1744
2017/06/30 01:33:54 [debug] 19140#19140: *21 recv() not ready (11: Resource temporarily unavailable)
2017/06/30 01:33:54 [debug] 19140#19140: *21 http client request body recv -2
2017/06/30 01:33:54 [debug] 19140#19140: *21 http client request body rest 8077
2017/06/30 01:33:54 [debug] 19140#19140: *21 event timer: 11, old: 1498779354309, new: 1498779354309
2017/06/30 01:33:54 [debug] 19140#19140: *21 http run request: "/index2.php?"
2017/06/30 01:33:54 [debug] 19140#19140: *21 http upstream read request handler
2017/06/30 01:33:54 [debug] 19140#19140: *21 http upstream send request
2017/06/30 01:33:54 [debug] 19140#19140: *21 http upstream send request body
2017/06/30 01:33:54 [debug] 19140#19140: *21 http read client request body
2017/06/30 01:33:54 [debug] 19140#19140: *21 recv: fd:11 1744 of 1744
2017/06/30 01:33:54 [debug] 19140#19140: *21 http client request body recv 1744

@Payam I try worker_process to 1 but same result.

The php-fpm log is free of errors...




ANDREA SORACCHI
<a href="tel:+393290512702" style="text-decoration: none; color: rgb(17, 37, 75);" target="_blank">+39 329 0512704
System Engineer

+39 0521 24 77 91
[hidden email]



Da: "Richard Stanway" <[hidden email]>
A: "nginx" <[hidden email]>
Inviato: Giovedì, 29 giugno 2017 18:47:36

Oggetto: Re: Strange issue after nginx update

If you want to stream the upload directly to your backend, you should consider fastcgi_request_buffering[1].
The problem is most likely with your PHP backend though, you should examine why it takes so long to process the request.


On Thu, Jun 29, 2017 at 12:01 PM, Andrea Soracchi <[hidden email]> wrote:
Hi Payam,

the problem is between Nginx and Php-fpm, but

I have set the debug level log to nginx and php-fpm.

Nginx:

2017/06/29 10:05:14 [warn] 5252#5252: *1613 a client request body is buffered to a temporary file /var/lib/nginx/body/0000000044, client: 192.168.18.18, server: andrea.eoraptor3.netbuilder.it, request: "POST /index2.php HTTP/1.1", host: "andrea.eoraptor3.netbuilder.it"
2017/06/29 10:05:14 [debug] 5252#5252: *1613 write: 9, 0000560D636FBE70, 8192, 0
2017/06/29 10:05:14 [debug] 5252#5252: *1613 recv: fd:3 5488 of 8192
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http client request body recv 5488
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http client request body rest 54606013
2017/06/29 10:05:14 [debug] 5252#5252: *1613 recv: fd:3 -1 of 2704
2017/06/29 10:05:14 [debug] 5252#5252: *1613 recv() not ready (11: Resource temporarily unavailable)
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http client request body recv -2
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http client request body rest 54606013
2017/06/29 10:05:14 [debug] 5252#5252: *1613 event timer: 3, old: 1498723634292, new: 1498723634292
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http run request: "/index2.php?"
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http read client request body
2017/06/29 10:05:14 [debug] 5252#5252: *1613 recv: fd:3 1368 of 2704
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http client request body recv 1368
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http client request body rest 54606013
2017/06/29 10:05:14 [debug] 5252#5252: *1613 recv: fd:3 -1 of 1336
2017/06/29 10:05:14 [debug] 5252#5252: *1613 recv() not ready (11: Resource temporarily unavailable)
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http client request body recv -2
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http client request body rest 54606013
2017/06/29 10:05:14 [debug] 5252#5252: *1613 event timer: 3, old: 1498723634292, new: 1498723634293
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http run request: "/index2.php?"
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http read client request body
2017/06/29 10:05:14 [debug] 5252#5252: *1613 recv: fd:3 1336 of 1336
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http client request body recv 1336
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http body new buf t:1 f:0 0000560D636FBE70, pos 0000560D636FBE70, size: 8192 file: 0, size: 0
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http write client request body, bufs 0000560D636F92C0
2017/06/29 10:05:14 [debug] 5252#5252: *1613 write: 9, 0000560D636FBE70, 8192, 8192
2017/06/29 10:05:14 [debug] 5252#5252: *1613 recv: fd:3 1400 of 8192
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http client request body recv 1400
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http client request body rest 54597821
2017/06/29 10:05:14 [debug] 5252#5252: *1613 recv: fd:3 -1 of 6792
2017/06/29 10:05:14 [debug] 5252#5252: *1613 recv() not ready (11: Resource temporarily unavailable)
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http client request body recv -2
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http client request body rest 54597821
2017/06/29 10:05:14 [debug] 5252#5252: *1613 event timer: 3, old: 1498723634292, new: 1498723634293
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http run request: "/index2.php?"
...
Repeated several times
...
...
2017/06/29 10:05:15 [debug] 5252#5252: *1613 writev() not ready (11: Resource temporarily unavailable)
2017/06/29 10:05:15 [debug] 5252#5252: *1613 chain writer out: 0000560D637FE780
2017/06/29 10:05:15 [debug] 5252#5252: *1613 event timer: 10, old: 1498723575096, new: 1498723575151
2017/06/29 10:05:15 [debug] 5252#5252: *1613 http upstream request: "/index2.php?"
2017/06/29 10:05:15 [debug] 5252#5252: *1613 http upstream send request handler
2017/06/29 10:05:15 [debug] 5252#5252: *1613 http upstream send request
2017/06/29 10:05:15 [debug] 5252#5252: *1613 http upstream send request body
2017/06/29 10:05:15 [debug] 5252#5252: *1613 chain writer in: 0000560D637FE780
2017/06/29 10:05:15 [debug] 5252#5252: *1613 writev: 8 of 8
2017/06/29 10:05:15 [debug] 5252#5252: *1613 sendfile: @54591488 22717
2017/06/29 10:05:15 [debug] 5252#5252: *1613 sendfile: 22717 of 22717 @54591488
2017/06/29 10:05:15 [debug] 5252#5252: *1613 writev: 11 of 11
2017/06/29 10:05:15 [debug] 5252#5252: *1613 chain writer out: 0000000000000000
2017/06/29 10:05:15 [debug] 5252#5252: *1613 event timer del: 10: 1498723575096
2017/06/29 10:05:15 [debug] 5252#5252: *1613 event timer add: 10: 300000:1498723815151
2017/06/29 10:05:15 [debug] 5252#5252: *1613 http upstream request: "/index2.php?"
2017/06/29 10:05:15 [debug] 5252#5252: *1613 http upstream dummy handler
2017/06/29 10:05:15 [debug] 5252#5252: *1613 http upstream request: "/index2.php?"
2017/06/29 10:05:15 [debug] 5252#5252: *1613 http upstream dummy handler
2017/06/29 10:05:40 [debug] 5252#5252: *1613 http upstream request: "/index2.php?"
2017/06/29 10:05:40 [debug] 5252#5252: *1613 http upstream process header
2017/06/29 10:05:40 [debug] 5252#5252: *1613 malloc: 0000560D637FF560:4096
2017/06/29 10:05:40 [debug] 5252#5252: *1613 recv: fd:10 56 of 4096
2017/06/29 10:05:40 [debug] 5252#5252: *1613 http fastcgi record byte: 01
2017/06/29 10:05:40 [debug] 5252#5252: *1613 http fastcgi record byte: 06
2017/06/29 10:05:40 [debug] 5252#5252: *1613 http fastcgi record byte: 00
2017/06/29 10:05:40 [debug] 5252#5252: *1613 http fastcgi record byte: 01
2017/06/29 10:05:40 [debug] 5252#5252: *1613 http fastcgi record byte: 00
2017/06/29 10:05:40 [debug] 5252#5252: *1613 http fastcgi record byte: 1D
2017/06/29 10:05:40 [debug] 5252#5252: *1613 http fastcgi record byte: 03
2017/06/29 10:05:40 [debug] 5252#5252: *1613 http fastcgi record byte: 00
2017/06/29 10:05:40 [debug] 5252#5252: *1613 http fastcgi record length: 29
2017/06/29 10:05:40 [debug] 5252#5252: *1613 http fastcgi parser: 0
2017/06/29 10:05:40 [debug] 5252#5252: *1613 http fastcgi header: "Content-type: text/html"
2017/06/29 10:05:40 [debug] 5252#5252: *1613 http fastcgi parser: 1
2017/06/29 10:05:40 [debug] 5252#5252: *1613 http fastcgi header done
2017/06/29 10:05:40 [debug] 5252#5252: *1613 xslt filter header
2017/06/29 10:05:40 [debug] 5252#5252: *1613 HTTP/1.1 200 OK^M


Php-fpm:

PHPFPM

[29-Jun-2017 10:05:14.699514] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 0 active children, 3 spare children, 3 running children. Spawning rate 1

[29-Jun-2017 10:05:16.700710] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:17.701773] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:18.702842] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:19.703778] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:20.705400] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:21.706471] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:22.707537] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:23.707779] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:24.708839] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:25.710378] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:26.710841] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:27.711798] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:28.712864] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:29.713932] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:30.715523] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:31.715785] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:32.716851] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:32.716851] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:33.717931] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:34.719001] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:35.720280] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:36.720662] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:37.721725] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:38.722791] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:39.723785] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1

[29-Jun-2017 10:05:40.725342] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 0 active children, 3 spare children, 3 running children. Spawning rate 1


Any idea?

Thanks a lot,
Andrea

ANDREA SORACCHI
<a href="tel:+393290512702" style="text-decoration: none; color: rgb(17, 37, 75);" target="_blank">+39 329 0512704
System Engineer

+39 0521 24 77 91
[hidden email]



From: "Payam Chychi" <[hidden email]>
To: [hidden email]
Sent: Giovedì, 29 giugno 2017 6:38:09
Subject: Re: Strange issue after nginx update


Are you seeing any errors in your php log?
are you connecting to the hostname or ip?

Also, make sure your interface is connected at full duplex. whats the output of "ethtool eth0" replace eth0 with your nic in use.

not sure what else really...
id say to check dns but its all local to you

- Payam


On Wed, Jun 28, 2017 at 9:01 PM Anoop Alias <[hidden email]> wrote:
give a try changing the nameservers in /etc/resolv.conf 


On Thu, Jun 29, 2017 at 3:51 AM, Andrea Soracchi <[hidden email]> wrote:
Hi,

I have attached part of the ettercap log.

I have posted a test file of 40MB.

The delay  is 29 second:

 from the last file's chunk at 23:56:06
 
 to the response of  index2.php at 23:56:35

The nginx's log show:

192.168.18.18 - - [28/Jun/2017:23:56:35 +0200] "POST /index2.php HTTP/1.1" 200 37 "-" "Generic Client"

Nothing retransmits, SElinux isn't installed and apparmor is stopped.

Nothing in dmesg...

Thanks a lot,


ANDREA SORACCHI
<a href="tel:+393290512702" style="text-decoration: none; color: rgb(17, 37, 75);" target="_blank">+39 329 0512704
System Engineer

+39 0521 24 77 91
[hidden email]


Da: "Payam Chychi" <[hidden email]>
A: "nginx" <[hidden email]>
Inviato: Mercoledì, 28 giugno 2017 19:56:04
Oggetto: Re: Strange issue after nginx update


On Wed, Jun 28, 2017 at 8:41 AM Andrea Soracchi <[hidden email]> wrote:
Hi,
could you please help me solve this issue? I'm getting crazy!

Before the nginx update my client worked perfectly: it posted files to my website without any delay.

How, after nginx update (ubuntu 16.04 LTS) I've got this issue:

- the client posts files successfully but the answer of the post is delayed. The more the file is bigger, the more the answer is delayed.

I put a sniffer into the website' server and I noticed that the nginx receives the post but it waits to transfer the file to php-fpm process, so also the answer to the client is delayed

The nginx server is:

nginx/1.10.0 (Ubuntu) and its conf is:

-----
user www-data;
worker_processes auto;
pid /run/nginx.pid;

events {
        worker_connections 768;
        # multi_accept on;
}

http {
        sendfile on;
        tcp_nodelay on;
        keepalive_timeout 65;
        types_hash_max_size 2048;
        client_max_body_size 0;
        log_not_found off;
        server_name_in_redirect off;
        client_body_timeout 120s;
        autoindex off;
        include /etc/nginx/mime.types;
        default_type application/octet-stream;
        ssl_protocols TLSv1 TLSv1.1 TLSv1.2; # Dropping SSLv3, ref: POODLE
        ssl_prefer_server_ciphers on;
        access_log /var/log/nginx/access.log;
        error_log /var/log/nginx/error.log info;
        gzip on;
        gzip_disable "msie6";
        gzip_types text/plain text/css application/json application/javascript text/xml application/xml application/xml+rss text/javascript;
        include /etc/nginx/conf.d/*.conf;
        include /etc/nginx/sites-enabled/*;
---

and website's php-fpm conf is:

server {
  listen                    80;
  server_name               test.it;
  server_name_in_redirect   off;
  autoindex                 off;
  client_max_body_size      500m;
  index                     index.html;
  root                      /home/test/test;
  location ~ \.(php|html|htm|php3)$ {
    try_files     $uri 404;
    fastcgi_pass  unix:/run/php/mdtest-fpm.sock;
    include       fastcgi_params;
  }
}

fastcgi_params config:

fastcgi_param  QUERY_STRING       $query_string;
fastcgi_param  REQUEST_METHOD     $request_method;
fastcgi_param  CONTENT_TYPE       $content_type;
fastcgi_param  CONTENT_LENGTH     $content_length;

fastcgi_param  SCRIPT_NAME        $fastcgi_script_name;
fastcgi_param  REQUEST_URI        $request_uri;
fastcgi_param  DOCUMENT_URI       $document_uri;
fastcgi_param  DOCUMENT_ROOT      $document_root;
fastcgi_param  SERVER_PROTOCOL    $server_protocol;
fastcgi_param  REQUEST_SCHEME     $scheme;
fastcgi_param  HTTPS              $https if_not_empty;

fastcgi_param  GATEWAY_INTERFACE  CGI/1.1;
fastcgi_param  SERVER_SOFTWARE    nginx/$nginx_version;

fastcgi_param  REMOTE_ADDR        $remote_addr;
fastcgi_param  REMOTE_PORT        $remote_port;
fastcgi_param  SERVER_ADDR        $server_addr;
fastcgi_param  SERVER_PORT        $server_port;
#fastcgi_param  SERVER_NAME        $server_name;
fastcgi_param  SERVER_NAME       $http_host;

# PHP only, required if PHP was built with --enable-force-cgi-redirect
fastcgi_param  REDIRECT_STATUS    200;

fastcgi_param SCRIPT_FILENAME     $document_root$fastcgi_script_name;


Thanks a lot,
Andrea


ANDREA SORACCHI
<a href="tel:+393290512702" style="text-decoration: none; color: rgb(17, 37, 75);" target="_blank">+39 329 0512704
System Engineer

+39 0521 24 77 91
[hidden email]


_______________________________________________
nginx mailing list
[hidden email]
http://mailman.nginx.org/mailman/listinfo/nginx

hi,

can you show the related wireshark data, how long is the response delayed by? and anything else like retransmits or anything else?

any SElinux security throtelling taking place? anything in dmesg?

--
Payam Tarverdyan Chychi
Network Security Specialist / Network Engineer

_______________________________________________
nginx mailing list
[hidden email]
http://mailman.nginx.org/mailman/listinfo/nginx

_______________________________________________
nginx mailing list
[hidden email]
http://mailman.nginx.org/mailman/listinfo/nginx



--
Anoop P Alias 
_______________________________________________
nginx mailing list
[hidden email]
http://mailman.nginx.org/mailman/listinfo/nginx
--
Payam Tarverdyan Chychi
Network Security Specialist / Network Engineer

--
Questo messaggio e' stato analizzato ed e' risultato non infetto.
This message was scanned and is believed to be clean.


_______________________________________________
nginx mailing list
[hidden email]
http://mailman.nginx.org/mailman/listinfo/nginx



_______________________________________________
nginx mailing list
[hidden email]
http://mailman.nginx.org/mailman/listinfo/nginx

--
Questo messaggio e' stato analizzato ed e' risultato non infetto.
This message was scanned and is believed to be clean.


_______________________________________________
nginx mailing list
[hidden email]
http://mailman.nginx.org/mailman/listinfo/nginx

_______________________________________________
nginx mailing list
[hidden email]
http://mailman.nginx.org/mailman/listinfo/nginx

--
Questo messaggio e' stato analizzato ed e' risultato non infetto.
This message was scanned and is believed to be clean.


_______________________________________________
nginx mailing list
[hidden email]
http://mailman.nginx.org/mailman/listinfo/nginx


_______________________________________________
nginx mailing list
[hidden email]
http://mailman.nginx.org/mailman/listinfo/nginx
Reply | Threaded
Open this post in threaded view
|

Re: Strange issue after nginx update

Andrea Soracchi-2
Hi,

same configuration with php7.1-fpm no problem, no delay with post!!!

My application doesn't work with php7.1, I'm very very desolated.

Any other idea?



ANDREA SORACCHI
<a href="tel:+393290512702" style="text-decoration: none; color: rgb(17, 37, 75);" data-mce-href="tel:+393290512702" data-mce-style="text-decoration: none; color: #11254b;">+39 329 0512704
System Engineer

+39 0521 24 77 91
[hidden email]



From: "Andrea Soracchi" <[hidden email]>
To: [hidden email]
Sent: Venerdì, 30 giugno 2017 10:00:40
Subject: Re: Strange issue after nginx update

Hi Richard,

I have enabled the
slowlog but nothing is written in the log.

When nginx successfully transfers to php-fpm, execution of the latter is fast.

Another log?


ANDREA SORACCHI
<a href="tel:+393290512702" style="text-decoration: none; color: rgb(17, 37, 75);" target="_blank">+39 329 0512704
System Engineer

+39 0521 24 77 91
[hidden email]



From: "Richard Stanway" <[hidden email]>
To: [hidden email]
Sent: Venerdì, 30 giugno 2017 2:17:08
Subject: Re: Strange issue after nginx update

Have you enabled the slowlog and request_slowlog_timeout directives in the php-fpm pool that this request is going to? These may provide a hint as to where the problem lies.

On Fri, Jun 30, 2017 at 1:46 AM, Andrea Soracchi <[hidden email]> wrote:
Hi Richard,

I have the same problem with fastcgi_request_buffering[1] set to off:

*21 http read client request body
2017/06/30 01:33:54 [debug] 19140#19140: *21 recv: fd:11 -1 of 1744
2017/06/30 01:33:54 [debug] 19140#19140: *21 recv() not ready (11: Resource temporarily unavailable)
2017/06/30 01:33:54 [debug] 19140#19140: *21 http client request body recv -2
2017/06/30 01:33:54 [debug] 19140#19140: *21 http client request body rest 8077
2017/06/30 01:33:54 [debug] 19140#19140: *21 event timer: 11, old: 1498779354309, new: 1498779354309
2017/06/30 01:33:54 [debug] 19140#19140: *21 http run request: "/index2.php?"
2017/06/30 01:33:54 [debug] 19140#19140: *21 http upstream check client, write event:1, "/index2.php"
2017/06/30 01:33:54 [debug] 19140#19140: *21 http upstream recv(): -1 (11: Resource temporarily unavailable)
2017/06/30 01:33:54 [debug] 19140#19140: *21 http upstream request: "/index2.php?"
2017/06/30 01:33:54 [debug] 19140#19140: *21 http upstream send request handler
2017/06/30 01:33:54 [debug] 19140#19140: *21 http upstream send request
2017/06/30 01:33:54 [debug] 19140#19140: *21 http upstream send request body
2017/06/30 01:33:54 [debug] 19140#19140: *21 fastcgi output filter
2017/06/30 01:33:54 [debug] 19140#19140: *21 chain writer in: 0000000000000000
2017/06/30 01:33:54 [debug] 19140#19140: *21 http read client request body
2017/06/30 01:33:54 [debug] 19140#19140: *21 recv: fd:11 -1 of 1744
2017/06/30 01:33:54 [debug] 19140#19140: *21 recv() not ready (11: Resource temporarily unavailable)
2017/06/30 01:33:54 [debug] 19140#19140: *21 http client request body recv -2
2017/06/30 01:33:54 [debug] 19140#19140: *21 http client request body rest 8077
2017/06/30 01:33:54 [debug] 19140#19140: *21 event timer: 11, old: 1498779354309, new: 1498779354309
2017/06/30 01:33:54 [debug] 19140#19140: *21 http run request: "/index2.php?"
2017/06/30 01:33:54 [debug] 19140#19140: *21 http upstream read request handler
2017/06/30 01:33:54 [debug] 19140#19140: *21 http upstream send request
2017/06/30 01:33:54 [debug] 19140#19140: *21 http upstream send request body
2017/06/30 01:33:54 [debug] 19140#19140: *21 http read client request body
2017/06/30 01:33:54 [debug] 19140#19140: *21 recv: fd:11 1744 of 1744
2017/06/30 01:33:54 [debug] 19140#19140: *21 http client request body recv 1744

@Payam I try worker_process to 1 but same result.

The php-fpm log is free of errors...




ANDREA SORACCHI
<a href="tel:+393290512702" style="text-decoration: none; color: rgb(17, 37, 75);" target="_blank">+39 329 0512704
System Engineer

+39 0521 24 77 91
[hidden email]



Da: "Richard Stanway" <[hidden email]>
A: "nginx" <[hidden email]>
Inviato: Giovedì, 29 giugno 2017 18:47:36

Oggetto: Re: Strange issue after nginx update

If you want to stream the upload directly to your backend, you should consider fastcgi_request_buffering[1].
The problem is most likely with your PHP backend though, you should examine why it takes so long to process the request.


On Thu, Jun 29, 2017 at 12:01 PM, Andrea Soracchi <[hidden email]> wrote:
Hi Payam,

the problem is between Nginx and Php-fpm, but

I have set the debug level log to nginx and php-fpm.

Nginx:

2017/06/29 10:05:14 [warn] 5252#5252: *1613 a client request body is buffered to a temporary file /var/lib/nginx/body/0000000044, client: 192.168.18.18, server: andrea.eoraptor3.netbuilder.it, request: "POST /index2.php HTTP/1.1", host: "andrea.eoraptor3.netbuilder.it"
2017/06/29 10:05:14 [debug] 5252#5252: *1613 write: 9, 0000560D636FBE70, 8192, 0
2017/06/29 10:05:14 [debug] 5252#5252: *1613 recv: fd:3 5488 of 8192
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http client request body recv 5488
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http client request body rest 54606013
2017/06/29 10:05:14 [debug] 5252#5252: *1613 recv: fd:3 -1 of 2704
2017/06/29 10:05:14 [debug] 5252#5252: *1613 recv() not ready (11: Resource temporarily unavailable)
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http client request body recv -2
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http client request body rest 54606013
2017/06/29 10:05:14 [debug] 5252#5252: *1613 event timer: 3, old: 1498723634292, new: 1498723634292
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http run request: "/index2.php?"
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http read client request body
2017/06/29 10:05:14 [debug] 5252#5252: *1613 recv: fd:3 1368 of 2704
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http client request body recv 1368
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http client request body rest 54606013
2017/06/29 10:05:14 [debug] 5252#5252: *1613 recv: fd:3 -1 of 1336
2017/06/29 10:05:14 [debug] 5252#5252: *1613 recv() not ready (11: Resource temporarily unavailable)
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http client request body recv -2
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http client request body rest 54606013
2017/06/29 10:05:14 [debug] 5252#5252: *1613 event timer: 3, old: 1498723634292, new: 1498723634293
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http run request: "/index2.php?"
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http read client request body
2017/06/29 10:05:14 [debug] 5252#5252: *1613 recv: fd:3 1336 of 1336
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http client request body recv 1336
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http body new buf t:1 f:0 0000560D636FBE70, pos 0000560D636FBE70, size: 8192 file: 0, size: 0
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http write client request body, bufs 0000560D636F92C0
2017/06/29 10:05:14 [debug] 5252#5252: *1613 write: 9, 0000560D636FBE70, 8192, 8192
2017/06/29 10:05:14 [debug] 5252#5252: *1613 recv: fd:3 1400 of 8192
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http client request body recv 1400
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http client request body rest 54597821
2017/06/29 10:05:14 [debug] 5252#5252: *1613 recv: fd:3 -1 of 6792
2017/06/29 10:05:14 [debug] 5252#5252: *1613 recv() not ready (11: Resource temporarily unavailable)
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http client request body recv -2
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http client request body rest 54597821
2017/06/29 10:05:14 [debug] 5252#5252: *1613 event timer: 3, old: 1498723634292, new: 1498723634293
2017/06/29 10:05:14 [debug] 5252#5252: *1613 http run request: "/index2.php?"
...
Repeated several times
...
...
2017/06/29 10:05:15 [debug] 5252#5252: *1613 writev() not ready (11: Resource temporarily unavailable)
2017/06/29 10:05:15 [debug] 5252#5252: *1613 chain writer out: 0000560D637FE780
2017/06/29 10:05:15 [debug] 5252#5252: *1613 event timer: 10, old: 1498723575096, new: 1498723575151
2017/06/29 10:05:15 [debug] 5252#5252: *1613 http upstream request: "/index2.php?"
2017/06/29 10:05:15 [debug] 5252#5252: *1613 http upstream send request handler
2017/06/29 10:05:15 [debug] 5252#5252: *1613 http upstream send request
2017/06/29 10:05:15 [debug] 5252#5252: *1613 http upstream send request body
2017/06/29 10:05:15 [debug] 5252#5252: *1613 chain writer in: 0000560D637FE780
2017/06/29 10:05:15 [debug] 5252#5252: *1613 writev: 8 of 8
2017/06/29 10:05:15 [debug] 5252#5252: *1613 sendfile: @54591488 22717
2017/06/29 10:05:15 [debug] 5252#5252: *1613 sendfile: 22717 of 22717 @54591488
2017/06/29 10:05:15 [debug] 5252#5252: *1613 writev: 11 of 11
2017/06/29 10:05:15 [debug] 5252#5252: *1613 chain writer out: 0000000000000000
2017/06/29 10:05:15 [debug] 5252#5252: *1613 event timer del: 10: 1498723575096
2017/06/29 10:05:15 [debug] 5252#5252: *1613 event timer add: 10: 300000:1498723815151
2017/06/29 10:05:15 [debug] 5252#5252: *1613 http upstream request: "/index2.php?"
2017/06/29 10:05:15 [debug] 5252#5252: *1613 http upstream dummy handler
2017/06/29 10:05:15 [debug] 5252#5252: *1613 http upstream request: "/index2.php?"
2017/06/29 10:05:15 [debug] 5252#5252: *1613 http upstream dummy handler
2017/06/29 10:05:40 [debug] 5252#5252: *1613 http upstream request: "/index2.php?"
2017/06/29 10:05:40 [debug] 5252#5252: *1613 http upstream process header
2017/06/29 10:05:40 [debug] 5252#5252: *1613 malloc: 0000560D637FF560:4096
2017/06/29 10:05:40 [debug] 5252#5252: *1613 recv: fd:10 56 of 4096
2017/06/29 10:05:40 [debug] 5252#5252: *1613 http fastcgi record byte: 01
2017/06/29 10:05:40 [debug] 5252#5252: *1613 http fastcgi record byte: 06
2017/06/29 10:05:40 [debug] 5252#5252: *1613 http fastcgi record byte: 00
2017/06/29 10:05:40 [debug] 5252#5252: *1613 http fastcgi record byte: 01
2017/06/29 10:05:40 [debug] 5252#5252: *1613 http fastcgi record byte: 00
2017/06/29 10:05:40 [debug] 5252#5252: *1613 http fastcgi record byte: 1D
2017/06/29 10:05:40 [debug] 5252#5252: *1613 http fastcgi record byte: 03
2017/06/29 10:05:40 [debug] 5252#5252: *1613 http fastcgi record byte: 00
2017/06/29 10:05:40 [debug] 5252#5252: *1613 http fastcgi record length: 29
2017/06/29 10:05:40 [debug] 5252#5252: *1613 http fastcgi parser: 0
2017/06/29 10:05:40 [debug] 5252#5252: *1613 http fastcgi header: "Content-type: text/html"
2017/06/29 10:05:40 [debug] 5252#5252: *1613 http fastcgi parser: 1
2017/06/29 10:05:40 [debug] 5252#5252: *1613 http fastcgi header done
2017/06/29 10:05:40 [debug] 5252#5252: *1613 xslt filter header
2017/06/29 10:05:40 [debug] 5252#5252: *1613 HTTP/1.1 200 OK^M


Php-fpm:

PHPFPM

[29-Jun-2017 10:05:14.699514] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 0 active children, 3 spare children, 3 running children. Spawning rate 1

[29-Jun-2017 10:05:16.700710] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:17.701773] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:18.702842] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:19.703778] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:20.705400] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:21.706471] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:22.707537] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:23.707779] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:24.708839] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:25.710378] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:26.710841] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:27.711798] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:28.712864] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:29.713932] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:30.715523] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:31.715785] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:32.716851] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:32.716851] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:33.717931] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:34.719001] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:35.720280] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:36.720662] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:37.721725] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:38.722791] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1
[29-Jun-2017 10:05:39.723785] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 1 active children, 2 spare children, 3 running children. Spawning rate 1

[29-Jun-2017 10:05:40.725342] DEBUG: pid 5135, fpm_pctl_perform_idle_server_maintenance(), line 379: [pool mdbeta] currently 0 active children, 3 spare children, 3 running children. Spawning rate 1


Any idea?

Thanks a lot,
Andrea

ANDREA SORACCHI
<a href="tel:+393290512702" style="text-decoration: none; color: rgb(17, 37, 75);" target="_blank">+39 329 0512704
System Engineer

+39 0521 24 77 91
[hidden email]



From: "Payam Chychi" <[hidden email]>
To: [hidden email]
Sent: Giovedì, 29 giugno 2017 6:38:09
Subject: Re: Strange issue after nginx update


Are you seeing any errors in your php log?
are you connecting to the hostname or ip?

Also, make sure your interface is connected at full duplex. whats the output of "ethtool eth0" replace eth0 with your nic in use.

not sure what else really...
id say to check dns but its all local to you

- Payam


On Wed, Jun 28, 2017 at 9:01 PM Anoop Alias <[hidden email]> wrote:
give a try changing the nameservers in /etc/resolv.conf 


On Thu, Jun 29, 2017 at 3:51 AM, Andrea Soracchi <[hidden email]> wrote:
Hi,

I have attached part of the ettercap log.

I have posted a test file of 40MB.

The delay  is 29 second:

 from the last file's chunk at 23:56:06
 
 to the response of  index2.php at 23:56:35

The nginx's log show:

192.168.18.18 - - [28/Jun/2017:23:56:35 +0200] "POST /index2.php HTTP/1.1" 200 37 "-" "Generic Client"

Nothing retransmits, SElinux isn't installed and apparmor is stopped.

Nothing in dmesg...

Thanks a lot,


ANDREA SORACCHI
<a href="tel:+393290512702" style="text-decoration: none; color: rgb(17, 37, 75);" target="_blank">+39 329 0512704
System Engineer

+39 0521 24 77 91
[hidden email]


Da: "Payam Chychi" <[hidden email]>
A: "nginx" <[hidden email]>
Inviato: Mercoledì, 28 giugno 2017 19:56:04
Oggetto: Re: Strange issue after nginx update


On Wed, Jun 28, 2017 at 8:41 AM Andrea Soracchi <[hidden email]> wrote:
Hi,
could you please help me solve this issue? I'm getting crazy!

Before the nginx update my client worked perfectly: it posted files to my website without any delay.

How, after nginx update (ubuntu 16.04 LTS) I've got this issue:

- the client posts files successfully but the answer of the post is delayed. The more the file is bigger, the more the answer is delayed.

I put a sniffer into the website' server and I noticed that the nginx receives the post but it waits to transfer the file to php-fpm process, so also the answer to the client is delayed

The nginx server is:

nginx/1.10.0 (Ubuntu) and its conf is:

-----
user www-data;
worker_processes auto;
pid /run/nginx.pid;

events {
        worker_connections 768;
        # multi_accept on;
}

http {
        sendfile on;
        tcp_nodelay on;
        keepalive_timeout 65;
        types_hash_max_size 2048;
        client_max_body_size 0;
        log_not_found off;
        server_name_in_redirect off;
        client_body_timeout 120s;
        autoindex off;
        include /etc/nginx/mime.types;
        default_type application/octet-stream;
        ssl_protocols TLSv1 TLSv1.1 TLSv1.2; # Dropping SSLv3, ref: POODLE
        ssl_prefer_server_ciphers on;
        access_log /var/log/nginx/access.log;
        error_log /var/log/nginx/error.log info;
        gzip on;
        gzip_disable "msie6";
        gzip_types text/plain text/css application/json application/javascript text/xml application/xml application/xml+rss text/javascript;
        include /etc/nginx/conf.d/*.conf;
        include /etc/nginx/sites-enabled/*;
---

and website's php-fpm conf is:

server {
  listen                    80;
  server_name               test.it;
  server_name_in_redirect   off;
  autoindex                 off;
  client_max_body_size      500m;
  index                     index.html;
  root                      /home/test/test;
  location ~ \.(php|html|htm|php3)$ {
    try_files     $uri 404;
    fastcgi_pass  unix:/run/php/mdtest-fpm.sock;
    include       fastcgi_params;
  }
}

fastcgi_params config:

fastcgi_param  QUERY_STRING       $query_string;
fastcgi_param  REQUEST_METHOD     $request_method;
fastcgi_param  CONTENT_TYPE       $content_type;
fastcgi_param  CONTENT_LENGTH     $content_length;

fastcgi_param  SCRIPT_NAME        $fastcgi_script_name;
fastcgi_param  REQUEST_URI        $request_uri;
fastcgi_param  DOCUMENT_URI       $document_uri;
fastcgi_param  DOCUMENT_ROOT      $document_root;
fastcgi_param  SERVER_PROTOCOL    $server_protocol;
fastcgi_param  REQUEST_SCHEME     $scheme;
fastcgi_param  HTTPS              $https if_not_empty;

fastcgi_param  GATEWAY_INTERFACE  CGI/1.1;
fastcgi_param  SERVER_SOFTWARE    nginx/$nginx_version;

fastcgi_param  REMOTE_ADDR        $remote_addr;
fastcgi_param  REMOTE_PORT        $remote_port;
fastcgi_param  SERVER_ADDR        $server_addr;
fastcgi_param  SERVER_PORT        $server_port;
#fastcgi_param  SERVER_NAME        $server_name;
fastcgi_param  SERVER_NAME       $http_host;

# PHP only, required if PHP was built with --enable-force-cgi-redirect
fastcgi_param  REDIRECT_STATUS    200;

fastcgi_param SCRIPT_FILENAME     $document_root$fastcgi_script_name;


Thanks a lot,
Andrea


ANDREA SORACCHI
<a href="tel:+393290512702" style="text-decoration: none; color: rgb(17, 37, 75);" target="_blank">+39 329 0512704
System Engineer

+39 0521 24 77 91
[hidden email]


_______________________________________________
nginx mailing list
[hidden email]
http://mailman.nginx.org/mailman/listinfo/nginx

hi,

can you show the related wireshark data, how long is the response delayed by? and anything else like retransmits or anything else?

any SElinux security throtelling taking place? anything in dmesg?

--
Payam Tarverdyan Chychi
Network Security Specialist / Network Engineer

_______________________________________________
nginx mailing list
[hidden email]
http://mailman.nginx.org/mailman/listinfo/nginx

_______________________________________________
nginx mailing list
[hidden email]
http://mailman.nginx.org/mailman/listinfo/nginx



--
Anoop P Alias 
_______________________________________________
nginx mailing list
[hidden email]
http://mailman.nginx.org/mailman/listinfo/nginx
--
Payam Tarverdyan Chychi
Network Security Specialist / Network Engineer

--
Questo messaggio e' stato analizzato ed e' risultato non infetto.
This message was scanned and is believed to be clean.


_______________________________________________
nginx mailing list
[hidden email]
http://mailman.nginx.org/mailman/listinfo/nginx



_______________________________________________
nginx mailing list
[hidden email]
http://mailman.nginx.org/mailman/listinfo/nginx

--
Questo messaggio e' stato analizzato ed e' risultato non infetto.
This message was scanned and is believed to be clean.


_______________________________________________
nginx mailing list
[hidden email]
http://mailman.nginx.org/mailman/listinfo/nginx

_______________________________________________
nginx mailing list
[hidden email]
http://mailman.nginx.org/mailman/listinfo/nginx

--
Questo messaggio e' stato analizzato ed e' risultato non infetto.
This message was scanned and is believed to be clean.


_______________________________________________
nginx mailing list
[hidden email]
http://mailman.nginx.org/mailman/listinfo/nginx

--
Questo messaggio e' stato analizzato ed e' risultato non infetto.
This message was scanned and is believed to be clean.


_______________________________________________
nginx mailing list
[hidden email]
http://mailman.nginx.org/mailman/listinfo/nginx


_______________________________________________
nginx mailing list
[hidden email]
http://mailman.nginx.org/mailman/listinfo/nginx
Reply | Threaded
Open this post in threaded view
|

Re: Strange issue after nginx update

Francis Daly
On Fri, Jun 30, 2017 at 04:10:32PM +0200, Andrea Soracchi wrote:

Hi there,

you suggest that with the old unknown version of nginx and the old
unknown version of php, things worked.

Now with the new updated version of nginx and the new updated version
of php, things fail.

And with the same updated version of nginx and a different updated
version of php, things work again.

The only pair there where you have one piece the same and one piece
different, is new nginx and two different versions of php - one works,
one fails.

So you probably want to compare the php versions and their configuration
to see what is different.


(If you have one version of php and two versions of nginx showing one
set working and one set failing, then you should compare the nginx
versions for differences. But that is not what you have reported here,
if I am reading it right.)

Good luck with it,

        f
--
Francis Daly        [hidden email]
_______________________________________________
nginx mailing list
[hidden email]
http://mailman.nginx.org/mailman/listinfo/nginx
Reply | Threaded
Open this post in threaded view
|

Re: Strange issue after nginx update

Andrea Soracchi-2
Hi Francis,

the problem is with the last ubuntu 16.04 LTS with the php 5.6 ( repository ondrej/php5-5.6).

I try to downgrade to ubuntu 14.04 LTS...

Thanks,

Andrea


ANDREA SORACCHI
<a href="tel:+393290512702" style="text-decoration: none; color: #11254b;" data-mce-href="tel:+393290512702" data-mce-style="text-decoration: none; color: #11254b;">+39 329 0512704
System Engineer

+39 0521 24 77 91
[hidden email]



Da: "Francis Daly" <[hidden email]>
A: "nginx" <[hidden email]>
Inviato: Venerdì, 30 giugno 2017 18:34:26
Oggetto: Re: Strange issue after nginx update

On Fri, Jun 30, 2017 at 04:10:32PM +0200, Andrea Soracchi wrote:

Hi there,

you suggest that with the old unknown version of nginx and the old
unknown version of php, things worked.

Now with the new updated version of nginx and the new updated version
of php, things fail.

And with the same updated version of nginx and a different updated
version of php, things work again.

The only pair there where you have one piece the same and one piece
different, is new nginx and two different versions of php - one works,
one fails.

So you probably want to compare the php versions and their configuration
to see what is different.


(If you have one version of php and two versions of nginx showing one
set working and one set failing, then you should compare the nginx
versions for differences. But that is not what you have reported here,
if I am reading it right.)

Good luck with it,

        f
--
Francis Daly        [hidden email]
_______________________________________________
nginx mailing list
[hidden email]
http://mailman.nginx.org/mailman/listinfo/nginx

--
Questo messaggio e' stato analizzato ed e' risultato non infetto.
This message was scanned and is believed to be clean.

_______________________________________________
nginx mailing list
[hidden email]
http://mailman.nginx.org/mailman/listinfo/nginx