diff --git a/src/php_v8_isolate_limits.cc b/src/php_v8_isolate_limits.cc index e34a2cd..7504d9a 100644 --- a/src/php_v8_isolate_limits.cc +++ b/src/php_v8_isolate_limits.cc @@ -32,6 +32,27 @@ #define php_v8_debug_execution(format, ...) #endif +static inline void php_v8_isolate_limits_update_time_point(php_v8_isolate_limits_t *limits) { + php_v8_debug_execution("Updating time limits\n"); + + std::chrono::milliseconds duration(static_cast(limits->time_limit * 1000)); + std::chrono::time_point from = std::chrono::high_resolution_clock::now(); + + php_v8_debug_execution(" now: %.3f\n", std::chrono::time_point_cast(from).time_since_epoch().count()/1000.0); + php_v8_debug_execution(" old time point: %.3f\n", std::chrono::time_point_cast(limits->time_point).time_since_epoch().count()/1000.0); + + limits->time_point = from + duration; + php_v8_debug_execution(" new time point: %.3f\n", std::chrono::time_point_cast(limits->time_point).time_since_epoch().count()/1000.0); +} + +static inline void php_v8_isolate_limits_maybe_terminate_thread(php_v8_isolate_limits_t *limits) { + if (!limits->active && limits->thread) { + limits->thread->join(); + delete limits->thread; + limits->thread = NULL; + } +} + static void php_v8_isolate_limits_interrupt_handler(v8::Isolate *isolate, void *data) { php_v8_isolate_t *php_v8_isolate = static_cast(data); php_v8_isolate_limits_t *limits = &php_v8_isolate->limits; @@ -81,12 +102,17 @@ void php_v8_isolate_limits_thread(php_v8_isolate_t *php_v8_isolate) { limits->mutex->lock(); if (limits->active && limits->time_limit > 0) { + now = std::chrono::high_resolution_clock::now(); if (now > limits->time_point) { + php_v8_debug_execution("Time limit reached, terminating\n"); + php_v8_debug_execution(" now: %.3f\n", std::chrono::time_point_cast(now).time_since_epoch().count()/1000.0); + php_v8_debug_execution(" time point: %.3f\n", std::chrono::time_point_cast(limits->time_point).time_since_epoch().count()/1000.0); + + limits->time_limit_hit = true; limits->active = false; php_v8_isolate->isolate->TerminateExecution(); - limits->time_limit_hit = true; } } @@ -103,6 +129,8 @@ void php_v8_isolate_limits_thread(php_v8_isolate_t *php_v8_isolate) { limits->mutex->unlock(); if (!limits->active) { + php_v8_debug_execution("Exit timer loop: %s, %s\n", has(limits->mutex, "mutex"), has(limits->thread, "thread")); + php_v8_debug_execution(" active: %s, depth: %d, time limit hit: %d, memory limit hit: %d\n", is(limits->active), limits->depth, limits->time_limit_hit, limits->memory_limit_hit); return; } @@ -113,6 +141,8 @@ void php_v8_isolate_limits_thread(php_v8_isolate_t *php_v8_isolate) { void php_v8_isolate_limits_maybe_start_timer(php_v8_isolate_t *php_v8_isolate) { php_v8_isolate_limits_t *limits = &php_v8_isolate->limits; + php_v8_debug_execution("Maybe start timer: %d, %s, %s\n", limits->depth, has(limits->mutex, "mutex"), has(limits->thread, "thread")); + assert (limits->depth < UINT32_MAX); if (!limits->mutex) { @@ -124,10 +154,14 @@ void php_v8_isolate_limits_maybe_start_timer(php_v8_isolate_t *php_v8_isolate) { limits->depth++; if (limits->active && !limits->thread) { + php_v8_isolate_limits_update_time_point(limits); + + php_v8_debug_execution(" start timer\n"); limits->thread = new std::thread(php_v8_isolate_limits_thread, php_v8_isolate); } } + void php_v8_isolate_limits_maybe_stop_timer(php_v8_isolate_t *php_v8_isolate) { php_v8_isolate_limits_t *limits = &php_v8_isolate->limits; @@ -172,6 +206,8 @@ void php_v8_isolate_limits_free(php_v8_isolate_t *php_v8_isolate) { if (limits->mutex) { delete limits->mutex; } + + limits->time_point.~time_point(); } void php_v8_isolate_limits_ctor(php_v8_isolate_t *php_v8_isolate) { @@ -180,13 +216,15 @@ void php_v8_isolate_limits_ctor(php_v8_isolate_t *php_v8_isolate) { limits->thread = NULL; limits->mutex = NULL; limits->depth = 0; + + new(&limits->time_point) std::chrono::time_point(); } void php_v8_isolate_limits_set_time_limit(php_v8_isolate_t *php_v8_isolate, double time_limit_in_seconds) { PHP_V8_DECLARE_ISOLATE(php_v8_isolate); PHP_V8_DECLARE_LIMITS(php_v8_isolate); - assert(time_limit_in_seconds >=0); + assert(time_limit_in_seconds >= 0); v8::Locker locker(isolate); @@ -196,28 +234,30 @@ void php_v8_isolate_limits_set_time_limit(php_v8_isolate_t *php_v8_isolate, doub limits->mutex->lock(); - std::chrono::milliseconds duration(static_cast(time_limit_in_seconds * 1000)); - std::chrono::time_point from = std::chrono::high_resolution_clock::now(); - + php_v8_debug_execution("Setting time limits, new limit: %f, old limit: %f, time_limit_hit: %s\n", time_limit_in_seconds, limits->time_limit, is(limits->time_limit_hit)); limits->time_limit = time_limit_in_seconds; - limits->time_point = from + duration; - limits->time_limit_hit = false; + php_v8_isolate_limits_update_time_point(limits); + + if (limits->time_limit_hit) { + php_v8_debug_execution(" trying to recover from time limit hit, active: %s\n", is(limits->active)); + + isolate->CancelTerminateExecution(); + + php_v8_isolate_limits_maybe_terminate_thread(limits); + limits->time_limit_hit = false; + } limits->active = (limits->time_limit > 0 || limits->memory_limit > 0) && !limits->time_limit_hit && !limits->memory_limit_hit; if (limits->active && limits->depth && !limits->thread) { + php_v8_debug_execution("Restart timer: %d, %s, %s\n", limits->depth, has(limits->memory_limit_hit, "memory limit hit"), has(limits->time_limit_hit, "time limit hit")); limits->thread = new std::thread(php_v8_isolate_limits_thread, php_v8_isolate); } limits->mutex->unlock(); - - if (!limits->active && limits->thread) { - limits->thread->join(); - delete limits->thread; - limits->thread = NULL; - } + php_v8_isolate_limits_maybe_terminate_thread(limits); } void php_v8_isolate_limits_set_memory_limit(php_v8_isolate_t *php_v8_isolate, size_t memory_limit_in_bytes) { @@ -232,22 +272,27 @@ void php_v8_isolate_limits_set_memory_limit(php_v8_isolate_t *php_v8_isolate, si limits->mutex->lock(); + php_v8_debug_execution("Updating memory limits, memory_limit_hit: %s\n", is(limits->memory_limit_hit)); limits->memory_limit = memory_limit_in_bytes; - limits->memory_limit_hit = false; + + if (limits->memory_limit_hit) { + php_v8_debug_execution(" trying to recover from memory limit hit, active: %s\n", is(limits->active)); + + isolate->CancelTerminateExecution(); + + php_v8_isolate_limits_maybe_terminate_thread(limits); + limits->memory_limit_hit = false; + } limits->active = (limits->time_limit > 0 || limits->memory_limit > 0) && !limits->time_limit_hit && !limits->memory_limit_hit; if (limits->active && limits->depth && !limits->thread) { + php_v8_debug_execution("Restart timer: %d, %s, %s\n", limits->depth, has(limits->memory_limit_hit, "memory limit hit"), has(limits->time_limit_hit, "time limit hit")); limits->thread = new std::thread(php_v8_isolate_limits_thread, php_v8_isolate); } limits->mutex->unlock(); - - if (!limits->active && limits->thread) { - limits->thread->join(); - delete limits->thread; - limits->thread = NULL; - } + php_v8_isolate_limits_maybe_terminate_thread(limits); } diff --git a/src/php_v8_isolate_limits.h b/src/php_v8_isolate_limits.h index 8b27c1f..a3c857b 100644 --- a/src/php_v8_isolate_limits.h +++ b/src/php_v8_isolate_limits.h @@ -31,6 +31,7 @@ extern void php_v8_isolate_limits_ctor(php_v8_isolate_t *php_v8_isolate); extern void php_v8_isolate_limits_set_time_limit(php_v8_isolate_t *php_v8_isolate, double time_limit_in_seconds); extern void php_v8_isolate_limits_set_memory_limit(php_v8_isolate_t *php_v8_isolate, size_t memory_limit_in_bytes); +extern void php_v8_isolate_limits_set_limits(php_v8_isolate_t *php_v8_isolate, double time_limit_in_seconds, size_t memory_limit_in_bytes); #define PHP_V8_DECLARE_ISOLATE_LOCAL_ALIAS(i) v8::Isolate *isolate = (i); diff --git a/tests/.testsuite.php b/tests/.testsuite.php index 69c1922..3c5d791 100644 --- a/tests/.testsuite.php +++ b/tests/.testsuite.php @@ -299,6 +299,19 @@ public function need_more_time() { // NOTE: this check is a bit fragile but should fits our need return isset($_ENV['TRAVIS']) && isset($_ENV['TEST_PHP_ARGS']) && $_ENV['TEST_PHP_ARGS'] == '-m'; } + + public function is_memory_test() { + // NOTE: this check is a bit fragile but should fits our need + if (!isset($_SERVER['ZEND_DONT_UNLOAD_MODULES']) || !$_SERVER['ZEND_DONT_UNLOAD_MODULES']) { + return false; + } + + if (isset($_SERVER['USE_ZEND_ALLOC']) && $_SERVER['USE_ZEND_ALLOC']) { + return false; + } + + return isset($_SERVER['LD_PRELOAD']) && false != strpos($_SERVER['LD_PRELOAD'], '/valgrind/'); + } } interface FilterInterface diff --git a/tests/V8Isolate_limit_time_affects_js_runtime_only.phpt b/tests/V8Isolate_limit_time_affects_js_runtime_only.phpt new file mode 100644 index 0000000..899841f --- /dev/null +++ b/tests/V8Isolate_limit_time_affects_js_runtime_only.phpt @@ -0,0 +1,91 @@ +--TEST-- +V8\Isolate - time limit affects js runtime only +--SKIPIF-- + +--FILE-- +need_more_time()) { + // On travis when valgrind active it takes more time to complete all operations so we just increase initial limits + $time_limit = 5.0; + $low_range = $time_limit/2; + $high_range = $time_limit*20; +} else { + $time_limit = 1.5; + $low_range = 1.45; + $high_range = 1.65; +} + +$helper->assert('Time limit accessor report no hit', false === $isolate->IsTimeLimitHit()); +$helper->assert('Get time limit default value is zero', 0.0 === $isolate->GetTimeLimit()); +$isolate->SetTimeLimit($time_limit); +$helper->assert('Get time limit returns valid value', $time_limit === $isolate->GetTimeLimit()); + +$helper->dump($isolate); +$helper->line(); + +// sleeping **before** running js should not affect js runtime timeout +sleep($time_limit); + +$t = microtime(true); +try { + $res = $script->Run($context); +} catch(\V8\Exceptions\TimeLimitException $e) { + $helper->exception_export($e); + echo 'script execution terminated', PHP_EOL; +} finally { + $helper->line(); + $t = microtime(true) - $t; + $helper->dump(round($t, 9)); + $helper->assert("Script execution time is within specified range ({$low_range}, {$high_range})", $t >= $low_range && $t < $high_range); +} + +$helper->assert('Get time limit returns valid value', $time_limit === $isolate->GetTimeLimit()); +$helper->assert('Time limit accessor report hit', true === $isolate->IsTimeLimitHit()); + +$helper->line(); +$helper->dump($isolate); + +// EXPECTF: ---/float\(.+\)/ +// EXPECTF: +++float(%f) + +// EXPECTF: ---/range \(.+, .+\)/ +// EXPECTF: +++range (%f, %f) +?> +--EXPECTF-- +Time limit accessor report no hit: ok +Get time limit default value is zero: ok +Get time limit returns valid value: ok +object(V8\Isolate)#3 (0) { +} + +V8\Exceptions\TimeLimitException: Time limit exceeded +script execution terminated + +float(%f) +Script execution time is within specified range (%f, %f): ok +Get time limit returns valid value: ok +Time limit accessor report hit: ok + +object(V8\Isolate)#3 (0) { +} diff --git a/tests/V8Isolate_limit_time_changed_at_runtime.phpt b/tests/V8Isolate_limit_time_changed_at_runtime.phpt new file mode 100644 index 0000000..b617740 --- /dev/null +++ b/tests/V8Isolate_limit_time_changed_at_runtime.phpt @@ -0,0 +1,106 @@ +--TEST-- +V8\Isolate - time limit changed at runtime +--SKIPIF-- + +--FILE-- +injectConsoleLog($context); + + +if ($helper->need_more_time()) { + // On travis when valgrind active it takes more time to complete all operations so we just increase initial limits + $time_limit = 5.0; + $low_range = $time_limit/2; + $high_range = $time_limit*20; +} else { + $time_limit = 1.5; + $low_range = 1.45; + $high_range = 1.65; +} + +// We sleep twice in php callback that called in js runtime +$low_range *=2; +$high_range *=2.2; // 2x +10% + +if (!$helper->need_more_time() && $helper->is_memory_test()) { + $high_range *=2; // valgrind adds some time overhead to test, so to avoid flaky test, we just set this to max sane value +} + +$func = new V8\FunctionObject($context, function (\V8\FunctionCallbackInfo $args) use ($helper) { + $t = microtime(true); + + $isolate = $args->GetIsolate(); + + $sleep_1 = $isolate->GetTimeLimit() + $isolate->GetTimeLimit()/10; // +10% to make 100% sure we hit time limit + $sleep_2 = $isolate->GetTimeLimit() + $isolate->GetTimeLimit()/10; + + $helper->assert('Time limit is not hit', !$isolate->IsTimeLimitHit()); + echo 'sleep ', $sleep_1, 'sec', PHP_EOL; + usleep($sleep_1*1000000); + $helper->assert('Time limit is hit', $isolate->IsTimeLimitHit()); + + $args->GetIsolate()->SetTimeLimit($isolate->GetTimeLimit()); // Setting timeout will reset any previous timeout + + $helper->assert('Setting time limit from php resets time limit hit', !$isolate->IsTimeLimitHit()); + echo 'sleep ', $sleep_2, 'sec', PHP_EOL; + usleep($sleep_2*1000000); + $helper->assert('However, it is hit once again', $isolate->IsTimeLimitHit()); + + echo 'total in function: ', microtime(true) - $t, 'sec', PHP_EOL; +}); + +$context->GlobalObject()->Set($context, new \V8\StringValue($isolate, 'sleep'), $func); + +$isolate->SetTimeLimit($time_limit); + +$t = microtime(true); +try { + // pause execution in php, and then trigger timeout exception by running some native js operations + $v8_helper->CompileRun($context, 'sleep(); let i = 0; while(true) {i++;}'); +} catch(\V8\Exceptions\TimeLimitException $e) { + $helper->exception_export($e); + echo 'script execution terminated', PHP_EOL; +} finally { + $helper->line(); + $t = microtime(true) - $t; + $helper->dump(round($t, 9)); + $helper->assert("Script execution time is within specified range ({$low_range}, {$high_range})", $t >= $low_range && $t < $high_range); +} + +$helper->line(); +$helper->dump($isolate); + +// EXPECTF: ---/\d\.\d+sec/ +// EXPECTF: +++%fsec + +// EXPECTF: ---/float\(.+\)/ +// EXPECTF: +++float(%f) + +// EXPECTF: ---/range \(.+, .+\)/ +// EXPECTF: +++range (%f, %f) +?> +--EXPECTF-- +Time limit is not hit: ok +sleep %fsec +Time limit is hit: ok +Setting time limit from php resets time limit hit: ok +sleep %fsec +However, it is hit once again: ok +total in function: %fsec +V8\Exceptions\TimeLimitException: Time limit exceeded +script execution terminated + +float(%f) +Script execution time is within specified range (%f, %f): ok + +object(V8\Isolate)#3 (0) { +}