PHP的CURL报错的排查记录:短连接的成本真的很高啊

最近在优化接口的时候发现,php的curl调用远程接口的时候出现了大量的这种错误

* Resolving timed out after 100 milliseconds
* Closing connection 0

问题是,我们这些接口的域名都是配置在hosts文件里的,没有道理会解析超时,然后有同事贴出鸟哥的一篇文章,Curl的毫秒超时的一个”Bug”,怀疑是libcurl库的bug,然后下载libcurl的源码看了半天,并没有找到什么奇怪的地方。

在我一筹莫展百无聊赖的时候,我改了curl一个参数CURLOPT_CONNECTTIMEOUT_MS,立马重现了这个错误。

<?php

function call()
{
    $ch = curl_init();
    curl_setopt($ch, CURLOPT_URL, "http://www.oschina.net/");
    curl_setopt($ch, CURLOPT_DNS_USE_GLOBAL_CACHE, TRUE);
    curl_setopt($ch, CURLOPT_DNS_CACHE_TIMEOUT, 300);
    curl_setopt($ch, CURLOPT_HEADER, TRUE);
    curl_setopt($ch, CURLOPT_VERBOSE, 1);
    curl_setopt($ch, CURLOPT_RETURNTRANSFER, TRUE);
    curl_setopt($ch, CURLOPT_FAILONERROR, TRUE);
    @curl_setopt($ch, CURLOPT_FOLLOWLOCATION, true);
    curl_setopt($ch, CURLOPT_MAXREDIRS, 5);
    curl_setopt($ch, CURLOPT_CONNECTTIMEOUT, false);
    curl_setopt($ch, CURLOPT_TIMEOUT, false);
    curl_setopt($ch, CURLOPT_CONNECTTIMEOUT_MS, 5);//这个连接超时时间,我们使用的是线上使用是100
    curl_setopt($ch, CURLOPT_TIMEOUT_MS, 1000);

    curl_setopt($ch, CURLOPT_SSL_VERIFYPEER, 0);
    curl_setopt($ch, CURLOPT_SSL_VERIFYHOST, 0);

    curl_setopt($ch, CURLOPT_USERAGENT, 'Mozilla/5.0 (Windows NT 6.1; WOW64) PHP-AccountAPI/1.1');

    $header = [];
    $header[] = "Accept-Language: zh-CN,zh;q=0.8,en;q=0.6";
    $header[] = "Accept-Charset: GBK,utf-8;q=0.7,*;q=0.3";

    curl_setopt($ch, CURLOPT_HTTPHEADER, $header);

    var_dump(curl_error($ch));
    var_dump(curl_errno($ch));

    $response = curl_exec($ch);
    var_dump($response);
}

call();

然后我就把这个参数改成了200毫秒,果然线上就再也没有报这错误。

虽然问题解决了,但是我很惊讶,为什么一个配置在hosts文件里的域名解析居然能消耗100多毫秒,然后开始分析curl在这个过程中干了什么,用strace跟踪下。

strace -o output.txt -f -T -tt -e trace=all php test.php

贴出部分结果

……略
24861 03:17:05.186737 open("web/local/test.php", O_RDONLY) = 4 <0.000361>
24861 03:17:05.187208 fstat(4, {st_mode=S_IFREG|0777, st_size=1246, ...}) = 0 <0.000062>
24861 03:17:05.187402 mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f51ae4b0000 <0.000006>
24861 03:17:05.187587 read(4, "<?php\n\nfunction call()\n{\n       "..., 4096) = 1246 <0.000017>
24861 03:17:05.187660 lseek(4, 0, SEEK_SET) = 0 <0.000006>
24861 03:17:05.187914 getcwd("/var/www/bili", 4096) = 14 <0.000004>
24861 03:17:05.188016 lstat("/var/www/bili/web/local/test.php", {st_mode=S_IFREG|0777, st_size=1246, ...}) = 0 <0.000167>
24861 03:17:05.188260 lstat("/var/www/bili/web/local", {st_mode=S_IFDIR|0777, st_size=272, ...}) = 0 <0.000129>
24861 03:17:05.188463 lstat("/var/www/bili/web", {st_mode=S_IFDIR|0777, st_size=1666, ...}) = 0 <0.000098>
24861 03:17:05.188633 lstat("/var/www/bili", {st_mode=S_IFDIR|0777, st_size=544, ...}) = 0 <0.000069>
24861 03:17:05.188774 lstat("/var/www", {st_mode=S_IFDIR|0777, st_size=136, ...}) = 0 <0.000049>
24861 03:17:05.188902 lstat("/var", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0 <0.000004>
24861 03:17:05.188981 rt_sigaction(SIGPROF, {0x6dbc70, [PROF], SA_RESTORER|SA_RESTART, 0x7f51aaf820e0}, {SIG_DFL, [], 0}, 8) = 0 <0.000004>
24861 03:17:05.189065 rt_sigprocmask(SIG_UNBLOCK, [PROF], NULL, 8) = 0 <0.000004>
24861 03:17:05.189179 fstat(0, {st_mode=S_IFCHR|0620, st_rdev=makedev(136, 0), ...}) = 0 <0.000005>
24861 03:17:05.189255 fstat(0, {st_mode=S_IFCHR|0620, st_rdev=makedev(136, 0), ...}) = 0 <0.000003>
24861 03:17:05.189322 fstat(0, {st_mode=S_IFCHR|0620, st_rdev=makedev(136, 0), ...}) = 0 <0.000003>
24861 03:17:05.189387 mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f51ae4af000 <0.000005>
24861 03:17:05.189453 lseek(0, 0, SEEK_CUR) = -1 ESPIPE (Illegal seek) <0.000003>
24861 03:17:05.189520 fstat(1, {st_mode=S_IFCHR|0620, st_rdev=makedev(136, 0), ...}) = 0 <0.000004>
24861 03:17:05.189587 fstat(1, {st_mode=S_IFCHR|0620, st_rdev=makedev(136, 0), ...}) = 0 <0.000004>
24861 03:17:05.189652 fstat(1, {st_mode=S_IFCHR|0620, st_rdev=makedev(136, 0), ...}) = 0 <0.000003>
24861 03:17:05.189716 mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f51ae4ae000 <0.000004>
24861 03:17:05.189780 lseek(1, 0, SEEK_CUR) = -1 ESPIPE (Illegal seek) <0.000004>
24861 03:17:05.189845 fstat(2, {st_mode=S_IFCHR|0620, st_rdev=makedev(136, 0), ...}) = 0 <0.000003>
24861 03:17:05.189913 fstat(2, {st_mode=S_IFCHR|0620, st_rdev=makedev(136, 0), ...}) = 0 <0.000003>
24861 03:17:05.189979 lseek(2, 0, SEEK_CUR) = -1 ESPIPE (Illegal seek) <0.000003>
24861 03:17:05.190045 getcwd("/var/www/bili", 4096) = 14 <0.000004>
24861 03:17:05.190134 ioctl(4, SNDCTL_TMR_TIMEBASE or SNDRV_TIMER_IOCTL_NEXT_DEVICE or TCGETS, 0x7ffe2ce060d0) = -1 ENOTTY (Inappropriate ioctl for device) <0.000004>
24861 03:17:05.190201 fstat(4, {st_mode=S_IFREG|0777, st_size=1246, ...}) = 0 <0.000037>
24861 03:17:05.190315 mmap(NULL, 1278, PROT_READ, MAP_PRIVATE, 4, 0) = 0x7f51ae4ad000 <0.000006>
24861 03:17:05.190494 munmap(0x7f51ae4ad000, 1278) = 0 <0.000007>
24861 03:17:05.190572 close(4)          = 0 <0.000037>
24861 03:17:05.190676 munmap(0x7f51ae4b0000, 4096) = 0 <0.000008>
24861 03:17:05.190764 socket(PF_INET, SOCK_STREAM, IPPROTO_IP) = 4 <0.000013>
24861 03:17:05.190840 fcntl(4, F_SETFL, O_RDONLY|O_NONBLOCK) = 0 <0.000003>
24861 03:17:05.190911 connect(4, {sa_family=AF_INET, sin_port=htons(10002), sin_addr=inet_addr("172.16.12.183")}, 16) = -1 EINPROGRESS (Operation now in progress) <0.000075>
24861 03:17:05.191154 select(5, [4], [4], [4], {0, 200000}) = 2 (in [4], out [4], left {0, 199997}) <0.000007>
24861 03:17:05.191301 getpeername(4, 0x7ffe2ce06440, [16]) = -1 ENOTCONN (Transport endpoint is not connected) <0.000003>
24861 03:17:05.191450 stat("/tmp/cachegrind.out.24861", 0x7ffe2ce06440) = -1 ENOENT (No such file or directory) <0.000015>
24861 03:17:05.191668 open("/tmp/cachegrind.out.24861", O_WRONLY|O_CREAT|O_TRUNC, 0666) = 5 <0.000026>
24861 03:17:05.191825 flock(5, LOCK_EX|LOCK_NB) = 0 <0.000005>
24861 03:17:05.191946 fstat(5, {st_mode=S_IFREG|0644, st_size=0, ...}) = 0 <0.000004>
24861 03:17:05.192037 mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f51ae4b0000 <0.000006>
24861 03:17:05.192110 write(5, "version: 1\ncreator: xdebug 2.2.5"..., 110) = 110 <0.000017>
24861 03:17:05.192228 write(5, "fl=php:internal\nfn=php::curl_ini"..., 34) = 34 <0.000007>
24861 03:17:05.192313 write(5, "5 17\n\n", 6) = 6 <0.000006>
24861 03:17:05.192405 write(5, "fl=php:internal\nfn=php::curl_set"..., 36) = 36 <0.000006>
24861 03:17:05.192478 write(5, "6 2\n\n", 5) = 5 <0.000006>
24861 03:17:05.192554 write(5, "fl=php:internal\nfn=php::curl_set"..., 36) = 36 <0.000006>
24861 03:17:05.192626 write(5, "7 1\n\n", 5) = 5 <0.000006>
24861 03:17:05.192699 write(5, "fl=php:internal\nfn=php::curl_set"..., 36) = 36 <0.000006>
24861 03:17:05.192770 write(5, "8 1\n\n", 5) = 5 <0.000006>
24861 03:17:05.192843 write(5, "fl=php:internal\nfn=php::curl_set"..., 36) = 36 <0.000006>
24861 03:17:05.192913 write(5, "9 1\n\n", 5) = 5 <0.000006>
24861 03:17:05.192986 write(5, "fl=php:internal\nfn=php::curl_set"..., 36) = 36 <0.000006>
24861 03:17:05.193057 write(5, "10 0\n\n", 6) = 6 <0.000005>
24861 03:17:05.193131 write(5, "fl=php:internal\nfn=php::curl_set"..., 36) = 36 <0.000006>
24861 03:17:05.193202 write(5, "11 0\n\n", 6) = 6 <0.000006>
24861 03:17:05.193278 write(5, "fl=php:internal\nfn=php::curl_set"..., 36) = 36 <0.000007>
24861 03:17:05.193349 write(5, "12 0\n\n", 6) = 6 <0.000005>
24861 03:17:05.193422 write(5, "fl=php:internal\nfn=php::curl_set"..., 36) = 36 <0.000006>
24861 03:17:05.193492 write(5, "13 1\n\n", 6) = 6 <0.000006>
24861 03:17:05.193565 write(5, "fl=php:internal\nfn=php::curl_set"..., 36) = 36 <0.000006>
24861 03:17:05.193710 write(5, "14 0\n\n", 6) = 6 <0.000006>
24861 03:17:05.193869 write(5, "fl=php:internal\nfn=php::curl_set"..., 36) = 36 <0.000006>
24861 03:17:05.194032 write(5, "15 1\n\n", 6) = 6 <0.000011>
24861 03:17:05.194298 write(5, "fl=php:internal\nfn=php::curl_set"..., 36) = 36 <0.000016>
24861 03:17:05.194460 write(5, "16 1\n\n", 6) = 6 <0.000011>
24861 03:17:05.194695 write(5, "fl=php:internal\nfn=php::curl_set"..., 36) = 36 <0.000010>
24861 03:17:05.194857 write(5, "18 0\n\n", 6) = 6 <0.000007>
24861 03:17:05.194944 write(5, "fl=php:internal\nfn=php::curl_set"..., 36) = 36 <0.000006>
24861 03:17:05.195020 write(5, "19 2\n\n", 6) = 6 <0.000006>
24861 03:17:05.195097 write(5, "fl=php:internal\nfn=php::curl_set"..., 36) = 36 <0.000006>
24861 03:17:05.195170 write(5, "21 1\n\n", 6) = 6 <0.000005>
24861 03:17:05.195255 write(5, "fl=php:internal\nfn=php::curl_set"..., 36) = 36 <0.000007>
24861 03:17:05.195330 write(5, "27 1\n\n", 6) = 6 <0.000006>
24861 03:17:05.195406 write(5, "fl=php:internal\nfn=php::curl_err"..., 35) = 35 <0.000006>
24861 03:17:05.195479 write(5, "29 0\n\n", 6) = 6 <0.000006>
24861 03:17:05.195571 write(1, "string(0) \"\"\n", 13) = 13 <0.000152>
24861 03:17:05.195846 write(5, "fl=php:internal\nfn=php::var_dump"..., 33) = 33 <0.000010>
24861 03:17:05.196087 write(5, "29 231\n\n", 8) = 8 <0.000007>
24861 03:17:05.196260 write(5, "fl=php:internal\nfn=php::curl_err"..., 35) = 35 <0.000006>
24861 03:17:05.196542 write(5, "30 0\n\n", 6) = 6 <0.000006>
24861 03:17:05.196703 write(1, "int(0)\n", 7) = 7 <0.000097>
24861 03:17:05.196922 write(5, "fl=php:internal\nfn=php::var_dump"..., 33) = 33 <0.000008>
24861 03:17:05.197067 write(5, "30 229\n\n", 8) = 8 <0.000006>
24861 03:17:05.197167 rt_sigaction(SIGPIPE, NULL, {SIG_IGN, [PIPE], SA_RESTORER|SA_RESTART, 0x7f51aaf820e0}, 8) = 0 <0.000004>
24861 03:17:05.197242 rt_sigaction(SIGPIPE, {SIG_IGN, [PIPE], SA_RESTORER|SA_RESTART, 0x7f51aad3f8d0}, NULL, 8) = 0 <0.000003>
24861 03:17:05.197320 rt_sigaction(SIGPIPE, NULL, {SIG_IGN, [PIPE], SA_RESTORER|SA_RESTART, 0x7f51aad3f8d0}, 8) = 0 <0.000003>
24861 03:17:05.197388 rt_sigaction(SIGPIPE, {SIG_IGN, [PIPE], SA_RESTORER|SA_RESTART, 0x7f51aad3f8d0}, NULL, 8) = 0 <0.000004>
24861 03:17:05.197487 write(2, "* ", 2) = 2 <0.000076>
24861 03:17:05.197695 write(2, "Hostname was NOT found in DNS ca"..., 36) = 36 <0.000086>
24861 03:17:05.197932 socket(PF_INET6, SOCK_DGRAM, IPPROTO_IP) = 6 <0.000000>
24861 03:17:05.198121 close(6)          = 0 <0.000008>
24861 03:17:05.198257 mmap(NULL, 8392704, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS|MAP_STACK, -1, 0) = 0x7f51a04c3000 <0.000007>
24861 03:17:05.198386 mprotect(0x7f51a04c3000, 4096, PROT_NONE) = 0 <0.000006>
24861 03:17:05.198464 clone(child_stack=0x7f51a0cc2fb0, flags=CLONE_VM|CLONE_FS|CLONE_FILES|CLONE_SIGHAND|CLONE_THREAD|CLONE_SYSVSEM|CLONE_SETTLS|CLONE_PARENT_SETTID|CLONE_CHILD_CLEARTID, parent_tidptr=0x7f51a0cc39d0, tls=0x7f51a0cc3700, child_tidptr=0x7f51a0cc39d0) = 24862 <0.000014>
24861 03:17:05.198635 rt_sigaction(SIGPIPE, {SIG_IGN, [PIPE], SA_RESTORER|SA_RESTART, 0x7f51aad3f8d0}, NULL, 8) = 0 <0.000004>
24861 03:17:05.198717 rt_sigaction(SIGPIPE, NULL, {SIG_IGN, [PIPE], SA_RESTORER|SA_RESTART, 0x7f51aad3f8d0}, 8) = 0 <0.000003>
24861 03:17:05.198788 rt_sigaction(SIGPIPE, {SIG_IGN, [PIPE], SA_RESTORER|SA_RESTART, 0x7f51aad3f8d0}, NULL, 8) = 0 <0.000004>
24861 03:17:05.198867 rt_sigaction(SIGPIPE, {SIG_IGN, [PIPE], SA_RESTORER|SA_RESTART, 0x7f51aad3f8d0}, NULL, 8) = 0 <0.000004>
24861 03:17:05.198946 poll(0, 0, 4 <unfinished ...>
24862 03:17:05.198997 set_robust_list(0x7f51a0cc39e0, 24) = 0 <0.000004>
24862 03:17:05.199084 socket(PF_LOCAL, SOCK_STREAM|SOCK_CLOEXEC|SOCK_NONBLOCK, 0) = 6 <0.000007>
24862 03:17:05.199158 connect(6, {sa_family=AF_LOCAL, sun_path="/var/run/nscd/socket"}, 110) = -1 ENOENT (No such file or directory) <0.000012>
24862 03:17:05.199240 close(6)          = 0 <0.000005>
24862 03:17:05.199324 socket(PF_LOCAL, SOCK_STREAM|SOCK_CLOEXEC|SOCK_NONBLOCK, 0) = 6 <0.000005>
24862 03:17:05.199401 connect(6, {sa_family=AF_LOCAL, sun_path="/var/run/nscd/socket"}, 110) = -1 ENOENT (No such file or directory) <0.000007>
24862 03:17:05.199477 close(6)          = 0 <0.000005>
24862 03:17:05.199555 mmap(NULL, 134217728, PROT_NONE, MAP_PRIVATE|MAP_ANONYMOUS|MAP_NORESERVE, -1, 0) = 0x7f51984c3000 <0.000005>
24862 03:17:05.199623 munmap(0x7f51984c3000, 62115840) = 0 <0.000008>
24862 03:17:05.199696 munmap(0x7f51a0000000, 4993024) = 0 <0.000005>
24862 03:17:05.199773 mprotect(0x7f519c000000, 135168, PROT_READ|PROT_WRITE) = 0 <0.000005>
24862 03:17:05.199846 open("/etc/nsswitch.conf", O_RDONLY|O_CLOEXEC) = 6 <0.000006>
24862 03:17:05.199928 fstat(6, {st_mode=S_IFREG|0644, st_size=497, ...}) = 0 <0.000004>
24862 03:17:05.199999 mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f51ae4ad000 <0.000005>
24862 03:17:05.200083 read(6, "# /etc/nsswitch.conf\n#\n# Example"..., 4096) = 497 <0.000006>
24862 03:17:05.200186 read(6, "", 4096) = 0 <0.000004>
24862 03:17:05.200375 close(6)          = 0 <0.000006>
24862 03:17:05.200575 munmap(0x7f51ae4ad000, 4096) = 0 <0.000011>
24862 03:17:05.200782 open("/etc/host.conf", O_RDONLY|O_CLOEXEC) = 6 <0.000008>
24862 03:17:05.200988 fstat(6, {st_mode=S_IFREG|0644, st_size=9, ...}) = 0 <0.000006>
24862 03:17:05.201191 mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f51ae4ad000 <0.000007>
24862 03:17:05.201393 read(6, "multi on\n", 4096) = 9 <0.000009>
24862 03:17:05.201599 read(6, "", 4096) = 0 <0.000006>
24862 03:17:05.201800 close(6)          = 0 <0.000007>
24862 03:17:05.201999 munmap(0x7f51ae4ad000, 4096) = 0 <0.000009>
24862 03:17:05.202172 futex(0x7f51ab2f6bc4, FUTEX_WAKE_PRIVATE, 2147483647) = 0 <0.000004>
24862 03:17:05.202336 open("/etc/resolv.conf", O_RDONLY|O_CLOEXEC) = 6 <0.000006>
24862 03:17:05.202462 fstat(6, {st_mode=S_IFREG|0644, st_size=20, ...}) = 0 <0.000004>
24862 03:17:05.202574 mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f51ae4ad000 <0.000006>
24862 03:17:05.202644 read(6, "nameserver 10.0.2.3\n", 4096) = 20 <0.000006>
24862 03:17:05.202716 read(6, "", 4096) = 0 <0.000004>
24862 03:17:05.202789 close(6)          = 0 <0.000005>
24862 03:17:05.202862 munmap(0x7f51ae4ad000, 4096) = 0 <0.000008>
24862 03:17:05.202934 uname({sys="Linux", node="debian", ...}) = 0 <0.000004>
24862 03:17:05.203034 open("/etc/ld.so.cache", O_RDONLY|O_CLOEXEC <unfinished ...>
24861 03:17:05.203072 <... poll resumed> ) = 0 (Timeout) <0.004086>
24861 03:17:05.203111 rt_sigaction(SIGPIPE, NULL, {SIG_IGN, [PIPE], SA_RESTORER|SA_RESTART, 0x7f51aad3f8d0}, 8) = 0 <0.000004>
24861 03:17:05.203181 rt_sigaction(SIGPIPE, {SIG_IGN, [PIPE], SA_RESTORER|SA_RESTART, 0x7f51aad3f8d0}, NULL, 8) = 0 <0.000004>
24861 03:17:05.203259 write(2, "* ", 2) = 2 <0.000085>
24861 03:17:05.203446 write(2, "Resolving timed out after 5 mill"..., 41) = 41 <0.000084>
24861 03:17:05.203790 rt_sigaction(SIGPIPE, {SIG_IGN, [PIPE], SA_RESTORER|SA_RESTART, 0x7f51aad3f8d0}, NULL, 8) = 0 <0.000005>
24861 03:17:05.203947 write(2, "* ", 2) = 2 <0.000069>
24861 03:17:05.204120 write(2, "Closing connection 0\n", 21) = 21 <0.000077>
24861 03:17:05.204424 rt_sigaction(SIGPIPE, {SIG_IGN, [PIPE], SA_RESTORER|SA_RESTART, 0x7f51aad3f8d0}, NULL, 8) = 0 <0.000004>
24861 03:17:05.204522 write(5, "fl=php:internal\nfn=php::curl_exe"..., 34) = 34 <0.000009>
24861 03:17:05.204598 write(5, "32 7376\n\n", 9) = 9 <0.000006>
24861 03:17:05.204673 rt_sigaction(SIGPIPE, NULL, {SIG_IGN, [PIPE], SA_RESTORER|SA_RESTART, 0x7f51aad3f8d0}, 8) = 0 <0.000003>
24861 03:17:05.204740 rt_sigaction(SIGPIPE, {SIG_IGN, [PIPE], SA_RESTORER|SA_RESTART, 0x7f51aad3f8d0}, NULL, 8) = 0 <0.000003>
24861 03:17:05.204813 rt_sigaction(SIGPIPE, NULL, {SIG_IGN, [PIPE], SA_RESTORER|SA_RESTART, 0x7f51aad3f8d0}, 8) = 0 <0.000003>
24861 03:17:05.204885 rt_sigaction(SIGPIPE, {SIG_IGN, [PIPE], SA_RESTORER|SA_RESTART, 0x7f51aad3f8d0}, NULL, 8) = 0 <0.000004>
24861 03:17:05.204959 rt_sigaction(SIGPIPE, {SIG_IGN, [PIPE], SA_RESTORER|SA_RESTART, 0x7f51aad3f8d0}, NULL, 8) = 0 <0.000004>
24861 03:17:05.205033 rt_sigaction(SIGPIPE, {SIG_IGN, [PIPE], SA_RESTORER|SA_RESTART, 0x7f51aad3f8d0}, NULL, 8) = 0 <0.000003>
24861 03:17:05.205111 write(5, "fl=/var/www/bili/web/local/test."..., 44) = 44 <0.000007>
24861 03:17:05.205195 write(5, "3 5022\ncfl=php:internal\ncfn=php:"..., 1154) = 1154 <0.000006>
24861 03:17:05.205279 write(5, "fl=/var/www/bili/web/local/test."..., 63) = 63 <0.000007>
24861 03:17:05.205351 write(5, "1 180\ncfl=/var/www/bili/web/loca"..., 74) = 74 <0.000024>
24861 03:17:05.205663 close(2)          = 0 <0.000005>
24861 03:17:05.205799 close(1)          = 0 <0.000003>
24861 03:17:05.205926 munmap(0x7f51ae4ae000, 4096) = 0 <0.000006>
24861 03:17:05.206059 close(0)          = 0 <0.000004>
24861 03:17:05.206166 munmap(0x7f51ae4af000, 4096) = 0 <0.000006>
24861 03:17:05.206260 close(5)          = 0 <0.000006>
24861 03:17:05.206335 munmap(0x7f51ae4b0000, 4096) = 0 <0.000007>
24861 03:17:05.206560 futex(0x7f51ae4b4968, FUTEX_WAIT_PRIVATE, 2, NULL <unfinished ...>
24862 03:17:05.206601 <... open resumed> ) = 6 <0.003531>
24862 03:17:05.206635 fstat(6, {st_mode=S_IFREG|0644, st_size=27024, ...}) = 0 <0.000004>
24862 03:17:05.206712 mmap(NULL, 27024, PROT_READ, MAP_PRIVATE, 6, 0) = 0x7f51ae4aa000 <0.000006>
24862 03:17:05.206779 close(6)          = 0 <0.000012>
24862 03:17:05.206897 access("/etc/ld.so.nohwcap", F_OK) = -1 ENOENT (No such file or directory) <0.000006>
24862 03:17:05.206976 open("/lib/x86_64-linux-gnu/libnss_files.so.2", O_RDONLY|O_CLOEXEC) = 0 <0.000009>
24862 03:17:05.207047 read(0, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\240\"\0\0\0\0\0\0"..., 832) = 832 <0.000005>
24862 03:17:05.207117 fstat(0, {st_mode=S_IFREG|0644, st_size=47712, ...}) = 0 <0.000003>
24862 03:17:05.207189 mmap(NULL, 2144392, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 0, 0) = 0x7f51a02b7000 <0.000007>
24862 03:17:05.207259 mprotect(0x7f51a02c2000, 2093056, PROT_NONE) = 0 <0.000008>
24862 03:17:05.207327 mmap(0x7f51a04c1000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 0, 0xa000) = 0x7f51a04c1000 <0.000007>
24862 03:17:05.207404 close(0)          = 0 <0.000003>
24862 03:17:05.207515 mprotect(0x7f51a04c1000, 4096, PROT_READ) = 0 <0.000008>
24862 03:17:05.207587 munmap(0x7f51ae4aa000, 27024) = 0 <0.000009>
24862 03:17:05.207660 futex(0x7f51ae4b4968, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
24861 03:17:05.207696 <... futex resumed> ) = 0 <0.001100>
……略

通过strace的跟踪,可以发现curl在请求的过程当中,打开了很多文件,涉及到很多系统调用,做这些事情的成本都是很高的。

所以,尽可能的使用长连接吧!

但是,php长连接有个硬伤,算了,不提了,以后有心情了在写吧。

更多架构、PHP、GO相关踩坑实践技巧请关注我的公众号:PHP架构师

转载于:https://my.oschina.net/u/222608/blog/808708

评论
添加红包

请填写红包祝福语或标题

红包个数最小为10个

红包金额最低5元

当前余额3.43前往充值 >
需支付:10.00
成就一亿技术人!
领取后你会自动成为博主和红包主的粉丝 规则
hope_wisdom
发出的红包
实付
使用余额支付
点击重新获取
扫码支付
钱包余额 0

抵扣说明:

1.余额是钱包充值的虚拟货币,按照1:1的比例进行支付金额的抵扣。
2.余额无法直接购买下载,可以购买VIP、付费专栏及课程。

余额充值