The situation is that in a PHP-developed web product, using the Guzzle6 Library as an HTTP client to access the external interface, it is now found that accessing the external interface is slow and takes 15 seconds to receive a response. And in the CLI directly curl this external interface, the response is very fast.
Try to solve this problem by yourself and discover the following phenomena:
1. First of all, guzzle should also be accessed using curl, as seen in the occasional curl error reported by Guzzle. Occasionally curle_couldnt_resolve_host such a mistake.
2. Then determine whether DNS is a problem, direct swap with IP access, the result is the same.
3. Then try the two Curl two options, one is the timeout setting, one is to consider whether the effect of IPV6, corresponding to the guzzle respectively is:
['connect_timeout' => 2, 'curl' => [ CURLOPT_IPRESOLVE => CURL_IPRESOLVE_V4 ],]
is still unchanged.
4. The Access interface host will be replaced with Baidu,qq,taobao these, found that most of the speed of access at this time normal, except QQ. It's slow too.
5. The duration of the visit now appears to be 15 seconds. Finally, the main contents of PHP-FPM are strace as follows:
5519 22:30:08.260401 Connect (7, {sa_family=af_inet, sin_port=htons (+), sin_addr=inet_addr ("121.xx.xx.xx")}, 16) = 1 Einprogress (Operation now in progress) 5519 22:30:08.260744 Clock_gettime (clock_monotonic, {278258, 519214625}) = 05519 22:30:08.260853 poll ([{fd=7, events=pollout| Pollwrnorm}], 1, 149999) = 1 ([{fd=7, revents=pollout| Pollwrnorm}]) 5519 22:30:08.286791 getsockopt (7, Sol_socket, So_error, [0], [4]) = 05519 22:30:08.286851 clock_gettime (CL Ock_monotonic, {278258, 545285059}) = 05519 22:30:08.286891 clock_gettime (clock_monotonic, {278258, 545323358}) = 05519 22:30:08.286926 Clock_gettime (clock_monotonic, {278258, 545358858}) = 05519 22:30:08.286962 clock_gettime (CLOCK_ Monotonic, {278258, 545394658}) = 05519 22:30:08.286997 clock_gettime (clock_monotonic, {278258, 545429558}) = 05519 22:3 0:08.287055 sendto (7, "Get/v1/xxx/xxx http/1.1" ..., $, msg_nosignal, NULL, 0) = 1105519 22:30:08.287206 poll ([{fd=7, E vents=pollin| pollpri| pollrdnorm| Pollrdband}], 1, 0) = 0 (TimEout) 5519 22:30:08.287248 poll ([{fd=7, events=pollin| pollpri| pollrdnorm| Pollrdband}], 1, 0) = 0 (Timeout) 5519 22:30:08.287284 clock_gettime (clock_monotonic, {278258, 545716856}) = 05519 22:30: 08.287350 Clock_gettime (clock_monotonic, {278258, 545782755}) = 05519 22:30:08.287388 clock_gettime (CLOCK_MONOTONIC, { 278258, 545820755}) = 05519 22:30:08.287471 poll ([{fd=7, events=pollin| pollpri| pollrdnorm| Pollrdband}], 1, 1000
.... 5519 22:30:09.288586 <, ... poll resumed>) = 0 (Timeout) 5519 22:30:09.288678 poll ([{fd=7, events=pollin| pollpri| pollrdnorm| Pollrdband}], 1, 0) = 0 (Timeout) 5519 22:30:09.288727 clock_gettime (clock_monotonic, {278259, 547161322}) = 05519 22:30: 09.288767 Clock_gettime (clock_monotonic, {278259, 547199920}) = 05519 22:30:09.288806 clock_gettime (CLOCK_MONOTONIC, { 278259, 547239318}) = 05519 22:30:09.288842 poll ([{fd=7, events=pollin| pollpri| pollrdnorm| Pollrdband}], 1, 1000
... 5519 22:30:10.289957 <, ... poll resumed>) = 0 (Timeout) 5519 22:30:10.290024 poll ([{fd=7, events=pollin| pollpri| pollrdnorm| Pollrdband}], 1, 0) = 0 (Timeout) 5519 22:30:10.290070 clock_gettime (clock_monotonic, {278260, 548504637}) = 05519 22:30: 10.290110 Clock_gettime (clock_monotonic, {278260, 548542537}) = 05519 22:30:10.290149 clock_gettime (CLOCK_MONOTONIC, { 278260, 548581437}) = 05519 22:30:10.290184 poll ([{fd=7, events=pollin| pollpri| pollrdnorm| Pollrdband}], 1, 1000
... Lasts until the 15th second to receive response 5519 22:30:23.309074 < ... poll resumed>) = 0 (Timeout) 5519 22:30:23.309151 poll ([{fd=7, Events=poll in| pollpri| pollrdnorm| Pollrdband}], 1, 0) = 0 (Timeout) 5519 22:30:23.309210 clock_gettime (clock_monotonic, {278273, 567644629}) = 05519 22:30: 23.309250 Clock_gettime (clock_monotonic, {278273, 567682629}) = 05519 22:30:23.309289 clock_gettime (CLOCK_MONOTONIC, { 278273, 567721628}) = 05519 22:30:23.309324 poll ([{fd=7, events=pollin| pollpri| pollrdnorm| Pollrdband}], 1, (+) = 1 ([{fd=7, revents=pollin| Pollrdnorm}]) 5519 22:30:23.386517 poll ([{fd=7, events=pollin| pollpri| pollrdnorm| Pollrdband}], 1, 0) = 1 ([{fd=7, revents=pollin| Pollrdnorm}]) 5519 22:30:23.386578 recvfrom (7, "http/1.1 ok\r\nserver:xxx" ..., 16384, 0, NULL, NULL) = 18375519 22:3 0:23.386676 Clock_gettime (clock_monotonic, {278273, 645121620}) = 0
Please help to analyze what may be the cause of the problem.
Thank you.
Reply content:
The situation is that in a PHP-developed web product, using the Guzzle6 Library as an HTTP client to access the external interface, it is now found that accessing the external interface is slow and takes 15 seconds to receive a response. And in the CLI directly curl this external interface, the response is very fast.
Try to solve this problem by yourself and discover the following phenomena:
1. First of all, guzzle should also be accessed using curl, as seen in the occasional curl error reported by Guzzle. Occasionally curle_couldnt_resolve_host such a mistake.
2. Then determine whether DNS is a problem, direct swap with IP access, the result is the same.
3. Then try the two Curl two options, one is the timeout setting, one is to consider whether the effect of IPV6, corresponding to the guzzle respectively is:
['connect_timeout' => 2, 'curl' => [ CURLOPT_IPRESOLVE => CURL_IPRESOLVE_V4 ],]
is still unchanged.
4. The Access interface host will be replaced with Baidu,qq,taobao these, found that most of the speed of access at this time normal, except QQ. It's slow too.
5. The duration of the visit now appears to be 15 seconds. Finally, the main contents of PHP-FPM are strace as follows:
5519 22:30:08.260401 Connect (7, {sa_family=af_inet, sin_port=htons (+), sin_addr=inet_addr ("121.xx.xx.xx")}, 16) = 1 Einprogress (Operation now in progress) 5519 22:30:08.260744 Clock_gettime (clock_monotonic, {278258, 519214625}) = 05519 22:30:08.260853 poll ([{fd=7, events=pollout| Pollwrnorm}], 1, 149999) = 1 ([{fd=7, revents=pollout| Pollwrnorm}]) 5519 22:30:08.286791 getsockopt (7, Sol_socket, So_error, [0], [4]) = 05519 22:30:08.286851 clock_gettime (CL Ock_monotonic, {278258, 545285059}) = 05519 22:30:08.286891 clock_gettime (clock_monotonic, {278258, 545323358}) = 05519 22:30:08.286926 Clock_gettime (clock_monotonic, {278258, 545358858}) = 05519 22:30:08.286962 clock_gettime (CLOCK_ Monotonic, {278258, 545394658}) = 05519 22:30:08.286997 clock_gettime (clock_monotonic, {278258, 545429558}) = 05519 22:3 0:08.287055 sendto (7, "Get/v1/xxx/xxx http/1.1" ..., $, msg_nosignal, NULL, 0) = 1105519 22:30:08.287206 poll ([{fd=7, E vents=pollin| pollpri| pollrdnorm| Pollrdband}], 1, 0) = 0 (TimEout) 5519 22:30:08.287248 poll ([{fd=7, events=pollin| pollpri| pollrdnorm| Pollrdband}], 1, 0) = 0 (Timeout) 5519 22:30:08.287284 clock_gettime (clock_monotonic, {278258, 545716856}) = 05519 22:30: 08.287350 Clock_gettime (clock_monotonic, {278258, 545782755}) = 05519 22:30:08.287388 clock_gettime (CLOCK_MONOTONIC, { 278258, 545820755}) = 05519 22:30:08.287471 poll ([{fd=7, events=pollin| pollpri| pollrdnorm| Pollrdband}], 1, 1000
.... 5519 22:30:09.288586 <, ... poll resumed>) = 0 (Timeout) 5519 22:30:09.288678 poll ([{fd=7, events=pollin| pollpri| pollrdnorm| Pollrdband}], 1, 0) = 0 (Timeout) 5519 22:30:09.288727 clock_gettime (clock_monotonic, {278259, 547161322}) = 05519 22:30: 09.288767 Clock_gettime (clock_monotonic, {278259, 547199920}) = 05519 22:30:09.288806 clock_gettime (CLOCK_MONOTONIC, { 278259, 547239318}) = 05519 22:30:09.288842 poll ([{fd=7, events=pollin| pollpri| pollrdnorm| Pollrdband}], 1, 1000
... 5519 22:30:10.289957 <, ... poll resumed>) = 0 (Timeout) 5519 22:30:10.290024 poll ([{fd=7, events=pollin| pollpri| pollrdnorm| Pollrdband}], 1, 0) = 0 (Timeout) 5519 22:30:10.290070 clock_gettime (clock_monotonic, {278260, 548504637}) = 05519 22:30: 10.290110 Clock_gettime (clock_monotonic, {278260, 548542537}) = 05519 22:30:10.290149 clock_gettime (CLOCK_MONOTONIC, { 278260, 548581437}) = 05519 22:30:10.290184 poll ([{fd=7, events=pollin| pollpri| pollrdnorm| Pollrdband}], 1, 1000
... Lasts until the 15th second to receive response 5519 22:30:23.309074 < ... poll resumed>) = 0 (Timeout) 5519 22:30:23.309151 poll ([{fd=7, Events=poll in| pollpri| pollrdnorm| Pollrdband}], 1, 0) = 0 (Timeout) 5519 22:30:23.309210 clock_gettime (clock_monotonic, {278273, 567644629}) = 05519 22:30: 23.309250 Clock_gettime (clock_monotonic, {278273, 567682629}) = 05519 22:30:23.309289 clock_gettime (CLOCK_MONOTONIC, { 278273, 567721628}) = 05519 22:30:23.309324 poll ([{fd=7, events=pollin| pollpri| pollrdnorm| Pollrdband}], 1, (+) = 1 ([{fd=7, revents=pollin| Pollrdnorm}]) 5519 22:30:23.386517 poll ([{fd=7, events=pollin| pollpri| pollrdnorm| Pollrdband}], 1, 0) = 1 ([{fd=7, revents=pollin| Pollrdnorm}]) 5519 22:30:23.386578 recvfrom (7, "http/1.1 ok\r\nserver:xxx" ..., 16384, 0, NULL, NULL) = 18375519 22:3 0:23.386676 Clock_gettime (clock_monotonic, {278273, 645121620}) = 0
Please help to analyze what may be the cause of the problem.
Thank you.
If the requirements are not too complex, or to encapsulate a simple httpclient, so to find a third-party library problem is more troublesome, or use debugging tools run to see
Try it again, just use curl to get a look at the speed.