Сайт периодически зависает (php-fpm Finishing)

Posted on 2018.07.04

Содержание

1 Репорт: сайт периодически тормозит, не грузится.
2 Второй взгляд: сайт периодически блокируется по php-fpm, кончаются свободные воркеры.
3 Третий взгляд: много воркеров php-fpm висит на статусе Finishing.
4 Воспроизводим проблему
5 strace
6 Виновник

Репорт: сайт периодически тормозит, не грузится.

Действительно, пытаешься зайти на сайт, он то открывается, то нет. Чаще нет. Что замечательно, по админке ходится нормально. Соответственно, подозрения падают на новую тему.

Второй взгляд: сайт периодически блокируется по php-fpm, кончаются свободные воркеры.

WARNING: [pool www] seems busy (you may need to increase pm.start_servers, or pm.min/max_spare_servers), spawning 8 children, there are 0 idle, and 13 total children
WARNING: [pool www] server reached pm.max_children setting (16), consider raising it

1 2	WARNING: [pool www] seems busy (you may need to increase pm.start_servers, or pm.min/max_spare_servers), spawning 8 children, there are 0 idle, and 13 total children WARNING: [pool www] server reached pm.max_children setting (16), consider raising it

А «тормозит» и «висит» сайт потому, что все 16 выделенных php-fpm воркеров заняты. Чем-то заняты. Неизвестно, чем. Но они пока не готовы принимать новые запросы, поэтому и висим.

Это мы видим через htop при php-fpm pm = dynamic, количество воркеров в спокойном состоянии будет не больше pm.max_spare_servers = 8, а не все 16 процессов, которые видны в списке.

Третий взгляд: много воркеров php-fpm висит на статусе Finishing.

Мы знаем, что у Апача есть статус монитор, можно зайти на специальную страницу и увидеть, что там происходит с воркерами, заняты ли они. Стандартная настройка примерно такая:

<IfModule mod_status.c>
	# Allow server status reports generated by mod_status,
	# with the URL of http://servername/server-status
	# Uncomment and change the "192.0.2.0/24" to allow access from other hosts.

	<Location /mystatus>
		SetHandler server-status
		Require local
		# Require ip 123.123.123.123/32
	</Location>

	# Keep track of extended status information for each request
	ExtendedStatus On

	# Determine if mod_status displays the first 63 characters of a request or
	# the last 63, assuming the request itself is greater than 63 chars.
	# Default: Off
	#SeeRequestTail On


	<IfModule mod_proxy.c>
		# Show Proxy LoadBalancer status in mod_status
		ProxyStatus On
	</IfModule>

</IfModule>

# Allow server status reports generated by mod_status,

# with the URL of http://servername/server-status

# Uncomment and change the "192.0.2.0/24" to allow access from other hosts.

SetHandler server-status

Require local

# Require ip 123.123.123.123/32

</Location>

# Keep track of extended status information for each request

ExtendedStatus On

# Determine if mod_status displays the first 63 characters of a request or

# the last 63, assuming the request itself is greater than 63 chars.

# Default: Off

#SeeRequestTail On

# Show Proxy LoadBalancer status in mod_status

ProxyStatus On

</IfModule>

, самое простое — открыть доступ для локального клиента. Значит через ssh на сервере мы можем выполнить команду вроде lynx localhost/mystatus и увидеть статусы воркеров.

Для пхп же всё не так просто. php-fpm как бы позволяет настроить подобную штуку:

pm.status_path = /myphpstatus

1	pm.status_path = /myphpstatus

, но прямого доступа к php-fpm у нас же нет, всё ловит апач. И когда пытаешься обратиться к такой ссылке, ничего не получается. К счастью, здесь нам помогает гугл и добрые люди, работает такая команда:

apt install libfcgi0ldbl
SCRIPT_NAME=/myphpstatus SCRIPT_FILENAME=/myphpstatus QUERY_STRING="full&html" REQUEST_METHOD=GET cgi-fcgi -bind -connect /run/php/php7.0-fpm.sock > stat.html && lynx stat.html

1 2	apt install libfcgi0ldbl SCRIPT_NAME=/myphpstatus SCRIPT_FILENAME=/myphpstatus QUERY_STRING="full&html" REQUEST_METHOD=GET cgi-fcgi -bind -connect /run/php/php7.0-fpm.sock > stat.html && lynx stat.html

Если биндинг апача и пхп-фпм не через сокет, а по tcp, то там вместо адреса сокета нужно указать адрес. QUERY_STRING можно менять на свой вкус:

; The URI to view the FPM status page. If this value is not set, no URI will be
; recognized as a status page. It shows the following informations:
;   pool                 - the name of the pool;
;   process manager      - static, dynamic or ondemand;
;   start time           - the date and time FPM has started;
;   start since          - number of seconds since FPM has started;
;   accepted conn        - the number of request accepted by the pool;
;   listen queue         - the number of request in the queue of pending
;                          connections (see backlog in listen(2));
;   max listen queue     - the maximum number of requests in the queue
;                          of pending connections since FPM has started;
;   listen queue len     - the size of the socket queue of pending connections;
;   idle processes       - the number of idle processes;
;   active processes     - the number of active processes;
;   total processes      - the number of idle + active processes;
;   max active processes - the maximum number of active processes since FPM
;                          has started;
;   max children reached - number of times, the process limit has been reached,
;                          when pm tries to start more children (works only for
;                          pm 'dynamic' and 'ondemand');
; Value are updated in real time.
; Example output:
;   pool:                 www
;   process manager:      static
;   start time:           01/Jul/2011:17:53:49 +0200
;   start since:          62636
;   accepted conn:        190460
;   listen queue:         0
;   max listen queue:     1
;   listen queue len:     42
;   idle processes:       4
;   active processes:     11
;   total processes:      15
;   max active processes: 12
;   max children reached: 0
;
; By default the status page output is formatted as text/plain. Passing either
; 'html', 'xml' or 'json' in the query string will return the corresponding
; output syntax. Example:
;   http://www.foo.bar/status
;   http://www.foo.bar/status?json
;   http://www.foo.bar/status?html
;   http://www.foo.bar/status?xml
;
; By default the status page only outputs short status. Passing 'full' in the
; query string will also return status for each pool process.
; Example:
;   http://www.foo.bar/status?full
;   http://www.foo.bar/status?json&full
;   http://www.foo.bar/status?html&full
;   http://www.foo.bar/status?xml&full
; The Full status returns for each process:
;   pid                  - the PID of the process;
;   state                - the state of the process (Idle, Running, ...);
;   start time           - the date and time the process has started;
;   start since          - the number of seconds since the process has started;
;   requests             - the number of requests the process has served;
;   request duration     - the duration in µs of the requests;
;   request method       - the request method (GET, POST, ...);
;   request URI          - the request URI with the query string;
;   content length       - the content length of the request (only with POST);
;   user                 - the user (PHP_AUTH_USER) (or '-' if not set);
;   script               - the main script called (or '-' if not set);
;   last request cpu     - the %cpu the last request consumed
;                          it's always 0 if the process is not in Idle state
;                          because CPU calculation is done when the request
;                          processing has terminated;
;   last request memory  - the max amount of memory the last request consumed
;                          it's always 0 if the process is not in Idle state
;                          because memory calculation is done when the request
;                          processing has terminated;
; If the process is in Idle state, then informations are related to the
; last request the process has served. Otherwise informations are related to
; the current request being served.
; Example output:
;   ************************
;   pid:                  31330
;   state:                Running
;   start time:           01/Jul/2011:17:53:49 +0200
;   start since:          63087
;   requests:             12808
;   request duration:     1250261
;   request method:       GET
;   request URI:          /test_mem.php?N=10000
;   content length:       0
;   user:                 -
;   script:               /home/fat/web/docs/php/test_mem.php
;   last request cpu:     0.00
;   last request memory:  0
;
; Note: There is a real-time FPM status monitoring sample web page available
;       It's available in: /usr/share/php/7.0/fpm/status.html
;
; Note: The value must start with a leading slash (/). The value can be
;       anything, but it may not be a good idea to use the .php extension or it
;       may conflict with a real PHP file.
; Default Value: not set

; The URI to view the FPM status page. If this value is not set, no URI will be

; recognized as a status page. It shows the following informations:

; pool - the name of the pool;

; process manager - static, dynamic or ondemand;

; start time - the date and time FPM has started;

; start since - number of seconds since FPM has started;

; accepted conn - the number of request accepted by the pool;

; listen queue - the number of request in the queue of pending

; connections (see backlog in listen(2));

; max listen queue - the maximum number of requests in the queue

; of pending connections since FPM has started;

; listen queue len - the size of the socket queue of pending connections;

; idle processes - the number of idle processes;

; active processes - the number of active processes;

; total processes - the number of idle + active processes;

; max active processes - the maximum number of active processes since FPM

; has started;

; max children reached - number of times, the process limit has been reached,

; when pm tries to start more children (works only for

; pm 'dynamic' and 'ondemand');

; Value are updated in real time.

; Example output:

; pool: www

; process manager: static

; start time: 01/Jul/2011:17:53:49 +0200

; start since: 62636

; accepted conn: 190460

; listen queue: 0

; max listen queue: 1

; listen queue len: 42

; idle processes: 4

; active processes: 11

; total processes: 15

; max active processes: 12

; max children reached: 0

;

; By default the status page output is formatted as text/plain. Passing either

; 'html', 'xml' or 'json' in the query string will return the corresponding

; output syntax. Example:

; http://www.foo.bar/status

; http://www.foo.bar/status?json

; http://www.foo.bar/status?html

; http://www.foo.bar/status?xml

;

; By default the status page only outputs short status. Passing 'full' in the

; query string will also return status for each pool process.

; Example:

; http://www.foo.bar/status?full

; http://www.foo.bar/status?json&full

; http://www.foo.bar/status?html&full

; http://www.foo.bar/status?xml&full

; The Full status returns for each process:

; pid - the PID of the process;

; state - the state of the process (Idle, Running, ...);

; start time - the date and time the process has started;

; start since - the number of seconds since the process has started;

; requests - the number of requests the process has served;

; request duration - the duration in µs of the requests;

; request method - the request method (GET, POST, ...);

; request URI - the request URI with the query string;

; content length - the content length of the request (only with POST);

; user - the user (PHP_AUTH_USER) (or '-' if not set);

; script - the main script called (or '-' if not set);

; last request cpu - the %cpu the last request consumed

; it's always 0 if the process is not in Idle state

; because CPU calculation is done when the request

; processing has terminated;

; last request memory - the max amount of memory the last request consumed

; it's always 0 if the process is not in Idle state

; because memory calculation is done when the request

; processing has terminated;

; If the process is in Idle state, then informations are related to the

; last request the process has served. Otherwise informations are related to

; the current request being served.

; Example output:

; ************************

; pid: 31330

; state: Running

; start time: 01/Jul/2011:17:53:49 +0200

; start since: 63087

; requests: 12808

; request duration: 1250261

; request method: GET

; request URI: /test_mem.php?N=10000

; content length: 0

; user: -

; script: /home/fat/web/docs/php/test_mem.php

; last request cpu: 0.00

; last request memory: 0

;

; Note: There is a real-time FPM status monitoring sample web page available

; It's available in: /usr/share/php/7.0/fpm/status.html

;

; Note: The value must start with a leading slash (/). The value can be

; anything, but it may not be a good idea to use the .php extension or it

; may conflict with a real PHP file.

; Default Value: not set

, глазами это читать неудобно, можно итоговый файл класть куда-нибидь в доступную по апачу папку и открывать её с клиента, а можно как я, просто подавать это куда-то в браузер командной строки. (может быть можно передавать поток сразу в него, без промежуточного файла, мне было не до этого, и так работает; это вам домашнее задание, сможете - напишите пожалуйста в комментариях)

Так выглядят воркеры сейчас, когда всё работает нормально. Или Running, или Idle. А там было Finishing, всё висело на нём. Причём чтобы получить вот такую картину, это тоже нужно присоединиться к воркеру, хотя бы один должен остаться свободен. У меня настроены таймауты request_terminate_timeout = 70s, поэтому рано или поздно хотя бы один освободится.

Finishing. И что делать дальше?

Воспроизводим проблему

Проблема достаточно волшебная, повторяется только на определённой версии Safari. В developer console видно, что происходит. Там куча 404 для шрифтов. Причём в отличие от Хрома, сафари пытается загрузить все варианты шрифтов что видит, не важно что они не используются на текущей странице.

Вот как это выглядит со стороны сервера, обратите внимание на неравномерные секунды в самой левой колонке: строчка в лог апача добавляется в момент, когда реквест выполнен до конца, а пишется время начала запроса. Видно, что некоторые запросы начались раньше, а закончились позже других. Такой неравномерности быть не должно, в нормальных случаях не наблюдается.

[13:44:34 +0000] "GET /hangtest2/ HTTP/1.1" 200 59353 "-" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_4) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/11.1 Safari/605.1.15"
[13:44:35 +0000] "GET /hangtest2/assets/fontsHelveticaNeueCyr-Medium.woff2 HTTP/1.1" 404 557243 "https://dima.stefantsov.com/hangtest2/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_4) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/11.1 Safari/605.1.15"
[13:44:35 +0000] "GET /hangtest2/assets/fontsHelveticaNeueCyr-Roman.woff2 HTTP/1.1" 404 557247 "https://dima.stefantsov.com/hangtest2/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_4) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/11.1 Safari/605.1.15"
[13:44:39 +0000] "GET /hangtest2/assets/fontsHelveticaNeueCyr-Medium.woff HTTP/1.1" 404 143352 "https://dima.stefantsov.com/hangtest2/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_4) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/11.1 Safari/605.1.15"
[13:44:39 +0000] "GET /hangtest2/assets/fontsHelveticaNeueCyr-Medium.ttf HTTP/1.1" 404 144800 "https://dima.stefantsov.com/hangtest2/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_4) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/11.1 Safari/605.1.15"
[13:44:39 +0000] "GET /hangtest2/assets/fontsHelveticaNeueCyr-Roman.woff HTTP/1.1" 404 143352 "https://dima.stefantsov.com/hangtest2/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_4) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/11.1 Safari/605.1.15"
[13:44:35 +0000] "GET /hangtest2/assets/fontsHelveticaNeueCyr-Bold.woff2 HTTP/1.1" 404 556935 "https://dima.stefantsov.com/hangtest2/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_4) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/11.1 Safari/605.1.15"
[13:44:41 +0000] "GET /hangtest2/assets/fontsHelveticaNeueCyr-Light.woff2 HTTP/1.1" 404 144937 "https://dima.stefantsov.com/hangtest2/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_4) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/11.1 Safari/605.1.15"
[13:44:42 +0000] "GET /hangtest2/assets/fontsHelveticaNeueCyr-Bold.ttf HTTP/1.1" 404 144937 "https://dima.stefantsov.com/hangtest2/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_4) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/11.1 Safari/605.1.15"
[13:44:43 +0000] "GET /hangtest2/assets/fontsHelveticaNeueCyr-Light.ttf HTTP/1.1" 404 144937 "https://dima.stefantsov.com/hangtest2/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_4) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/11.1 Safari/605.1.15"
[13:44:44 +0000] "GET /hangtest2/assets/fontsHelveticaNeueCyr-Light.svg HTTP/1.1" 404 144937 "https://dima.stefantsov.com/hangtest2/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_4) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/11.1 Safari/605.1.15"
[13:44:45 +0000] "GET /hangtest2/assets/fontsHelveticaNeueCyr-Thin.woff2 HTTP/1.1" 404 144937 "https://dima.stefantsov.com/hangtest2/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_4) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/11.1 Safari/605.1.15"
[13:44:49 +0000] "GET /hangtest2/assets/fontsHelveticaNeueCyr-UltraLight.woff HTTP/1.1" 404 144937 "https://dima.stefantsov.com/hangtest2/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_4) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/11.1 Safari/605.1.15"
[13:44:51 +0000] "GET /hangtest2/assets/fontsHelveticaNeueCyr-Heavy.woff2 HTTP/1.1" 404 144937 "https://dima.stefantsov.com/hangtest2/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_4) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/11.1 Safari/605.1.15"
[13:44:53 +0000] "GET /hangtest2/assets/fontsHelveticaNeueCyr-Heavy.svg HTTP/1.1" 404 144937 "https://dima.stefantsov.com/hangtest2/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_4) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/11.1 Safari/605.1.15"
[13:44:53 +0000] "GET /hangtest2/assets/fontsHelveticaNeueCyr-Black.woff2 HTTP/1.1" 404 144937 "https://dima.stefantsov.com/hangtest2/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_4) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/11.1 Safari/605.1.15"
[13:44:40 +0000] "GET /hangtest2/assets/fontsHelveticaNeueCyr-Medium.svg HTTP/1.1" 404 144937 "https://dima.stefantsov.com/hangtest2/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_4) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/11.1 Safari/605.1.15"
[13:44:40 +0000] "GET /hangtest2/assets/fontsHelveticaNeueCyr-Roman.ttf HTTP/1.1" 404 144937 "https://dima.stefantsov.com/hangtest2/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_4) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/11.1 Safari/605.1.15"
[13:44:42 +0000] "GET /hangtest2/assets/fontsHelveticaNeueCyr-Bold.svg HTTP/1.1" 404 144937 "https://dima.stefantsov.com/hangtest2/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_4) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/11.1 Safari/605.1.15"
[13:44:43 +0000] "GET /hangtest2/assets/fontsHelveticaNeueCyr-Light.woff HTTP/1.1" 404 144937 "https://dima.stefantsov.com/hangtest2/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_4) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/11.1 Safari/605.1.15"
[13:44:46 +0000] "GET /hangtest2/assets/fontsHelveticaNeueCyr-Thin.ttf HTTP/1.1" 404 144937 "https://dima.stefantsov.com/hangtest2/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_4) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/11.1 Safari/605.1.15"
[13:44:46 +0000] "GET /hangtest2/assets/fontsHelveticaNeueCyr-Thin.woff HTTP/1.1" 404 144937 "https://dima.stefantsov.com/hangtest2/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_4) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/11.1 Safari/605.1.15"
[13:44:48 +0000] "GET /hangtest2/assets/fontsHelveticaNeueCyr-Thin.svg HTTP/1.1" 404 144937 "https://dima.stefantsov.com/hangtest2/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_4) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/11.1 Safari/605.1.15"
[13:44:50 +0000] "GET /hangtest2/assets/fontsHelveticaNeueCyr-UltraLight.svg HTTP/1.1" 404 144937 "https://dima.stefantsov.com/hangtest2/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_4) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/11.1 Safari/605.1.15"
[13:44:52 +0000] "GET /hangtest2/assets/fontsHelveticaNeueCyr-Heavy.ttf HTTP/1.1" 404 144937 "https://dima.stefantsov.com/hangtest2/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_4) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/11.1 Safari/605.1.15"
[13:44:52 +0000] "GET /hangtest2/assets/fontsHelveticaNeueCyr-Heavy.woff HTTP/1.1" 404 144937 "https://dima.stefantsov.com/hangtest2/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_4) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/11.1 Safari/605.1.15"
[13:44:54 +0000] "GET /hangtest2/assets/fontsHelveticaNeueCyr-Black.woff HTTP/1.1" 404 144937 "https://dima.stefantsov.com/hangtest2/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_4) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/11.1 Safari/605.1.15"
[13:44:41 +0000] "GET /hangtest2/assets/fontsHelveticaNeueCyr-Roman.svg HTTP/1.1" 404 144937 "https://dima.stefantsov.com/hangtest2/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_4) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/11.1 Safari/605.1.15"
[13:44:41 +0000] "GET /hangtest2/assets/fontsHelveticaNeueCyr-Bold.woff HTTP/1.1" 404 140456 "https://dima.stefantsov.com/hangtest2/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_4) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/11.1 Safari/605.1.15"
[13:44:55 +0000] "GET /hangtest2/assets/fontsHelveticaNeueCyr-Black.svg HTTP/1.1" 404 144937 "https://dima.stefantsov.com/hangtest2/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_4) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/11.1 Safari/605.1.15"
[13:44:48 +0000] "GET /hangtest2/assets/fontsHelveticaNeueCyr-UltraLight.woff2 HTTP/1.1" 404 144937 "https://dima.stefantsov.com/hangtest2/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_4) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/11.1 Safari/605.1.15"
[13:44:49 +0000] "GET /hangtest2/assets/fontsHelveticaNeueCyr-UltraLight.ttf HTTP/1.1" 404 144937 "https://dima.stefantsov.com/hangtest2/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_4) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/11.1 Safari/605.1.15"
[13:44:55 +0000] "GET /hangtest2/assets/fontsHelveticaNeueCyr-Black.ttf HTTP/1.1" 404 144937 "https://dima.stefantsov.com/hangtest2/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_4) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/11.1 Safari/605.1.15"

[13:44:34 +0000] "GET /hangtest2/ HTTP/1.1" 200 59353 "-" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_4) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/11.1 Safari/605.1.15"

[13:44:35 +0000] "GET /hangtest2/assets/fontsHelveticaNeueCyr-Medium.woff2 HTTP/1.1" 404 557243 "https://dima.stefantsov.com/hangtest2/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_4) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/11.1 Safari/605.1.15"

[13:44:35 +0000] "GET /hangtest2/assets/fontsHelveticaNeueCyr-Roman.woff2 HTTP/1.1" 404 557247 "https://dima.stefantsov.com/hangtest2/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_4) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/11.1 Safari/605.1.15"

[13:44:39 +0000] "GET /hangtest2/assets/fontsHelveticaNeueCyr-Medium.woff HTTP/1.1" 404 143352 "https://dima.stefantsov.com/hangtest2/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_4) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/11.1 Safari/605.1.15"

[13:44:39 +0000] "GET /hangtest2/assets/fontsHelveticaNeueCyr-Medium.ttf HTTP/1.1" 404 144800 "https://dima.stefantsov.com/hangtest2/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_4) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/11.1 Safari/605.1.15"

[13:44:39 +0000] "GET /hangtest2/assets/fontsHelveticaNeueCyr-Roman.woff HTTP/1.1" 404 143352 "https://dima.stefantsov.com/hangtest2/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_4) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/11.1 Safari/605.1.15"

[13:44:35 +0000] "GET /hangtest2/assets/fontsHelveticaNeueCyr-Bold.woff2 HTTP/1.1" 404 556935 "https://dima.stefantsov.com/hangtest2/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_4) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/11.1 Safari/605.1.15"

[13:44:41 +0000] "GET /hangtest2/assets/fontsHelveticaNeueCyr-Light.woff2 HTTP/1.1" 404 144937 "https://dima.stefantsov.com/hangtest2/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_4) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/11.1 Safari/605.1.15"

[13:44:42 +0000] "GET /hangtest2/assets/fontsHelveticaNeueCyr-Bold.ttf HTTP/1.1" 404 144937 "https://dima.stefantsov.com/hangtest2/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_4) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/11.1 Safari/605.1.15"

[13:44:43 +0000] "GET /hangtest2/assets/fontsHelveticaNeueCyr-Light.ttf HTTP/1.1" 404 144937 "https://dima.stefantsov.com/hangtest2/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_4) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/11.1 Safari/605.1.15"

[13:44:44 +0000] "GET /hangtest2/assets/fontsHelveticaNeueCyr-Light.svg HTTP/1.1" 404 144937 "https://dima.stefantsov.com/hangtest2/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_4) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/11.1 Safari/605.1.15"

[13:44:45 +0000] "GET /hangtest2/assets/fontsHelveticaNeueCyr-Thin.woff2 HTTP/1.1" 404 144937 "https://dima.stefantsov.com/hangtest2/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_4) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/11.1 Safari/605.1.15"

[13:44:49 +0000] "GET /hangtest2/assets/fontsHelveticaNeueCyr-UltraLight.woff HTTP/1.1" 404 144937 "https://dima.stefantsov.com/hangtest2/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_4) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/11.1 Safari/605.1.15"

[13:44:51 +0000] "GET /hangtest2/assets/fontsHelveticaNeueCyr-Heavy.woff2 HTTP/1.1" 404 144937 "https://dima.stefantsov.com/hangtest2/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_4) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/11.1 Safari/605.1.15"

[13:44:53 +0000] "GET /hangtest2/assets/fontsHelveticaNeueCyr-Heavy.svg HTTP/1.1" 404 144937 "https://dima.stefantsov.com/hangtest2/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_4) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/11.1 Safari/605.1.15"

[13:44:53 +0000] "GET /hangtest2/assets/fontsHelveticaNeueCyr-Black.woff2 HTTP/1.1" 404 144937 "https://dima.stefantsov.com/hangtest2/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_4) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/11.1 Safari/605.1.15"

[13:44:40 +0000] "GET /hangtest2/assets/fontsHelveticaNeueCyr-Medium.svg HTTP/1.1" 404 144937 "https://dima.stefantsov.com/hangtest2/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_4) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/11.1 Safari/605.1.15"

[13:44:40 +0000] "GET /hangtest2/assets/fontsHelveticaNeueCyr-Roman.ttf HTTP/1.1" 404 144937 "https://dima.stefantsov.com/hangtest2/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_4) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/11.1 Safari/605.1.15"

[13:44:42 +0000] "GET /hangtest2/assets/fontsHelveticaNeueCyr-Bold.svg HTTP/1.1" 404 144937 "https://dima.stefantsov.com/hangtest2/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_4) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/11.1 Safari/605.1.15"

[13:44:43 +0000] "GET /hangtest2/assets/fontsHelveticaNeueCyr-Light.woff HTTP/1.1" 404 144937 "https://dima.stefantsov.com/hangtest2/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_4) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/11.1 Safari/605.1.15"

[13:44:46 +0000] "GET /hangtest2/assets/fontsHelveticaNeueCyr-Thin.ttf HTTP/1.1" 404 144937 "https://dima.stefantsov.com/hangtest2/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_4) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/11.1 Safari/605.1.15"

[13:44:46 +0000] "GET /hangtest2/assets/fontsHelveticaNeueCyr-Thin.woff HTTP/1.1" 404 144937 "https://dima.stefantsov.com/hangtest2/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_4) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/11.1 Safari/605.1.15"

[13:44:48 +0000] "GET /hangtest2/assets/fontsHelveticaNeueCyr-Thin.svg HTTP/1.1" 404 144937 "https://dima.stefantsov.com/hangtest2/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_4) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/11.1 Safari/605.1.15"

[13:44:50 +0000] "GET /hangtest2/assets/fontsHelveticaNeueCyr-UltraLight.svg HTTP/1.1" 404 144937 "https://dima.stefantsov.com/hangtest2/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_4) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/11.1 Safari/605.1.15"

[13:44:52 +0000] "GET /hangtest2/assets/fontsHelveticaNeueCyr-Heavy.ttf HTTP/1.1" 404 144937 "https://dima.stefantsov.com/hangtest2/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_4) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/11.1 Safari/605.1.15"

[13:44:52 +0000] "GET /hangtest2/assets/fontsHelveticaNeueCyr-Heavy.woff HTTP/1.1" 404 144937 "https://dima.stefantsov.com/hangtest2/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_4) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/11.1 Safari/605.1.15"

[13:44:54 +0000] "GET /hangtest2/assets/fontsHelveticaNeueCyr-Black.woff HTTP/1.1" 404 144937 "https://dima.stefantsov.com/hangtest2/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_4) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/11.1 Safari/605.1.15"

[13:44:41 +0000] "GET /hangtest2/assets/fontsHelveticaNeueCyr-Roman.svg HTTP/1.1" 404 144937 "https://dima.stefantsov.com/hangtest2/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_4) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/11.1 Safari/605.1.15"

[13:44:41 +0000] "GET /hangtest2/assets/fontsHelveticaNeueCyr-Bold.woff HTTP/1.1" 404 140456 "https://dima.stefantsov.com/hangtest2/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_4) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/11.1 Safari/605.1.15"

[13:44:55 +0000] "GET /hangtest2/assets/fontsHelveticaNeueCyr-Black.svg HTTP/1.1" 404 144937 "https://dima.stefantsov.com/hangtest2/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_4) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/11.1 Safari/605.1.15"

[13:44:48 +0000] "GET /hangtest2/assets/fontsHelveticaNeueCyr-UltraLight.woff2 HTTP/1.1" 404 144937 "https://dima.stefantsov.com/hangtest2/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_4) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/11.1 Safari/605.1.15"

[13:44:49 +0000] "GET /hangtest2/assets/fontsHelveticaNeueCyr-UltraLight.ttf HTTP/1.1" 404 144937 "https://dima.stefantsov.com/hangtest2/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_4) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/11.1 Safari/605.1.15"

[13:44:55 +0000] "GET /hangtest2/assets/fontsHelveticaNeueCyr-Black.ttf HTTP/1.1" 404 144937 "https://dima.stefantsov.com/hangtest2/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_4) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/11.1 Safari/605.1.15"

Причём, почему-то виснет именно процесс 404 для определённого браузера. Именно для залогиненного админа.

strace

strace это волшебная утилита. Можно наживую присоединиться к процессу php-fpm, который в данный момент Finishing и попробовать понять, на чём он там завис.

Подключаемся: strace -p 21424

Видим:

strace: Process 21424 attached
write(5, "</tr><tr data-qm-subject=\"Core\" "..., 28984) = -1 ECONNRESET (Connection reset by peer)
setitimer(ITIMER_PROF, {it_interval={0, 0}, it_value={0, 0}}, NULL) = 0
sendto(6, "\1\0\0\0\1", 5, MSG_DONTWAIT, NULL, 0) = 5
close(6)                                = 0
fcntl(4, F_SETLK, {l_type=F_UNLCK, l_whence=SEEK_SET, l_start=0, l_len=0}) = 0
write(5, "\1\3\0\1\0\10\0\0\0\0\0\0\0s: ", 16) = -1 EPIPE (Broken pipe)
--- SIGPIPE {si_signo=SIGPIPE, si_code=SI_USER, si_pid=21424, si_uid=33} ---
shutdown(5, SHUT_WR)                    = 0
recvfrom(5, "\1\5\0\1\0\0\0\0", 8, 0, NULL, NULL) = 8
recvfrom(5, "", 8, 0, NULL, NULL)       = 0
close(5)                                = 0
setitimer(ITIMER_PROF, {it_interval={0, 0}, it_value={0, 0}}, NULL) = 0
accept(0, ^Cstrace: Process 21424 detached

strace: Process 21424 attached

write(5, "</tr><tr data-qm-subject=\"Core\" "..., 28984) = -1 ECONNRESET (Connection reset by peer)

setitimer(ITIMER_PROF, {it_interval={0, 0}, it_value={0, 0}}, NULL) = 0

sendto(6, "\1\0\0\0\1", 5, MSG_DONTWAIT, NULL, 0) = 5

close(6) = 0

fcntl(4, F_SETLK, {l_type=F_UNLCK, l_whence=SEEK_SET, l_start=0, l_len=0}) = 0

write(5, "\1\3\0\1\0\10\0\0\0\0\0\0\0s: ", 16) = -1 EPIPE (Broken pipe)

--- SIGPIPE {si_signo=SIGPIPE, si_code=SI_USER, si_pid=21424, si_uid=33} ---

shutdown(5, SHUT_WR) = 0

recvfrom(5, "\1\5\0\1\0\0\0\0", 8, 0, NULL, NULL) = 8

recvfrom(5, "", 8, 0, NULL, NULL) = 0

close(5) = 0

setitimer(ITIMER_PROF, {it_interval={0, 0}, it_value={0, 0}}, NULL) = 0

accept(0, ^Cstrace: Process 21424 detached

Причём сначала висит текст где-то до -1 ECONNRESET (Connection reset by peer), затем через секунд 5+ выводится как раз -1 ECONNRESET (Connection reset by peer) и всё остальное быстро-быстро, и процесс завершается.

То есть понятно, что задержки вызваны тем, что что-то пытается куда-то подключиться и отваливается. Может быть к БД (там всё хорошо, хз), может быть к какому-то внешнему ресурсу.

Виновник

А ещё мы видим, что рядом с -1 ECONNRESET (Connection reset by peer) находится аутпут html очень похожий на аутпут Query Monitor. Может быть дело именно в нём.

Отключаем Query Monitor и действительно, проблема больше не повторяется. Теперь процессы завершаются быстро, а не по 5+ секунд. Ну и осталось избавиться от 404 в ресурсах темы, чтобы не нагружать сервер генерацией 404 страниц.

Ура!

P.S.: Почему это проявлялось именно на этом Safari и не проявлялось на остальных я не знаю и скорее всего не узнаю. Пробовал создавать нового админа, чистить все куки и хранилища, открывать с инкогнито, поведение стабильно одинаковое.

Дебаг apache, php-fpm, safari, strace, лаги, query monitor