Hello,

The problem I'm experiencing: randomly, some requests take an extra 20 seconds, up to 60s to finish.

Manually running curl shows the following behavior:
- curl example.com/api
- 2 seconds - nothing happens (this would be processing time)
- 0.5-1 seconds - json output (stopping in the middle of things like div class="aa )
- 20+ seconds - no output
- last second - the remaining 1-2 lines of the request output are displayed
- request finishes


I expect to not have the 20+ seconds delay where nothing happens.



Here is an example Instana trace showing the error: https://user-images.githubusercontent.com/1954578/162889849-8a2445c0-55b2-4d3b-ba88-a2e89b225dfb.png
Notice this supports the CURL output that PHP has processed the request in 2 seconds.

I have captured a tcpdump of the communication: https://user-images.githubusercontent.com/1954578/162890064-81d8328d-cb20-4d96-8f06-4d67a0006f95.png

To note that the lat FCGI_STDOUT packet is delayed by 50+ seconds, and it contains a few bytes(in this case the json closing paramthesis "]}}" ):

FastCGI (FCGI_STDOUT)
Version: 1
Type: FCGI_STDOUT (6)
Request ID: 1
Content Length: 6
Padding Length: 2
Content Data: 5c6e225d5d7d
Padding Data: 0000

FastCGI (FCGI_STDOUT)
Version: 1
Type: FCGI_STDOUT (6)
Request ID: 1
Content Length: 6
Padding Length: 2
Content Data: 5c6e225d5d7d
Padding Data: 0000


My php-fpm settings:

# php-fpm -v
PHP 7.4.28 (fpm-fcgi) (built: Mar 29 2022 03:26:54)
Copyright (c) The PHP Group
Zend Engine v3.4.0, Copyright (c) Zend Technologies
with Zend OPcache v7.4.28, Copyright (c), by Zend Technologies



[www]
user = www-data
group = www-data
listen.owner = www-data
listen.group = www-data
listen = 0.0.0.0:9000
listen.backlog = 1024
process.priority = 0
pm = dynamic
pm.min_spare_servers = 5
pm.max_spare_servers = 10
pm.process_idle_timeout = 55
pm.max_children = 100
pm.start_servers = 10
pm.max_requests = 10000
slowlog = /var/log/php-fpm/slowlog.log
request_slowlog_timeout = 10
request_terminate_timeout = 600
user = www-data
catch_workers_output = yes
security.limit_extensions = .php .phar
pm.status_path = /status
php_admin_value[memory_limit] = 512M
php_admin_value[post_max_size] = 256M
php_admin_value[upload_max_filesize] = 256M
php_admin_value[max_execution_time] = 60
php_admin_value[opcache.revalidate_freq] = 0
php_admin_value[opcache.validate_timestamps] = 0
php_admin_value[opcache.max_accelerated_files] = 32531
php_admin_value[opcache.memory_consumption] = 512M
php_admin_value[opcache.interned_strings_buffer] = 128
php_admin_value[opcache.huge_code_pages] = 0
php_admin_value[zend.assertions] = 0
php_admin_value[max_input_vars] = 2000


My nginx settings:

# nginx -v
nginx version: nginx/1.20.1


upstream php {
server 127.0.0.1:9000;
}

server_tokens off;
server_names_hash_bucket_size 256;
client_max_body_size 256m;

server {
listen 80;
server_name xxx;

root /usr/share/xxx/public_api;
index index.php;
try_files $uri $uri/ /index.php?$args;

access_log /var/log/nginx/access.log;
error_log /var/log/nginx/error.log;

client_header_timeout 120;
client_body_timeout 120;
send_timeout 120;
keepalive_timeout 60;

gzip on;
gzip_comp_level 4;
gzip_proxied any;
gzip_types application/atom+xml application/javascript application/json application/rss+xml
application/vnd.ms-fontobject application/x-font-ttf application/x-web-app-manifest+json
application/xhtml+xml application/xml font/opentype image/svg+xml image/x-icon text/css
text/plain text/x-component;

location ~ \.php$ {
fastcgi_connect_timeout 60s;
fastcgi_read_timeout 120s;
fastcgi_send_timeout 120s;

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

fastcgi_param APPLICATION_ENV live;
fastcgi_param HTTPS off;

opentracing_fastcgi_propagate_context;
}
}

Update: I managed to track down the issue to resource contention on the Instana monitoring side. Metrics were sent using TCP and hanging php-fpm under certain conditions.