0

I have a script that produces a report. For most widgets* it produces a report with no problem. For a particular widget it exits in the middle during a mysql query and a 500 is returned to the browser. By inserting writes to the php_error log I know the exact last line to be executed and it's always the same line. It's not a timeout because other widget reports run longer (and it bombs out in about 10 seconds).

Also, I've tried running the query it's trying to run in phpadmin and it runs OK.

When this abort occurs I see nothing appear in php_error.log, nothing in apache's error log and when I surround the offending statement with a try/catch, no exception is caught.

Is there somewhere else I can look that might show what error is occurring?

* by widget I'm not referring to a UI component. I'm using widget in the sense of fictional product from a fictional company

addendum ====================================================================== Since it was requested I posted the code although I think the problem isn't the code since it works in all but this once case. The problem is more likely in the data for this particular case.

error_log('['.__FILE__.']['.__LINE__."] check");

$table = new metrics_sessions();

//here I print out the SQL statement that will eventually be executed
error_log('['.__FILE__.']['.__LINE__."] check: "."guider_slug=? ".($effective_mindate!=null?" and date>'".$effective_mindate."'":"").($effective_maxdate!=null?" and date<'".$effective_maxdate." 23:59:59'":"").($effective_version!=0 && $effective_version!="all"?" and version=".$specific_version:"").($effective_campaign!==null && $effective_campaign!="all" ?" and campaign='".$effective_campaign."'":"")." order by date");

// BELOW IS THE LAST LINE I SEE IN PHP ERROR
error_log('['.__FILE__.']['.__LINE__."] check"); 

try {

    $sessions = $table->Find("guider_slug=? ".($effective_mindate!=null?" and date>'".$effective_mindate."'":"").($effective_maxdate!=null?" and date<'".$effective_maxdate." 23:59:59'":"").($effective_version!=0 && $effective_version!="all"?" and version=".$specific_version:"").($effective_campaign!==null && $effective_campaign!="all" ?" and campaign='".$effective_campaign."'":"")." order by date",array($param_gslug));

    error_log('['.__FILE__.']['.__LINE__."] check");

}catch(Exception $e){

    error_log('['.__FILE__.']['.__LINE__."] check");
    error_log('Caught exception: '.$e->getMessage());
    error_log('File: '.$e->getFile());
    error_log('Line: '.$e->getLine());
    error_log('Trace: '.$e->getTraceAsString());

}

error_log('['.__FILE__.']['.__LINE__."] session count: ".count($sessions));
dl__
  • 4,500
  • 5
  • 28
  • 34
  • If you omit that particular widget, does the script complete? Or does it always stop after a certain number? – hughes Aug 18 '11 at 17:31
  • Do you see an error supression symbol (@) anywhere near that line? Or within the function that is called on that line? If so, remove it. – Gerry Aug 18 '11 at 17:32
  • 1
    @Chris I added the offending section of code although – dl__ Aug 18 '11 at 17:39
  • Sure the problem might be in the data, but the real problem here is that your not getting an error message which would allow you to debug. – Gerry Aug 18 '11 at 17:44
  • So $table->Find is failing? Have you looked inside that code to see if there is any error suppression? – Gerry Aug 18 '11 at 17:46
  • @hughes The widgets are not processed sequentially. From a browser a user selects the widget to see a report on. All the other widgets seem to work fine - and even this widget worked fine until recently. That's why I suspect some problem in the data for this widget. But no one's talking about what error they've run into. – dl__ Aug 18 '11 at 17:47
  • 500 errors get logged in the server's error log, with more details as to WHY the error occurred. – Marc B Aug 18 '11 at 17:47
  • @Gerry, that may be a good point. Although I said I was calling mysql because it's a mysql database ultimately. I am using a adodb wrapper which could be surpressing the error (although it would be a stupid thing for them to do). I'll look. – dl__ Aug 18 '11 at 17:49
  • @Marc B maybe I'm looking at the wrong file ( /var/log/apache2/error.log) when I tail that file I see recent errors but I don't see a line added when the report fails. I do see a new line popup in the access log showing that a 500 error was returned. – dl__ Aug 18 '11 at 17:57
  • maybe something in that ->Find() method call is doing a manual `header('HTTP/1.1 500 error')` type thing. – Marc B Aug 18 '11 at 17:59
  • @Gerry, OK, now that I looked through the adodb library code I see than many calls to mysql are prefixed with @. I did a little reading on the @ symbol at php.net and I see the claim that if you set up a custom error handler it will still be called regardless of the @ symbol. I'm going to try that to see what that tells me. – dl__ Aug 18 '11 at 18:16
  • "although it would be a stupid thing for them to do"..."OK, now that I looked through the adodb library code I see than many calls to mysql are prefixed with @" Yup :) – Gerry Aug 18 '11 at 18:30
  • "I see the claim that if you set up a custom error handler it will still be called regardless of the @ symbol." Unfortunately most Fatal errors can not be handled by the error handler as the php engine could be in an unstable state at that time. You'll have to be lucky to get a useful error. – Gerry Aug 18 '11 at 18:40
  • @Gerry, I did not get anything from my custom error handler as you expected. I may have to edit the library code to remove the @ symbols at least temporarily. – dl__ Aug 18 '11 at 18:48
  • Either that or switch to something else. Your case is a common example of why I really do hate that operator. http://stackoverflow.com/questions/136899/suppress-error-with-operator-in-php/960288#960288 – Gerry Aug 18 '11 at 18:52

2 Answers2

1

Check for error supression operators (@) in your code and the code you are calling.

Gerry
  • 10,584
  • 4
  • 41
  • 49
  • Added this for posterity and so I can get the cred =P – Gerry Aug 18 '11 at 18:56
  • Well, I did find that it isn't the query that's bombing. The actual mysql_query that ultimately gets called didn't have the @ and when I surround the call with statements to write to the error log, I see both statements. So it's bombing somewhere between getting the results and actually returning from the ->Find() – dl__ Aug 18 '11 at 19:09
  • Keep putting log writes at half way points (binary search) and you'll find the troublesome call soon enough. – Gerry Aug 18 '11 at 19:22
  • 1
    The adodb wrapper code was crashing due to (I assume) a memory problem when a query returned more than 500,000 rows. Copying the array returned from mysql_query to it's own structure killed the script. It never did return an error message. Thanks for your help. – dl__ Aug 18 '11 at 20:31
0

Try editing your error php.ini file to allow warnings and error codes to be displayed.

error_reporting = E_ALL | E_STRICT

This would be sufficient.

j0k
  • 22,600
  • 28
  • 79
  • 90
Brett Tompkins
  • 1