PHP script executes twice when longer than 60 seconds

Question

Alright, so I've been wracking my brain about this for the past 3 hours now and been googling like crazy with no resolution to the problem. So, I wrote an example script that reproduces this since my original script is around 800 lines.

<?php
    set_time_limit(0);
    ini_set('max_input_time', '-1');
    ini_set('max_execution_time', '0');

    error_log("executing script... ");
    $time = time();
    for ($t = 0; $t <= 15; $t++) {
        error_log("Logging: $t (".(time()-$time)." seconds)");
        sleep(5);
    }
    error_log("execution done (".(time()-$time)." seconds)");
?>

Now, the sleep function is just being used to re-create the time of execution of the page and is not used in the original code. This will produce the following result in the error_log file

[Tue Nov 06 16:24:14 2012] executing script...
[Tue Nov 06 16:24:14 2012] Logging: 0 (0 seconds)
[Tue Nov 06 16:24:19 2012] Logging: 1 (5 seconds)
[Tue Nov 06 16:24:24 2012] Logging: 2 (10 seconds)
[Tue Nov 06 16:24:29 2012] Logging: 3 (15 seconds)
[Tue Nov 06 16:24:34 2012] Logging: 4 (20 seconds)
[Tue Nov 06 16:24:39 2012] Logging: 5 (25 seconds)
[Tue Nov 06 16:24:44 2012] Logging: 6 (30 seconds)
[Tue Nov 06 16:24:49 2012] Logging: 7 (35 seconds)
[Tue Nov 06 16:24:54 2012] Logging: 8 (40 seconds)
[Tue Nov 06 16:24:59 2012] Logging: 9 (45 seconds)
[Tue Nov 06 16:25:04 2012] Logging: 10 (50 seconds)
[Tue Nov 06 16:25:09 2012] Logging: 11 (55 seconds)
[Tue Nov 06 16:25:14 2012] executing script...
[Tue Nov 06 16:25:14 2012] Logging: 0 (0 seconds)
[Tue Nov 06 16:25:14 2012] Logging: 12 (60 seconds)
[Tue Nov 06 16:25:19 2012] Logging: 1 (5 seconds)
[Tue Nov 06 16:25:19 2012] Logging: 13 (65 seconds)
[Tue Nov 06 16:25:24 2012] Logging: 2 (10 seconds)
[Tue Nov 06 16:25:24 2012] Logging: 14 (70 seconds)
[Tue Nov 06 16:25:29 2012] Logging: 3 (15 seconds)
[Tue Nov 06 16:25:29 2012] Logging: 15 (75 seconds)
[Tue Nov 06 16:25:34 2012] Logging: 4 (20 seconds)
[Tue Nov 06 16:25:34 2012] execution done (80 seconds)
[Tue Nov 06 16:25:39 2012] Logging: 5 (25 seconds)
[Tue Nov 06 16:25:44 2012] Logging: 6 (30 seconds)
[Tue Nov 06 16:25:49 2012] Logging: 7 (35 seconds)
[Tue Nov 06 16:25:54 2012] Logging: 8 (40 seconds)
[Tue Nov 06 16:25:59 2012] Logging: 9 (45 seconds)
[Tue Nov 06 16:26:04 2012] Logging: 10 (50 seconds)
[Tue Nov 06 16:26:09 2012] Logging: 11 (55 seconds)
[Tue Nov 06 16:26:14 2012] Logging: 12 (60 seconds)
[Tue Nov 06 16:26:19 2012] Logging: 13 (65 seconds)
[Tue Nov 06 16:26:24 2012] Logging: 14 (70 seconds)
[Tue Nov 06 16:26:29 2012] Logging: 15 (75 seconds)
[Tue Nov 06 16:26:34 2012] execution done (80 seconds)

heres some settings from phpinfo that are relevant

=== apache2handler ===
Max Requests: Per Child: 1000 - Keep Alive: on - Max Per Connection: 200
Timeouts: Connection: 300 - Keep-Alive: 2 

=== PHP Version 5.4.5 Core Settings ===
max_execution_time     Local: 0     Master: 30
max_input_time         Local: -1    Master: -1

I have tried everything i can think of. it appears to be a server setting either with Apache or PHP, because when i run this same script on my localhost, it executes successfully like it should without the double load. and before its asked, yes every time I make an INI change or apache config change I have been restarting apache.

also, here is the access_log entries for the example above.

*.*.*.* - - [06/Nov/2012:16:43:56 -0700] "GET /test.php HTTP/1.1" 200 20 "-" "Mozilla/5.0 (Windows NT 6.1; WOW64; rv:16.0) Gecko/20100101 Firefox/16.0" *.*.*.* *********.com 80 55050278 1012 321 *.*.*.*
*.*.*.* - - [06/Nov/2012:16:44:56 -0700] "GET /test.php HTTP/1.1" 200 20 "-" "Mozilla/5.0 (Windows NT 6.1; WOW64; rv:16.0) Gecko/20100101 Firefox/16.0" *.*.*.* *********.com 80 60054985 1012 321 *.*.*.*

There is definitely something doing this once 60 seconds has been reached in execution time because when i change the execution time to say, 55 seconds, it runs once just as it should.

[Tue Nov 06 16:46:00 2012] executing script...
[Tue Nov 06 16:46:00 2012] Logging: 0 (0 seconds)
[Tue Nov 06 16:46:05 2012] Logging: 1 (5 seconds)
[Tue Nov 06 16:46:10 2012] Logging: 2 (10 seconds)
[Tue Nov 06 16:46:15 2012] Logging: 3 (15 seconds)
[Tue Nov 06 16:46:20 2012] Logging: 4 (20 seconds)
[Tue Nov 06 16:46:25 2012] Logging: 5 (25 seconds)
[Tue Nov 06 16:46:30 2012] Logging: 6 (30 seconds)
[Tue Nov 06 16:46:35 2012] Logging: 7 (35 seconds)
[Tue Nov 06 16:46:40 2012] Logging: 8 (40 seconds)
[Tue Nov 06 16:46:45 2012] Logging: 9 (45 seconds)
[Tue Nov 06 16:46:50 2012] Logging: 10 (50 seconds)
[Tue Nov 06 16:46:55 2012] execution done (55 seconds)

Any help with this will be much appreciated!

I don't think its the same as there is an extension involved on it but http://serverfault.com/questions/409100/php-script-times-out-after-60-seconds-on-apache is very similar and might be worth a look. — Caltor, Nov 08 '12 at 08:14
I'm also seeing this happen - I'm still holding out hope for a solution. — John, Mar 24 '17 at 15:19

score 5 · Answer 1 · edited May 23 '17 at 12:25

5

Could something such as a missing favicon be causing your script to get called twice. See http://www.webdeveloper.com/forum/showthread.php?245809-Script-Running-Twice. It can also.happen if you have the non www redirected to www or vice versa. See PHP executes twice on page load when redirecting from non-www to www

edited May 23 '17 at 12:25

Community

1
1

answered Nov 07 '12 at 00:23

Caltor

2,538
1
27
55

no there is a favicon, otherwise I would have seen it in the access log as failing. – Sheac Nov 07 '12 at 00:28
Put phpinfo() after your 3 settings at the top to see if they are taking effect. – Caltor Nov 08 '12 at 08:05
you should add a favico. I didnt have one, and my page was loaded twice. As soon as I added one, it works OK! – John Smith Oct 06 '15 at 07:52
@sheac are you redirecting to/from www as per the other linked article? – Caltor Oct 06 '15 at 13:04

score 3 · Answer 2 · answered Nov 07 '12 at 00:10

3

Just to rule it out, have you tried testing this in another browser? I only mention it because i stumbled on this recently:

https://support.mozilla.org/en-US/questions/922783

answered Nov 07 '12 at 00:10

Steve

20,703
5
41
67

interesting... It doesn't repeat the call after 60 seconds in chrome, however chrome doesn't receive the page response after 60 seconds of execution. This still doesn't explain why the same script does work on my localhost apache server when executing longer than 60 seconds unless it has to do with browsers making external requests and not internal. hmmm – Sheac Nov 07 '12 at 00:43

score 0 · Answer 3 · answered Aug 17 '17 at 17:16

0

As a workaround, perhaps you can split your execution into two pages; when you're done with the first one, just load the second one. This can also work around certain resource limitations such as low RAM budget in your PHP config.

answered Aug 17 '17 at 17:16

Chad

364
2
7

PHP script executes twice when longer than 60 seconds

3 Answers3

Linked