Fatal error: Maximum execution time of 180 seconds exceeded

Posted by mattyoung on July 19, 2009 at 1:56am

5 followers

Issue Summary

Running just the Simpletest testcase:

An error occurred.
Path: /batch?id=3&op=do
Message:
Fatal error: Maximum execution time of 180 seconds exceeded in C:\drupal\drupal-HEAD\modules\simpletest\drupal_web_test_case.php on line 1269


Call Stack:
0008 75240 1. {main}() C:\drupal\drupal-HEAD\index.php:0
3171 12486688 2. menu_execute_active_handler() C:\drupal\drupal-HEAD\index.php:22
3332 13191864 3. call_user_func_array() C:\drupal\drupal-HEAD\includes\menu.inc:402
3332 13191864 4. system_batch_page() C:\drupal\drupal-HEAD\includes\menu.inc:0
3376 13300656 5. _batch_page() C:\drupal\drupal-HEAD\modules\system\system.admin.inc:1829
3396 13309104 6. _batch_do() C:\drupal\drupal-HEAD\includes\batch.inc:63
3396 13309448 7. _batch_process() C:\drupal\drupal-HEAD\includes\batch.inc:141
3397 13314664 8. call_user_func_array() C:\drupal\drupal-HEAD\includes\batch.inc:245
3397 13314664 9. _simpletest_batch_operation() C:\drupal\drupal-HEAD\includes\batch.inc:0
3533 14107144 10. DrupalTestCase->run() C:\drupal\drupal-HEAD\modules\simpletest\simpletest.module:170
9673 35767752 11. SimpleTestFunctionalTest->testWebTestRunner() C:\drupal\drupal-HEAD\modules\simpletest\drupal_web_test_case.php:398
5074 36021608 12. DrupalWebTestCase->drupalPost() C:\drupal\drupal-HEAD\modules\simpletest\simpletest.test:91
0652 35811144 13. DrupalWebTestCase->checkForMetaRefresh() C:\drupal\drupal-HEAD\modules\simpletest\drupal_web_test_case.php:1442
1154 35813192 14. DrupalWebTestCase->drupalGet() C:\drupal\drupal-HEAD\modules\simpletest\drupal_web_test_case.php:1476
1156 35813824 15. DrupalWebTestCase->curlExec() C:\drupal\drupal-HEAD\modules\simpletest\drupal_web_test_case.php:1348
1157 35815176 16. curl_exec() C:\drupal\drupal-HEAD\modules\simpletest\drupal_web_test_case.php:1247
6762 35807072 17. DrupalWebTestCase->curlHeaderCallback() C:\drupal\drupal-HEAD\modules\simpletest\drupal_web_test_case.php:0

in my php.ini,

max_execution_time = 3600

So I don't understand where this 180 seconds come from.

Comments

#1

Posted by boombatower on July 20, 2009 at 1:28am

Status:

active

» postponed (maintainer needs more info)

Since we have had issues with tests timeing out they set the timeout themseleves

The default is:

<?php
  /**
   * Time limit for the test.
   */
  protected $timeLimit = 180;
?>

and in DrupalWebTestCase::setUp()

<?php
set_time_limit($this->timeLimit);
?>

Seems like your machine is taking longer than usual, could be CPU speed or something related to configuration.

#2

Posted by mattyoung on July 20, 2009 at 4:19am

On my laptop, I need at least 300 for the Simpletest testcase to get through. So 180 is not enough for me.

The test takes 10 minutes to run.

How about setting this to a much higher value? This is for development only so it shouldn't matter.

#3

Posted by boombatower on July 20, 2009 at 4:57am

Seems reasonable, perhaps even a setting on setting page. Since it takes no where near that long to run on my machine I would rather it detect it quicker.

#4

Posted by mattyoung on July 20, 2009 at 5:56am

>Seems reasonable, perhaps even a setting on setting page

I think a setting value would be ideal. If possible, you can even set an error/exception handler to catch time out and direct the user to increase the value?

additionally, in simpletest_requirement() add:

<?php
if (ini_get('safe_mode') || strpos(ini_get('disable_functions'), 'set_time_limit') !== FALSE) {
     $requirements['php_set_time_limit']['serverity'] = REQUIREMENT_ERROR;
     $requirements['php_set_time_limit']['description'] = t('Simpletest cannot run in safe_mode or with function set_time_limit() disable. Correct this in php.ini');
}
?>

#5

Posted by boombatower on July 20, 2009 at 8:09pm

Status:

postponed (maintainer needs more info)

» active

Right, this just needs a patch.

#6

Posted by mattyoung on July 20, 2009 at 10:23pm

Status:

active

» needs review

Here is a patch

1. add settings value for set_time_limit()
2. add requirements check for safe_mode or set_time_limit() disable
3. fix a little error in simpletest_requirements(), it was calling t() instead, it should be $t().

Attachment	Size	Status	Test result	Operations
simpletest-523878.patch	2.58 KB	Idle	Failed: Failed to install HEAD.	View details

#7

Posted by boombatower on July 20, 2009 at 11:59pm

Category:

bug report

» feature request

Re-rolled per: http://drupal.org/patch and cleaned up documentation.

Attachment	Size	Status	Test result	Operations
523878-time-limit.patch	3.99 KB	Idle	Failed: Failed to install HEAD.	View details

#8

Posted by mattyoung on July 21, 2009 at 5:18am

add form validation for simpletest_time_limit in case some one enter something crazy

Attachment	Size	Status	Test result	Operations
523878-time-limit.patch	4.75 KB	Idle	Failed: Failed to install HEAD.	View details

#9

Posted by System Message on August 1, 2009 at 9:12am

Status:

needs review

» needs work

The last submitted patch failed testing.

#10

Posted by mattyoung on August 1, 2009 at 7:02pm

Status:

needs work

» needs review

Re-roll patch

Attachment	Size	Status	Test result	Operations
523878-time-limit.patch	20.6 KB	Idle	Failed: Failed to apply patch.	View details

#11

Posted by boombatower on August 3, 2009 at 5:04am

Patch looks a bit wacky since there is double line spacing. I haven't look at it in detail.

#12

Posted by mattyoung on August 3, 2009 at 6:37am

I just update to latest HEAD and re-roll the patch. Could it be problem with LF/CR mix up? I see every line is replace with exactly the same but with ^M at the end.

#13

Posted by mattyoung on August 3, 2009 at 11:01pm

Re-roll pactch. I made sure the files use unix eol style. I check the patch and it look okay to me.

Attachment	Size	Status	Test result	Operations
523878-time-limit.patch	4.8 KB	Idle	Passed: 13798 passes, 0 fails, 0 exceptions	View details

#14

Posted by boombatower on August 3, 2009 at 11:16pm

Status:

needs review

» needs work

+
+
+function simpletest_settings_form_validate($form, $form_state) {
+  $value = $form_state['values']['simpletest_time_limit'];
+  if ($value !== (string)(int)$value || $value < 0) {
+    form_error($form['general']['simpletest_time_limit'], t('Must be an integer >= 0.'));
+  }
+}
\ No newline at end of file

Should be end of line...needs documentation...and remove extra blank line from above.

Otherwise looks fine.

#15

Posted by mattyoung on August 3, 2009 at 11:48pm

Re-roll patch per instruction in previous message

Attachment	Size	Status	Test result	Operations
523878-time-limit.patch	4.9 KB	Idle	Passed: 13766 passes, 0 fails, 0 exceptions	View details

#16

Posted by mattyoung on August 3, 2009 at 11:56pm

Status:

needs work

» needs review

forgot to change status.

#17

Posted by boombatower on August 4, 2009 at 2:27am

Status:

needs review

» reviewed & tested by the community

Simpletest calls set_time_limit() with this value to increase the PHP script exe

Simpletest calls set_time_limit() with this value to set the PHP script exe

I tested this with a value of 1 and it timedout....so looks good.

Attachment	Size	Status	Test result	Operations
523878-time-limit.patch	4.82 KB	Idle	Failed: Failed to apply patch.	View details

#18

Posted by webchick on August 8, 2009 at 10:24pm

Status:

reviewed & tested by the community

» needs work

+++ modules/simpletest/simpletest.pages.inc	4 Aug 2009 02:26:50 -0000
@@ -449,3 +456,15 @@
+ * Validate settings form value 'simpletest_time_limit' is an integer >= 0
+ * to prevent user from entering invalid value.

Shorten so fits into one line, or add one-line summary.

+++ modules/simpletest/simpletest.pages.inc	4 Aug 2009 02:26:50 -0000
@@ -449,3 +456,15 @@
+  if ($value !== (string)(int)$value || $value < 0) {

What is that weird $value !== (string)(int)$value stuff? Isn't it enough to cast $value to an integer and ensure it's not < 0?

If not, let's comment this because it's very weird.

+++ modules/simpletest/simpletest.install	4 Aug 2009 02:26:50 -0000
@@ -132,6 +133,7 @@
+  $can_set_time_limit = !ini_get('safe_mode') && strpos(ini_get('disable_functions'), 'set_time_limit') === FALSE;

Is checking for function_exists('set_time_limit') not sufficient here?

+++ modules/simpletest/simpletest.install	4 Aug 2009 02:26:50 -0000
@@ -156,7 +158,16 @@
+    $requirements['php_set_time_limit']['description'] = $t('Simpletest cannot run in safe_mode or with function set_time_limit() disable. Correct this in php.ini');

disabled. php.ini should be followed by a period since it ends the sentence.

Beer-o-mania starts in 23 days! Don't drink and patch.

#19

Posted by mattyoung on August 9, 2009 at 6:37pm

Assigned to:	Anonymous	» mattyoung
Status:	needs work	» needs review

+++ modules/simpletest/simpletest.pages.inc 4 Aug 2009 02:26:50 -0000
@@ -449,3 +456,15 @@
+ * Validate settings form value 'simpletest_time_limit' is an integer >= 0
+ * to prevent user from entering invalid value.

>
>Shorten so fits into one line, or add one-line summary.

Okay.

+++ modules/simpletest/simpletest.pages.inc 4 Aug 2009 02:26:50 -0000
@@ -449,3 +456,15 @@
+  if ($value !== (string)(int)$value || $value < 0) {

>
>What is that weird $value !== (string)(int)$value stuff? Isn't it enough to cast $value to an integer and ensure it's not < 0?

You can enter "3.1415926" and casting to int is "3" which would pass the test but then we end up storing a float value. This is the best way to ensure the user is entering an *integer* number.

>If not, let's comment this because it's very weird.

Comment added.

+++ modules/simpletest/simpletest.install 4 Aug 2009 02:26:50 -0000
@@ -132,6 +133,7 @@
+  $can_set_time_limit = !ini_get('safe_mode') && strpos(ini_get('disable_functions'), 'set_time_limit') === FALSE;

>
>Is checking for function_exists('set_time_limit') not sufficient here?

The function could exist but we could be running in safe_mode, then calling that function has no effect. We need to warn people about that.

+++ modules/simpletest/simpletest.install 4 Aug 2009 02:26:50 -0000
@@ -156,7 +158,16 @@
+    $requirements['php_set_time_limit']['description'] = $t('Simpletest cannot run in safe_mode or with function set_time_limit() disable. Correct this in php.ini');

>
>disabled. php.ini should be followed by a period since it ends the sentence.

I made the change. I hope I understand you correctly.

Attachment	Size	Status	Test result	Operations
523878-time-limit.patch	5.26 KB	Idle	Failed: Failed to apply patch.	View details

#20

Posted by boombatower on August 13, 2009 at 3:27pm

Status:

needs review

» needs work

+++ modules/simpletest/simpletest.install	9 Aug 2009 07:26:03 -0000
@@ -156,7 +158,16 @@ function simpletest_requirements($phase)
+    'title' => $t('Can call %f', array('%f' => 'set_time_limit()')),

Single letter placeholders are not generally used, lets change to %function.

+++ modules/simpletest/simpletest.pages.inc	9 Aug 2009 07:26:03 -0000
@@ -453,3 +460,15 @@ function simpletest_settings_form(&$form
+  // ensure input value is an integer and not a float or non-integer

Comments begin with cap and end with period.

+++ modules/simpletest/simpletest.pages.inc	9 Aug 2009 07:26:03 -0000
@@ -453,3 +460,15 @@ function simpletest_settings_form(&$form
+  if ($value !== (string)(int)$value || $value < 0) {

I think "$value !== (string)(int)$value" could be changed to "$value != (int) $value". That would be a bit more standard as I don't think we need a strict compare here and it requires a double cast which, as webchick noted, is odd.

+++ modules/simpletest/simpletest.pages.inc	9 Aug 2009 07:26:03 -0000
@@ -453,3 +460,15 @@ function simpletest_settings_form(&$form
+    form_error($form['general']['simpletest_time_limit'], t('Must be an integer >= 0.'));

Form error messages should include the field name and should use plain english, '>=' should be 'greater then or equal to'.

Beer-o-mania starts in 18 days! Don't drink and patch.

#21

Posted by boombatower on August 13, 2009 at 3:34pm

Status:

needs work

» needs review

I went ahead and made the changes and cleaned up the validate function.

The function never actually checked if the string was numeric, so 'a' was accepted.

<?php
(int) 'a'
?>

Converts the character to its ord code. I added an is_numeric() check.

Attachment	Size	Status	Test result	Operations
523878-time-limit.patch	4.86 KB	Idle	Failed: Failed to apply patch.	View details

#22

Posted by System Message on August 15, 2009 at 4:20pm

Status:

needs review

» needs work

The last submitted patch failed testing.

#23

Posted by boombatower on August 15, 2009 at 11:03pm

Status:

needs work

» needs review

Confirmed it still works after re-roll. Since fatal errors pick it up...you get the following as the last assertion.

Maximum execution time of 1 second exceeded

Attachment	Size	Status	Test result	Operations
523878-time-limit.patch	4.71 KB	Idle	Passed: 13767 passes, 0 fails, 0 exceptions	View details

#24

Posted by mattyoung on August 15, 2009 at 11:23pm

Status:

needs review

» reviewed & tested by the community

Looks good.

#25

Posted by Dries on August 16, 2009 at 12:08pm

Status:

reviewed & tested by the community

» needs review

I don't understand why we want to make this is a settings versus just bumping the value. That sounds like a really marginal use case to me, and would justify many more things to be settings.

In the description, shouldn't 'error' be 'errors'?

#26

Posted by webchick on August 16, 2009 at 5:27pm

Agreed. Shouldn't we just throw the set_time_limit() call before each testXX function? The docs http://ca.php.net/set_time_limit indicate that it re-starts the timer each time it is called. If the underlying bug is that the scripts are running out of time, that just means we have to call it more often to reset the timer sooner, no?

#27

Posted by mattyoung on August 16, 2009 at 6:03pm

It's a good idea to call set_time_limit() to restart the timer on each test.

For this patch, having a user option of setting to something is good. I get time out on the default. So with this, I just set it to zero to have no time limit. You never know what kind a slow machine people might be running on.