Revision: 3663
Author: pekka.klarck
Date: Sat May 29 10:19:46 2010
Log: 1) Log the 'x seconds left' debug message before running timeouts to
avoid playing with the signal handler (and passing logger) unnecessarily.
2) Small changes to how activity is determined.
http://code.google.com/p/robotframework/source/detail?r=3663
Modified:
/trunk/src/robot/running/handlers.py
/trunk/src/robot/running/timeouts.py
/trunk/utest/running/test_timeouts.py
=======================================
--- /trunk/src/robot/running/handlers.py Sat May 29 07:28:57 2010
+++ /trunk/src/robot/running/handlers.py Sat May 29 10:19:46 2010
@@ -109,8 +109,8 @@
def _runner_for(self, handler, output, positional, named, timeout):
if timeout and timeout.active:
- return lambda: timeout.run(handler, args=positional,
kwargs=named,
- logger=output)
+ output.debug(timeout.get_message())
+ return lambda: timeout.run(handler, args=positional,
kwargs=named)
return lambda: handler(*positional, **named)
def _run_with_output_captured_and_signal_monitor(self, runner, output):
=======================================
--- /trunk/src/robot/running/timeouts.py Sat May 29 08:34:30 2010
+++ /trunk/src/robot/running/timeouts.py Sat May 29 10:19:46 2010
@@ -18,8 +18,6 @@
from robot.utils.robotthread import ThreadedRunner
from robot.errors import TimeoutError, DataError, FrameworkError
-from signalhandler import STOP_SIGNAL_MONITOR
-
class _Timeout(object):
@@ -27,7 +25,7 @@
self.string = timeout or ''
self.message = message
self.secs = -1
- self.starttime = 0
+ self.starttime = -1
self.error = None
if variables:
self.replace_variables(variables)
@@ -38,7 +36,7 @@
@property
def active(self):
- return self.secs > 0
+ return self.starttime > 0
def replace_variables(self, variables):
try:
@@ -53,11 +51,12 @@
self.error = 'Setting %s failed: %s' % (self.type.lower(),
unicode(err))
def start(self):
- self.starttime = time.time()
+ if self.secs > 0:
+ self.starttime = time.time()
def time_left(self):
- if self.starttime == 0:
- raise FrameworkError('Timeout not started')
+ if not self.active:
+ return -1
elapsed = time.time() - self.starttime
return self.secs - elapsed
@@ -71,16 +70,12 @@
return cmp(not self.active, not other.active) \
or cmp(self.time_left(), other.time_left())
- def run(self, runnable, args=None, kwargs=None, logger=None):
+ def run(self, runnable, args=None, kwargs=None):
if self.error:
raise DataError(self.error)
if not self.active:
raise FrameworkError('Timeout is not active')
timeout = self.time_left()
- STOP_SIGNAL_MONITOR.stop_running_keyword()
- if logger:
- logger.debug(self.get_message())
- STOP_SIGNAL_MONITOR.start_running_keyword()
if timeout <= 0:
raise TimeoutError(self.get_message())
runner = ThreadedRunner(runnable, args, kwargs)
@@ -89,8 +84,8 @@
try:
runner.stop_thread()
except:
- raise TimeoutError('Stopping keyword after %s failed: %s' %
- (self.type.lower(),
utils.get_error_message()))
+ raise TimeoutError('Stopping keyword after %s failed: %s'
+ % (self.type.lower(),
utils.get_error_message()))
raise TimeoutError(self.get_message())
def get_message(self):
=======================================
--- /trunk/utest/running/test_timeouts.py Sat May 29 08:34:43 2010
+++ /trunk/utest/running/test_timeouts.py Sat May 29 10:19:46 2010
@@ -103,31 +103,19 @@
return touts
-class MockLogger:
- def __init__(self):
- self.msgs = []
- def debug(self, msg):
- self.msgs.append(('DEBUG',msg))
- def info(self, msg):
- self.msgs.append(('INFO',msg))
-
-
class TestRun(unittest.TestCase):
def setUp(self):
self.tout = TestTimeout('1s', variables=VariableMock())
self.tout.start()
- self.logger = MockLogger()
def test_passing(self):
- assert_none(self.tout.run(passing, logger=self.logger))
- self._verify_debug_msg(self.logger.msgs[0])
+ assert_none(self.tout.run(passing))
def test_returning(self):
for arg in [ 10, 'hello', ['l','i','s','t'], unittest]:
- ret = self.tout.run(returning, args=(arg,), logger=self.logger)
+ ret = self.tout.run(returning, args=(arg,))
assert_equals(ret, arg)
- self._verify_debug_msg(self.logger.msgs[-1])
def test_failing(self):
assert_raises_with_msg(MyException, 'hello world',
@@ -145,16 +133,14 @@
def test_method_executed_normally_if_no_timeout(self):
os.environ['ROBOT_THREAD_TESTING'] = 'initial value'
- self.tout.run(sleeping, (0.05,), {}, self.logger)
- self._verify_debug_msg(self.logger.msgs[0])
+ self.tout.run(sleeping, (0.05,))
assert_equals(os.environ['ROBOT_THREAD_TESTING'], '0.05')
def test_method_stopped_if_timeout(self):
os.environ['ROBOT_THREAD_TESTING'] = 'initial value'
self.tout.secs = 0.001
assert_raises_with_msg(TimeoutError, 'Test timeout 1 second
exceeded.',
- self.tout.run, sleeping, (0.05,), {},
self.logger)
- self._verify_debug_msg(self.logger.msgs[0])
+ self.tout.run, sleeping, (0.05,))
time.sleep(0.1)
assert_equals(os.environ['ROBOT_THREAD_TESTING'], 'initial value')
@@ -164,20 +150,36 @@
assert_raises(TimeoutError, self.tout.run, sleeping, (10,))
def test_customized_message(self):
- self.logger.msgs = []
tout = KeywordTimeout('1s', 'My message', VariableMock())
tout.start()
- tout.run(passing, logger=self.logger)
- self._verify_debug_msg(self.logger.msgs[0], 'Keyword')
- tout.secs = 0.01
- time.sleep(0.02)
+ tout.run(passing)
+ tout.secs = 0.001
+ time.sleep(0.01)
assert_raises_with_msg(TimeoutError, 'My message',
- tout.run, sleeping, (1,), {}, self.logger)
-
- def _verify_debug_msg(self, msg, type='Test'):
- assert_equals(msg[0], 'DEBUG')
- assert_true(msg[1].startswith('%s timeout 1 second active.' %
type), msg[1])
- assert_true(msg[1].endswith('seconds left.'), msg[1])
+ tout.run, sleeping, (1,))
+
+
+class TestMessage(unittest.TestCase):
+
+ def test_non_active(self):
+ assert_equal(TestTimeout().get_message(), 'Test timeout not
active.')
+
+ def test_active(self):
+ tout = KeywordTimeout('42s', variables=VariableMock())
+ tout.start()
+ msg = tout.get_message()
+ assert_true(msg.startswith('Keyword timeout 42 seconds active.'),
msg)
+ assert_true(msg.endswith('seconds left.'), msg)
+
+ def test_failed_default(self):
+ tout = TestTimeout('1s', variables=VariableMock())
+ tout.starttime = time.time() - 2
+ assert_equal(tout.get_message(), 'Test timeout 1 second exceeded.')
+
+ def test_failed_custom(self):
+ tout = KeywordTimeout('1s', 'Custom message', VariableMock())
+ tout.starttime = time.time() - 2
+ assert_equal(tout.get_message(), 'Custom message')
if __name__ == '__main__':
