PHP script continues to execute after 500 Internal Server Error is thrown

[mariondorsett]

I'm trying to debug a situation I have, and I don't know if it's F3 or another issue, right now I'm trying to determine the source of the problem.

My Setup:

- I have a script that simply loads F3 so I can use the \DB\SQL\Mapper class and send data returned from the Infusion API to my database table.

- I have a CSV file that is parsed, and the rows are prepared into an array.

- I process the prepared array and send the data to Infusion, and insert/update records w/ the update rows information.

The problem:

- The script runs for a few seconds and then I get a 500 Internal Server Error.

- My logs contain no errors.  My hosting provider found an error in their logs that report the script timed out.

- I can see new rows being added to the database after the script has been reported as being timed out.

- I confirmed with my host that the script continues to process to completion, and the 500 error is bogus.

Scenario 1:

My first scenario does not use F3 or a database and is stable when executed.

I have a script that processes a CSV, and communicates with Infusions using their API.  Infusion throttles their API, so the script sleep(1)s and then continues.  The script will make over 100K iterations and never time out. 

Scenario 2: 

This is where I run into the issue.  This script is configured a little differently, they're not identical, and this script uses F3 and a database.  The Infusion iSDK is the same library files as in scenario 1.  This script can't run 30 iterations before it reports that it says it's timed out. In fact I can only make it through 28 iterations successfully w/o getting the 500 Error.

I guess that only question I have, is can F3 be at fault in this scenario some how, possibly triggering the 500 error prematurely?

This whole situation seriously has me confused, and it making the data migration I'm working on take longer than it should.

Just curious of any one has any insight?

[xfra35]

If the 2 scripts are configured differently, are you sure that the max execution time is not set too low in the 2nd scenario?

Apart from that, F3 throws a 500 error on all types of PHP errors, except notices (E_NOTICE and E_USER_NOTICE).

But in previous releases (3.3.0 and maybe lower), it used to choke on all errors, including notices.

Which version of the framework are you running?

[marion dorsett]

I'm using F3 Version 3.4.1-Dev.

The execution time is being extended in the loop I have running using set_time_limit(5);  Which I've used on dozens of scripts to keep them running through their full iteration, but also to stop the script if they take too long.  I've never had an instance where I got a 500 error saying the script timed out, and it keeps running in the browser.

Since Infusion's API throttles calls, if I make them sleep(1) and set_time_limit(5) it works well.  I've been using the practice for years to import data into Infusion.

The only thing different in this instance is that I set up F3 to use the mapper, which is why I posted.

I suppose it's possible that the response maybe triggered by Infusion somehow, but I'm just at a complete loss as to why the PHP script doesn't terminate w/ the error.

One concern I have - not that I would do this - but in an instance where I'm processing truly sensitive data like a credit card payment, and want to stop the script... in this case. I can't.

In more relevant terms of my current use case, if I make a small mistake and use a do/while loop, I could crash the server, because I can't stop the script.

Did I mention I'm confused as to how this is even possible?

 

--
You received this message because you are subscribed to a topic in the Google Groups "Fat-Free Framework" group.
To unsubscribe from this topic, visit https://groups.google.com/d/topic/f3-framework/9g09LlxidxA/unsubscribe.
To unsubscribe from this group and all its topics, send an email to f3-framework...@googlegroups.com.
To post to this group, send email to f3-fra...@googlegroups.com.
Visit this group at http://groups.google.com/group/f3-framework.
For more options, visit https://groups.google.com/d/optout.

[ikkez]

Maybe PHP runs out of memory. You said that 28 iterations are fine but it dies when you try 30. Maybe you have a memory leak somewhere in the script.. Try to adjust the php.ini memory_limit setting, or try without the mapper. Is your data that big or so you load many rows in one batch?

[marion dorsett]

That's interesting because, scenario 1 actually processes a larger data set than scenario 2.

PHP isn't running out of memory, because the results are still being passed to both Infusion and the database, it's just that my browser is no longer connected to the PHP process that keeps running on the server.

I'll remove F3 and try using the mysqli connection.

On Thu, May 21, 2015 at 6:44 PM, ikkez via Fat-Free Framework <f3-framework+APn2wQcLLxvM44tXyXU...@googlegroups.com> wrote:

Maybe PHP runs out of memory. You said that 28 iterations are fine but it dies when you try 30. Maybe you have a memory leak somewhere in the script.. Try to adjust the php.ini memory_limit setting, or try without the mapper. Is your data that big or so you load many rows in one batch?

[marion dorsett]

Ah HA!  I figured it out. F3 is the cause, but I'm not sure this is a bug.

I read this:  http://php.net/manual/en/features.connection-handling.php

If you do not tell PHP to ignore a user abort and the user aborts, your script will terminate. The one exception is if you have registered a shutdown function using register_shutdown_function(). With a shutdown function, when the remote user hits his STOP button, the next time your script tries to output something PHP will detect that the connection has been aborted and the shutdown function is called. 

Then Base class does call register_shutdown_function()... and my script doesn't output anything, so it keeps going to completion.

So apparently, my problem was the script timing out, and because F3 registered a shutdown function and my code didn't have any output the script was never aborted.

I used set_time_limit(0) to force the script to run as long as it needs to, and I guess in this case I just misjudged the execution time each iteration in the loop required.

Thank you for your suggestions, you pointed me in the right direction.

[xfra35]

That's an interesting point. But it is related to user script abortion ("users hits his STOP button"), not script timeout.

The framework doesn't look faulty to me : the 500 error is thrown because a fatal error has been detected during shutdown ("max execution time").

I've made the following test:

$f3->UNLOAD=function($f3){

  error_log('count='.$f3->count);

};

$f3->route('GET /',function($f3){

  set_time_limit(1);

  @unlink($f3->LOGS.'test.log');

  $log=new Log('test.log');

  $i=0;

  while ($i<100000000) {$log->write($i++);}

  $log->write('done');

});

As you can see, nothing is echoed. The script aborts after 1 second and the last logged value is 3292.

The reason why your script continued to work in the background is mysterious. It shouldn't be related, but have you checked the value of the ignore_user_abort parameter?

[marion dorsett]

I don't think the framework is at fault either.

Although, I don't think it's a mystery why the script continued to run.  

I think the key lies in the fact that the script terminates the next time it tries to output data.  In this case, I don't think it was referring specifically to outputting data directly to the browser, I think it means any output from the script, like sending data to your log file.

The reason I say that, was I setup my mail() function to notify me when the script finished, and I confirmed the script finished by comparing the CSV to the data in the database, and I had the final row..... but I never got the email, which in this case I would consider the output.

The final solution for me was that in my loop I did set_time_limit(15), and echoed the contactId I got back from Infusion in my loop.

The script now runs w/o issue.

On Fri, May 22, 2015 at 6:01 AM, xfra35 via Fat-Free Framework <f3-framework+APn2wQdllyYRCbrJQTu...@googlegroups.com> wrote:

That's an interesting point. But it is related to user abortion ("users hits his STOP button"), not script timeout.