doucu7330
2017-05-16 09:00
浏览 196
已采纳

php set_time_limit()在php-fpm上生成超时

I have a strange issue with php-fpm and set_time_limit(). After i upgraded php at all to 5.6.30 a previously worked script dies with timeout.

<?php
set_time_limit( 300 );
echo "ok";

The result is:

( ! ) Fatal error: Maximum execution time of 30 seconds exceeded in /var/www/hutml/asd.php on line 2
Call Stack
#   Time    Memory  Function    Location
1   0.0002  238976  {main}( )   .../asd.php:0
2   0.0004  239616  set_time_limit ( )  .../asd.php:2

The interesting part is if i restart php-fpm it works for a few requests (3-8) and than stops working forever (till next restart).

Here is the trace where it not works:

Process 12972 attached
0.000000 accept(0, {sa_family=AF_INET, sin_port=htons(49070), sin_addr=inet_addr("127.0.0.1")}, [16]) = 4
0.738389 clock_gettime(CLOCK_MONOTONIC, {668002, 562282734}) = 0
0.000045 gettimeofday({1494920122, 398537}, NULL) = 0
0.000033 times({tms_utime=5129, tms_stime=553, tms_cutime=0, tms_cstime=0}) = 496191553
0.000057 poll([{fd=4, events=POLLIN}], 1, 5000) = 1 ([{fd=4, revents=POLLIN}])
0.000054 read(4, "\1\1\0\1\0\10\0\0", 8) = 8
0.000042 read(4, "\0\1\0\0\0\0\0\0", 8) = 8
0.000035 read(4, "\1\4\0\1\5b\6\0", 8) = 8
0.000030 read(4, "\f\0QUERY_STRING\16\3REQUEST_METHODGE"..., 1384) = 1384
0.000065 read(4, "\1\4\0\1\0\0\0\0", 8) = 8
0.000041 gettimeofday({1494920122, 398893}, NULL) = 0
0.000031 lstat("/var/www/hutml/asd.php", {st_mode=S_IFREG|0644, st_size=40, ...}) = 0
0.000097 clock_gettime(CLOCK_MONOTONIC, {668002, 562819467}) = 0
0.000059 gettimeofday({1494920122, 399081}, NULL) = 0
0.000040 gettimeofday({1494920122, 399120}, NULL) = 0
0.000033 setitimer(ITIMER_PROF, {it_interval={0, 0}, it_value={60, 0}}, NULL) = 0
0.000037 rt_sigaction(SIGPROF, {0x5d4980, [PROF], SA_RESTORER|SA_RESTART, 0x7efdf5602510}, {0x5d4980, [PROF], SA_RESTORER|SA_RESTART, 0x7efdf5602510}, 8) = 0
0.000102 rt_sigprocmask(SIG_UNBLOCK, [PROF], NULL, 8) = 0
0.000633 gettimeofday({1494920122, 399930}, NULL) = 0
0.000101 clock_gettime(CLOCK_MONOTONIC, {668002, 563838495}) = 0
0.000079 getcwd("/", 4095) = 2
0.000039 chdir("/var/www/hutml") = 0
0.000043 setitimer(ITIMER_PROF, {it_interval={0, 0}, it_value={30, 0}}, NULL) = 0
0.000035 fcntl(3, F_SETLK, {type=F_RDLCK, whence=SEEK_SET, start=1, len=1}) = 0
0.000081 stat("/var/www/hutml/asd.php", {st_mode=S_IFREG|0644, st_size=40, ...}) = 0
0.000060 gettimeofday({1494920122, 400364}, NULL) = 0
0.000047 gettimeofday({1494920122, 400409}, NULL) = 0
30.079993 --- SIGPROF {si_signo=SIGPROF, si_code=SI_KERNEL, si_value={int=0, ptr=0x100000000}} ---
0.000198 setitimer(ITIMER_PROF, {it_interval={0, 0}, it_value={30, 0}}, NULL) = 0
0.000060 rt_sigaction(SIGPROF, {0x5d4980, [PROF], SA_RESTORER|SA_RESTART, 0x7efdf5602510}, {0x5d4980, [PROF], SA_RESTORER|SA_RESTART, 0x7efdf5602510}, 8) = 0
0.000065 rt_sigprocmask(SIG_UNBLOCK, [PROF], NULL, 8) = 0
0.000546 open("/var/log/php-fpm/www-error.log", O_WRONLY|O_CREAT|O_APPEND, 0644) = 5
0.000275 gettimeofday({1494920152, 481549}, NULL) = 0
0.000216 stat("/usr/share/zoneinfo/UTC", {st_mode=S_IFREG|0644, st_size=118, ...}) = 0
0.001098 open("/usr/share/zoneinfo/UTC", O_RDONLY) = 6
0.000030 fstat(6, {st_mode=S_IFREG|0644, st_size=118, ...}) = 0
0.000024 mmap(NULL, 118, PROT_READ, MAP_SHARED, 6, 0) = 0x7efdf7bcc000
0.007856 close(6) = 0
0.007871 munmap(0x7efdf7bcc000, 118) = 0
0.000199 write(5, "[16-May-2017 07:35:52 UTC] PHP F"..., 127) = 127
0.000090 close(5) = 0
0.000056 open("/var/log/php-fpm/www-error.log", O_WRONLY|O_CREAT|O_APPEND, 0644) = 5
0.000133 gettimeofday({1494920152, 499120}, NULL) = 0
0.000039 write(5, "[16-May-2017 07:35:52 UTC] PHP S"..., 44) = 44
0.000033 close(5) = 0
0.000090 open("/var/log/php-fpm/www-error.log", O_WRONLY|O_CREAT|O_APPEND, 0644) = 5
0.000031 gettimeofday({1494920152, 499310}, NULL) = 0
0.000028 write(5, "[16-May-2017 07:35:52 UTC] PHP "..., 70) = 70
0.000026 close(5) = 0
0.000038 open("/var/log/php-fpm/www-error.log", O_WRONLY|O_CREAT|O_APPEND, 0644) = 5
0.000026 gettimeofday({1494920152, 499428}, NULL) = 0
0.000027 write(5, "[16-May-2017 07:35:52 UTC] PHP "..., 78) = 78
0.000023 close(5) = 0
0.000085 chdir("/") = 0
0.000072 clock_gettime(CLOCK_MONOTONIC, {668032, 663420619}) = 0
0.000029 times({tms_utime=8131, tms_stime=553, tms_cutime=0, tms_cstime=0}) = 496194562
0.000092 setitimer(ITIMER_PROF, {it_interval={0, 0}, it_value={0, 0}}, NULL) = 0
0.000280 umask(022) = 022
0.000237 fcntl(3, F_SETLK, {type=F_UNLCK, whence=SEEK_SET, start=0, len=0}) = 0
0.001047 write(4, "\1\6\0\1\0g\1\0Status: 500 Internal Ser"..., 128) = 128
0.000869 shutdown(4, SHUT_WR) = 0
0.000451 recvfrom(4, "\1\5\0\1\0\0\0\0", 8, 0, NULL, NULL) = 8
0.000043 recvfrom(4, "", 8, 0, NULL, NULL) = 0
0.000020 close(4) = 0
0.000037 clock_gettime(CLOCK_MONOTONIC, {668032, 666524271}) = 0
0.000052 setitimer(ITIMER_PROF, {it_interval={0, 0}, it_value={0, 0}}, NULL) = 0
0.000040 clock_gettime(CLOCK_MONOTONIC, {668032, 666616844}) = 0
0.000023 accept(0, Process 12972 detached

And an other one where works as well:

Process 13888 attached
0.000000 accept(0, {sa_family=AF_INET, sin_port=htons(49118), sin_addr=inet_addr("127.0.0.1")}, [16]) = 4
2.933113 clock_gettime(CLOCK_MONOTONIC, {668265, 781254874}) = 0
0.000116 gettimeofday({1494920385, 617536}, NULL) = 0
0.000157 times({tms_utime=0, tms_stime=0, tms_cutime=0, tms_cstime=0}) = 496217871
0.000140 poll([{fd=4, events=POLLIN}], 1, 5000) = 1 ([{fd=4, revents=POLLIN}])
0.000517 read(4, "\1\1\0\1\0\10\0\0", 8) = 8
0.000301 read(4, "\0\1\0\0\0\0\0\0", 8) = 8
0.000135 read(4, "\1\4\0\1\5b\6\0", 8) = 8
0.000104 read(4, "\f\0QUERY_STRING\16\3REQUEST_METHODGE"..., 1384) = 1384
0.000253 read(4, "\1\4\0\1\0\0\0\0", 8) = 8
0.000233 gettimeofday({1494920385, 619407}, NULL) = 0
0.000081 lstat("/var/www/hutml/asd.php", {st_mode=S_IFREG|0644, st_size=40, ...}) = 0
0.000280 lstat("/var/www/hutml", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
0.000083 lstat("/var/www", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
0.000140 lstat("/var", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
0.000154 clock_gettime(CLOCK_MONOTONIC, {668265, 783895254}) = 0
0.000287 gettimeofday({1494920385, 620465}, NULL) = 0
0.000384 gettimeofday({1494920385, 620818}, NULL) = 0
0.000161 stat("/var/www/hutml/.user.ini", 0x7ffd7f6695a0) = -1 ENOENT (No such file or directory)
0.000245 setitimer(ITIMER_PROF, {it_interval={0, 0}, it_value={60, 0}}, NULL) = 0
0.000147 rt_sigaction(SIGPROF, {0x5d4980, [PROF], SA_RESTORER|SA_RESTART, 0x7fe68069d510}, {SIG_DFL, [], 0}, 8) = 0
0.000218 rt_sigprocmask(SIG_UNBLOCK, [PROF], NULL, 8) = 0
0.001945 brk(0x17b0000) = 0x17b0000
0.001032 gettimeofday({1494920385, 624573}, NULL) = 0
0.000481 gettimeofday({1494920385, 625048}, NULL) = 0
0.000219 gettimeofday({1494920385, 625286}, NULL) = 0
0.000154 open("/var/www/hutml/asd.php", O_RDONLY) = 5
0.000168 fstat(5, {st_mode=S_IFREG|0644, st_size=40, ...}) = 0
0.000264 fstat(5, {st_mode=S_IFREG|0644, st_size=40, ...}) = 0
0.000262 fstat(5, {st_mode=S_IFREG|0644, st_size=40, ...}) = 0
0.000215 mmap(NULL, 40, PROT_READ, MAP_SHARED, 5, 0) = 0x7fe682c67000
0.000130 clock_gettime(CLOCK_MONOTONIC, {668265, 790237375}) = 0
0.000117 getcwd("/", 4095) = 2
0.000160 chdir("/var/www/hutml") = 0
0.000266 setitimer(ITIMER_PROF, {it_interval={0, 0}, it_value={30, 0}}, NULL) = 0
0.000058 fcntl(3, F_SETLK, {type=F_RDLCK, whence=SEEK_SET, start=1, len=1}) = 0
0.000044 stat("/var/www/hutml/asd.php", {st_mode=S_IFREG|0644, st_size=40, ...}) = 0
0.001159 fcntl(3, F_SETLKW, {type=F_WRLCK, whence=SEEK_SET, start=0, len=1}) = 0
0.000133 fcntl(3, F_SETLK, {type=F_UNLCK, whence=SEEK_SET, start=0, len=1}) = 0
0.000049 munmap(0x7fe682c67000, 40) = 0
0.000046 close(5) = 0
0.000054 gettimeofday({1494920385, 628504}, NULL) = 0
0.000092 gettimeofday({1494920385, 628597}, NULL) = 0
0.000061 setitimer(ITIMER_PROF, {it_interval={0, 0}, it_value={0, 0}}, NULL) = 0
0.000033 setitimer(ITIMER_PROF, {it_interval={0, 0}, it_value={300, 0}}, NULL) = 0
0.000080 chdir("/") = 0
0.000061 clock_gettime(CLOCK_MONOTONIC, {668265, 792621333}) = 0
0.000053 times({tms_utime=0, tms_stime=0, tms_cutime=0, tms_cstime=0}) = 496217872
0.000076 setitimer(ITIMER_PROF, {it_interval={0, 0}, it_value={0, 0}}, NULL) = 0
0.000152 fcntl(3, F_SETLK, {type=F_UNLCK, whence=SEEK_SET, start=0, len=0}) = 0
0.000068 setitimer(ITIMER_PROF, {it_interval={0, 0}, it_value={0, 0}}, NULL) = 0
0.000068 setitimer(ITIMER_PROF, {it_interval={0, 0}, it_value={30, 0}}, NULL) = 0
0.000236 write(4, "\1\6\0\1\0F\2\0X-Powered-By: PHP/5.6.30"..., 96) = 96
0.000208 shutdown(4, SHUT_WR) = 0
0.000435 recvfrom(4, "\1\5\0\1\0\0\0\0", 8, 0, NULL, NULL) = 8
0.000059 recvfrom(4, "", 8, 0, NULL, NULL) = 0
0.000064 close(4) = 0
0.000041 clock_gettime(CLOCK_MONOTONIC, {668265, 794075045}) = 0
0.000078 setitimer(ITIMER_PROF, {it_interval={0, 0}, it_value={0, 0}}, NULL) = 0
0.000039 clock_gettime(CLOCK_MONOTONIC, {668265, 794190802}) = 0
0.000030 accept(0, Process 13888 detached

If you have any ide/experience/whatever please feel free to share with me.

Thanks.

  • 写回答
  • 好问题 提建议
  • 关注问题
  • 收藏
  • 邀请回答

2条回答 默认 最新

  • dqhdpppm02183 2017-06-21 10:00
    已采纳

    I extended /etc/nginx/nginx.conf http section with the followings:

    client_header_timeout 3000;
    client_body_timeout 3000;
    fastcgi_read_timeout 3000;
    client_max_body_size 32m;
    fastcgi_buffers 8 128k;
    fastcgi_buffer_size 128k;
    
    已采纳该答案
    评论
    解决 无用
    打赏 举报
  • dtu72460 2017-05-16 09:07

    This happens because of larger memory consumption of your system.

    You have to change your php.ini file with the maximum execution time to 1200 ms

    Don't forget to restart your apache server after modifying your php.ini

    评论
    解决 无用
    打赏 举报

相关推荐 更多相似问题