Я выполняю POST-запрос на локальный веб-сервис api (через LAN) с помощью фиктивного метода, который работает очень быстро сам (менее секунды).
Проблема в том, что если я использую php5-fpm, для выполнения запроса POST ( curl post , streams ) требуется очень много времени.
Если я использую скрипт php-cli с тем же кодом или командой curl console – он работает очень быстро, как шарм.
Странная вещь: если я использую system для выполнения команды консоли curl с php5-fpm, для выполнения запроса потребовалось много времени. Таким образом, нет способа обмануть 🙁
Я использую прямой адрес ipv4 для устранения проблем DNS (я попытался определить параметр CURLOPT_IPRESOLVE , но производительность была такой же).
Если я опускаю параметр curl CURLOPT_POSTFIELDS , запрос выполняется очень быстро и в php5-fpm.
Я использую debian jessie с официальным пакетом php 5.6.9.
Итак, почему эта проблема происходит с php5-fpm?
Мой curl php-код:
$data = json_encode([ 'id' => 1, 'method' => 'test', 'sid' => session_id(), ]); $curl = curl_init(); curl_setopt($curl, CURLOPT_URL, 'http://192.168.182.22'); curl_setopt($curl, CURLOPT_RETURNTRANSFER, true); curl_setopt($curl, CURLOPT_POST, true); curl_setopt($curl, CURLOPT_HTTPHEADER, [ 'Content-type: application/json', 'Content-length: ' . strlen($data) ]); curl_setopt($curl, CURLOPT_POSTFIELDS, $data); $out = curl_exec($curl); curl_close($curl);
Curl get info output (показывает, что starttransfer_time очень медленный):
array(26) { ["url"]=> string(22) "http://192.168.182.22/" ["content_type"]=> string(24) "text/html; charset=UTF-8" ["http_code"]=> int(200) ["header_size"]=> int(532) ["request_size"]=> int(188) ["filetime"]=> int(-1) ["ssl_verify_result"]=> int(0) ["redirect_count"]=> int(0) ["total_time"]=> float(10.285093) ["namelookup_time"]=> float(3.2E-5) ["connect_time"]=> float(0.000156) ["pretransfer_time"]=> float(0.000181) ["size_upload"]=> float(82) ["size_download"]=> float(99) ["speed_download"]=> float(9) ["speed_upload"]=> float(7) ["download_content_length"]=> float(-1) ["upload_content_length"]=> float(82) ["starttransfer_time"]=> float(10.285052) ["redirect_time"]=> float(0) ["redirect_url"]=> string(0) "" ["primary_ip"]=> string(14) "192.168.182.22" ["certinfo"]=> array(0) { } ["primary_port"]=> int(80) ["local_ip"]=> string(14) "192.168.182.20" ["local_port"]=> int(49286) }
Еще одна попытка с потоками. Он также работает медленно (немного быстрее, чем завиток, но в любом случае я могу получить задержку в 40-50 секунд):
$url = 'http://192.168.182.22/'; $data = json_encode([ 'id' => 1, 'method' => 'test', 'sid' => session_id(), ]); $headers = [ 'Content-type: application/json', 'Connection: close', 'Content-Length: ' . strlen($data) ]; $options = array( 'http' => array( 'header' => join("\r\n", $headers) . "\r\n", 'method' => 'POST', 'content' => $data, ), ); $context = stream_context_create($options); $result = file_get_contents($url, false, $context);
В diff /etc/php5/fpm/php.ini /etc/php5/cli/php.ini нет существенной разницы:
303c303 < disable_functions = pcntl_alarm,pcntl_fork,pcntl_waitpid,pcntl_wait,pcntl_wifexited,pcntl_wifstopped,pcntl_wifsignaled,pcntl_wexitstatus,pcntl_wtermsig,pcntl_wstopsig,pcntl_signal,pcntl_signal_dispatch,pcntl_get_last_error,pcntl_strerror,pcntl_sigprocmask,pcntl_sigwaitinfo,pcntl_sigtimedwait,pcntl_exec,pcntl_getpriority,pcntl_setpriority, --- > disable_functions = 363c363 < expose_php = Off --- > expose_php = On 393c393 < memory_limit = 256M --- > memory_limit = -1 660c660 < post_max_size = 200M --- > post_max_size = 8M 810c810 < upload_max_filesize = 200M --- > upload_max_filesize = 2M
Главное, что в tcpdump я вижу разные запросы – php5-fpm включает запросы ARP. Я не вижу таких в консоли curl / php-cli. Возможно, проблема возникает, когда удаленный сервер api хочет вернуть ответ, но не может найти способ, как это сделать?
(@Mircea советует добавлять статические маршруты arp, мы добавили их, запросы ARP исчезли из tcpdump, но паузы все еще присутствуют).
вывод tcpdump для php5-fpm:
00:55:22.347822 IP 192.168.182.20.52659 > 192.168.182.22.80: Flags [S], seq 4210728690, win 29200, options [mss 1460,sackOK,TS val 301284147 ecr 0,nop,wscale 7], length 0 E..<..@.@..~...........P..........r............ ..;3........ 00:55:22.347898 IP 192.168.182.22.80 > 192.168.182.20.52659: Flags [S.], seq 2702388053, ack 4210728691, win 28960, options [mss 1460,sackOK,TS val 280740546 ecr 301284147,nop,wscale 7], length 0 E..<..@.@.M@.........P....+U......q .R......... ......;3.... 00:55:22.347906 IP 192.168.182.20.52659 > 192.168.182.22.80: Flags [.], ack 1, win 229, options [nop,nop,TS val 301284147 ecr 280740546], length 0 E..4..@.@..............P......+V........... ..;3.... 00:55:22.347942 IP 192.168.182.20.52659 > 192.168.182.22.80: Flags [P.], seq 1:206, ack 1, win 229, options [nop,nop,TS val 301284147 ecr 280740546], length 205 E.....@.@..............P......+V.....o..... ..;3....POST / HTTP/1.1 Host: 192.168.182.22 Content-Type: application/x-www-form-urlencoded Content-Length: 82 Accept: */* {"id":1,"method":"station.sync","params":[1],"sid":"1gn8f4mhctui9ki91bla6osnf4"} 00:55:22.347997 IP 192.168.182.22.80 > 192.168.182.20.52659: Flags [.], ack 206, win 235, options [nop,nop,TS val 280740547 ecr 301284147], length 0 E..4..@.@.c..........P....+V........2...... ......;3 00:55:27.356575 ARP, Request who-has 192.168.182.22 tell 192.168.182.20, length 28 ..........).4............... 00:55:27.356777 ARP, Reply 192.168.182.22 is-at 00:0c:29:46:99:bc, length 46 ..........)F........).4....................... 00:55:36.742347 IP 192.168.182.22.80 > 192.168.182.20.52659: Flags [P.], seq 1:558, ack 206, win 235, options [nop,nop,TS val 280744145 ecr 301284147], length 557 E..a..@.@.a..........P....+V........a...... ......;3HTTP/1.1 200 OK Server: nginx/1.6.2 Date: Wed, 01 Jul 2015 21:55:36 GMT Content-Type: application/json Transfer-Encoding: chunked Connection: keep-alive Expires: Thu, 19 Nov 1981 08:52:00 GMT Cache-Control: no-store, no-cache, must-revalidate, post-check=0, pre-check=0 Pragma: no-cache Access-Control-Allow-Credentials: true Access-Control-Allow-Headers: Content-Type, X-Requested-With Access-Control-Allow-Methods: GET, POST, OPTIONS p3p: CP=IDC DSP COR ADM DEVi TAIi PSA PSD IVAi IVDi CONi HIS OUR IND CNT 16 {"id":1,"result":true} 0 00:55:36.742374 IP 192.168.182.20.52659 > 192.168.182.22.80: Flags [.], ack 558, win 237, options [nop,nop,TS val 301287746 ecr 280744145], length 0 E..4..@.@..............P......-............ ..IB.... 00:55:36.742486 IP 192.168.182.20.52659 > 192.168.182.22.80: Flags [F.], seq 206, ack 558, win 237, options [nop,nop,TS val 301287746 ecr 280744145], length 0 E..4..@.@..............P......-............ ..IB.... 00:55:36.742559 IP 192.168.182.22.80 > 192.168.182.20.52659: Flags [F.], seq 558, ack 207, win 235, options [nop,nop,TS val 280744145 ecr 301287746], length 0 E..4..@.@.c..........P....-..........:..... ......IB 00:55:36.742566 IP 192.168.182.20.52659 > 192.168.182.22.80: Flags [.], ack 559, win 237, options [nop,nop,TS val 301287746 ecr 280744145], length 0 E..4..@.@..............P......-............ ..IB.... 00:55:41.744102 ARP, Request who-has 192.168.182.20 tell 192.168.182.22, length 46 ..........)F.................................. 00:55:41.744121 ARP, Reply 192.168.182.20 is-at 00:0c:29:04:34:c9, length 28 ..........).4.......)F......
tcpdump для быстрых (консольных / php-cli) запросов:
0:43:46.854062 IP 192.168.182.20.52527 > 192.168.182.22.80: Flags [S], seq 560731240, win 29200, options [mss 1460,sackOK,TS val 301110274 ecr 0,nop,wscale 7], length 0 E..<.j@.@............/.P!lh.....r............ ............ 00:43:46.854198 IP 192.168.182.22.80 > 192.168.182.20.52527: Flags [S.], seq 1849811122, ack 560731241, win 28960, options [mss 1460,sackOK,TS val 280566673 ecr 301110274,nop,wscale 7], length 0 E..<..@.@.M@.........P./nA..!li.q ........... ............ 00:43:46.854216 IP 192.168.182.20.52527 > 192.168.182.22.80: Flags [.], ack 1, win 229, options [nop,nop,TS val 301110274 ecr 280566673], length 0 E..4.k@.@............/.P!l.inA............. ........ 00:43:46.854265 IP 192.168.182.20.52527 > 192.168.182.22.80: Flags [P.], seq 1:233, ack 1, win 229, options [nop,nop,TS val 301110274 ecr 280566673], length 232 E....l@.@............/.P!l.inA............. ........POST / HTTP/1.1 User-Agent: curl/7.38.0 Host: 192.168.182.22 Accept: */* Content-Length: 84 Content-Type: application/x-www-form-urlencoded {"id":1, "sid": "1gn8f4mhctui9ki91bla6osnf4","method":"station.sync", "params":[10]} 00:43:46.854317 IP 192.168.182.22.80 > 192.168.182.20.52527: Flags [.], ack 233, win 235, options [nop,nop,TS val 280566673 ecr 301110274], length 0 E..4."@.@.R%.........P./nA..!lQ...b...... ........ 00:43:46.891248 IP 192.168.182.22.80 > 192.168.182.20.52527: Flags [P.], seq 1:615, ack 233, win 235, options [nop,nop,TS val 280566682 ecr 301110274], length 614 E....#@.@.O..........P./nA..!lQ.......... ........HTTP/1.1 200 OK Server: nginx/1.6.2 Date: Wed, 01 Jul 2015 21:43:46 GMT Content-Type: application/json Transfer-Encoding: chunked Connection: keep-alive Expires: Thu, 19 Nov 1981 08:52:00 GMT Cache-Control: no-store, no-cache, must-revalidate, post-check=0, pre-check=0 Pragma: no-cache Access-Control-Allow-Credentials: true Access-Control-Allow-Headers: Content-Type, X-Requested-With Access-Control-Allow-Methods: GET, POST, OPTIONS p3p: CP=IDC DSP COR ADM DEVi TAIi PSA PSD IVAi IVDi CONi HIS OUR IND CNT 4f {"id":1,"error":{"code":"SERVER_ERROR","message":"Station #10 is not running"}} 0 00:43:46.891273 IP 192.168.182.20.52527 > 192.168.182.22.80: Flags [.], ack 615, win 238, options [nop,nop,TS val 301110283 ecr 280566682], length 0 E..4.m@.@............/.P!l.QnA............. ........ 00:43:46.891932 IP 192.168.182.20.52527 > 192.168.182.22.80: Flags [F.], seq 233, ack 615, win 238, options [nop,nop,TS val 301110283 ecr 280566682], length 0 E..4.n@.@............/.P!l.QnA............. ........ 00:43:46.896944 IP 192.168.182.22.80 > 192.168.182.20.52527: Flags [F.], seq 615, ack 234, win 235, options [nop,nop,TS val 280566684 ecr 301110283], length 0 E..4.$@.@.R#.........P./nA..!lR...`i..... ........ 00:43:46.896954 IP 192.168.182.20.52527 > 192.168.182.22.80: Flags [.], ack 616, win 238, options [nop,nop,TS val 301110285 ecr 280566684], length 0 E..4.o@.@............/.P!l.RnA............. ........
Одна вещь, которую я заметил на моем собственном примере FPM (используя Nginx), заключается в том, что я не получу промежуточный вывод. Я никогда не потрудился расследовать это, поскольку это никогда не имело значения для моих собственных потребностей в использовании (небольшие единицы работы с небольшим объемом выпуска).
В вашем случае, возможно, ответ отправляется быстро, но соединение остается в живых – заставляя получателя ждать дополнительных данных, которые никогда не приходят. Вы можете проверить это, исследуя ведение журнала на стороне сервера, чтобы проверять время ответа с точки зрения сервера.
Я просто отслеживаю аналогичную проблему. Я думаю, это может быть по той же причине. Я сталкиваюсь с подобной проблемой, как авасин. Я обнаружил, что php-fpm curl to localhost медленный, но зависание php-cli на localhost происходит очень быстро. Кроме того, время отладки starttransfer_time показывает высокий starttransfer_time в php-fpm, но довольно низкий в php-процессе.
Я нашел основную причину вчера, проблема в php- fpm в конфигурации http://www.conf . Becuase php-fpm имеет низкий start_server , php-fpm фактически обрабатывает завиток с ограниченным числом процессов php-fpm. Решение состоит в том, чтобы увеличить количество start_server , это повлияет на количество параллелизма, которое может обрабатывать ваш php-fpm. Производительность резко снизится, когда параллелизм превысит количество текущих процессов php-fpm. Следовательно, все становится медленным. У php-cli нет такой же проблемы, поскольку он может запускать много php-процессов, если у вас достаточно памяти, поэтому она всегда быстрая. Я сделал много экспериментов, здесь php curl localhost медленнее при одновременных запросах . Посмотрите, если вы заинтересованы.