2 new revisions:
Revision: a5c4de3ca2f3
Author: Pekka Klärck
Date: Fri Sep 23 01:44:35 2011
Log: Tests for all listener methods logging messages using INFO and
WARN le...
http://code.google.com/p/robotframework/source/detail?r=a5c4de3ca2f3
Revision: 0d8c8619eb84
Author: Pekka Klärck
Date: Fri Sep 23 01:48:29 2011
Log: Fixed recursion and endless loop problems caused by listeners
logging....
http://code.google.com/p/robotframework/source/detail?r=0d8c8619eb84
==============================================================================
Revision: a5c4de3ca2f3
Author: Pekka Klärck
Date: Fri Sep 23 01:44:35 2011
Log: Tests for all listener methods logging messages using INFO and
WARN level.
Update issue 548
Tests are done.
http://code.google.com/p/robotframework/source/detail?r=a5c4de3ca2f3
Added:
/atest/robot/output/listener_interface/listener_logging.txt
/atest/testdata/output/listeners/logging_listener.py
=======================================
--- /dev/null
+++ /atest/robot/output/listener_interface/listener_logging.txt Fri Sep 23
01:44:35 2011
@@ -0,0 +1,120 @@
+*** Settings ***
+Suite Setup Run Tests With Logging Listener
+Force Tags regression pybot jybot
+Resource listener_resource.txt
+
+*** Test Cases ***
+
+Logging from listener does not break output file
+ Test statuses should be correct
+ Log and report should be created
+
+All start and end methods can log warnings to execution errors
+ Correct warnings should be shown in execution errors
+
+Methods inside start_keyword and end_keyword can log normal messages
+ Correct messages should be logged to normal log
+
+Methods outside start_keyword and end_keyword can log messages to syslog
+ Correct messages should be logged to syslog
+
+
+*** Keywords ***
+Run Tests With Logging Listener
+ ${path} = Normalize Path
${DATADIR}/output/listeners/logging_listener.py
+ Run Tests --listener ${path} -l l.html -r r.html
misc/pass_and_fail.html
+
+Test statuses should be correct
+ Check Test Case Pass
+ Check Test Case Fail
+
+Log and report should be created
+ File Should Not Be Empty ${OUTDIR}/l.html
+ File Should Not Be Empty ${OUTDIR}/r.html
+
+Correct warnings should be shown in execution errors
+ Execution errors should have messages from message and log_message
methods
+ Correct start/end warnings should be shown in execution errors
+
+Execution errors should have messages from message and log_message methods
+ Check Log Message ${ERRORS.msgs[0]} message: INFO Robot Framework *
WARN pattern=yes
+ Check Log Message ${ERRORS.msgs[-5]} log_message: DEBUG Traceback *
WARN pattern=yes
+
+Correct start/end warnings should be shown in execution errors
+ ${msgs} = Get start/end messages ${ERRORS.msgs}
+ ${index} = Set Variable ${0}
+ @{kw} = Create List start_keyword end_keyword
+ @{uk} = Create List start_keyword @{kw} @{kw} end_keyword
+ :FOR ${method} IN start_suite @{uk} start_test @{uk} end_test
+ ... start_test @{uk} @{kw} end_test end_suite
+ \ Check Log Message ${msgs[${index}]} ${method} WARN
+ \ ${index} = Set Variable ${index + 1}
+ Length Should Be ${msgs} ${index}
+
+Get start/end messages
+ [Arguments] ${all msgs}
+ @{all msgs} = Set Variable ${all msgs}
+ ${return} = Create List
+ :FOR ${msg} IN @{all msgs}
+ \ Run Keyword Unless "message: " in """${msg.message}""" Append To
List ${return} ${msg}
+ [Return] ${return}
+
+Correct messages should be logged to normal log
+ 'My Keyword' has correct messages ${SUITE.setup} Suite Setup
+ ${tc} = Check Test Case Pass
+ 'My Keyword' has correct messages ${tc.kws[0]} Pass
+ ${tc} = Check Test Case Fail
+ 'My Keyword' has correct messages ${tc.kws[0]} Fail
+ 'Fail' has correct messages ${tc.kws[1]}
+
+'My Keyword' has correct messages
+ [Arguments] ${kw} ${name}
+ Check Log Message ${kw.kws[0].msgs[0]} start_keyword INFO
+ Check Log Message ${kw.kws[0].msgs[1]} start_keyword WARN
+ Check Log Message ${kw.kws[0].msgs[2]} log_message: TRACE Arguments:
* INFO pattern=yes
+ Check Log Message ${kw.kws[0].msgs[3]} log_message: TRACE Arguments:
* WARN pattern=yes
+ Check Log Message ${kw.kws[0].msgs[4]} Hello says "${name}"! INFO
+ Check Log Message ${kw.kws[0].msgs[5]} log_message: INFO Hello
says "${name}"! INFO
+ Check Log Message ${kw.kws[0].msgs[6]} log_message: INFO Hello
says "${name}"! WARN
+ Check Log Message ${kw.kws[0].msgs[7]} log_message: TRACE Return:
None INFO
+ Check Log Message ${kw.kws[0].msgs[8]} log_message: TRACE Return:
None WARN
+ Check Log Message ${kw.kws[0].msgs[9]} end_keyword INFO
+ Check Log Message ${kw.kws[0].msgs[10]} end_keyword WARN
+ Check Log Message ${kw.kws[1].msgs[0]} start_keyword INFO
+ Check Log Message ${kw.kws[1].msgs[1]} start_keyword WARN
+ Check Log Message ${kw.kws[1].msgs[2]} log_message: TRACE Arguments:
* INFO pattern=yes
+ Check Log Message ${kw.kws[1].msgs[3]} log_message: TRACE Arguments:
* WARN pattern=yes
+ Check Log Message ${kw.kws[1].msgs[4]} log_message: DEBUG Debug
message INFO
+ Check Log Message ${kw.kws[1].msgs[5]} log_message: DEBUG Debug
message WARN
+ Check Log Message ${kw.kws[1].msgs[6]} log_message: TRACE Return:
None INFO
+ Check Log Message ${kw.kws[1].msgs[7]} log_message: TRACE Return:
None WARN
+ Check Log Message ${kw.kws[1].msgs[8]} end_keyword INFO
+ Check Log Message ${kw.kws[1].msgs[9]} end_keyword WARN
+ Check Log Message ${kw.msgs[0]} start_keyword INFO
+ Check Log Message ${kw.msgs[1]} start_keyword WARN
+ Check Log Message ${kw.msgs[2]} log_message: TRACE Arguments: *
INFO pattern=yes
+ Check Log Message ${kw.msgs[3]} log_message: TRACE Arguments: *
WARN pattern=yes
+ Check Log Message ${kw.msgs[4]} log_message: TRACE Return: None INFO
+ Check Log Message ${kw.msgs[5]} log_message: TRACE Return: None WARN
+ Check Log Message ${kw.msgs[6]} end_keyword INFO
+ Check Log Message ${kw.msgs[7]} end_keyword WARN
+
+'Fail' has correct messages
+ [Arguments] ${kw}
+ Check Log Message ${kw.msgs[0]} start_keyword INFO
+ Check Log Message ${kw.msgs[1]} start_keyword WARN
+ Check Log Message ${kw.msgs[2]} log_message: TRACE Arguments: *
INFO pattern=yes
+ Check Log Message ${kw.msgs[3]} log_message: TRACE Arguments: *
WARN pattern=yes
+ Check Log Message ${kw.msgs[4]} Expected failure FAIL
+ Check Log Message ${kw.msgs[5]} log_message: FAIL Expected failure
INFO
+ Check Log Message ${kw.msgs[6]} log_message: FAIL Expected failure
WARN
+ Check Log Message ${kw.msgs[7]} log_message: DEBUG Traceback *
INFO pattern=yes
+ Check Log Message ${kw.msgs[8]} log_message: DEBUG Traceback *
WARN pattern=yes
+ Check Log Message ${kw.msgs[9]} end_keyword INFO
+ Check Log Message ${kw.msgs[10]} end_keyword WARN
+
+Correct messages should be logged to syslog
+ :FOR ${msg} IN message: INFO Robot Framework trunk start_suite
+ ... end_suite start_test end_test output_file log_file
report_file
+ \ Check syslog contains | INFO \ | ${msg}
+ \ Check syslog contains | WARN \ | ${msg}
=======================================
--- /dev/null
+++ /atest/testdata/output/listeners/logging_listener.py Fri Sep 23
01:44:35 2011
@@ -0,0 +1,20 @@
+import logging
+from robot.api import logger
+
+ROBOT_LISTENER_API_VERSION = 2
+
+def get_logging_listener_method(name):
+ def listener_method(*args):
+ if name in ['message', 'log_message']:
+ msg = args[0]
+ message = '%s: %s %s' % (name, msg['level'], msg['message'])
+ else:
+ message = name
+ logging.info(message)
+ logger.warn(message)
+ return listener_method
+
+for name in ['start_suite', 'end_suite', 'start_test', 'end_test',
+ 'start_keyword', 'end_keyword', 'log_message', 'message',
+ 'output_file', 'log_file', 'report_file', 'debug_file', 'close']:
+ globals()[name] = get_logging_listener_method(name)
==============================================================================
Revision: 0d8c8619eb84
Author: Pekka Klärck
Date: Fri Sep 23 01:48:29 2011
Log: Fixed recursion and endless loop problems caused by listeners
logging.
Update issue 548
Status: Done
Listeners logging caused interesting recursion problems and endless loops in
some situations. These problems ought to be fixed now. Or at least test in
the previous commit don't fail anymore.
http://code.google.com/p/robotframework/source/detail?r=0d8c8619eb84
Modified:
/src/robot/output/listeners.py
/src/robot/output/logger.py
=======================================
--- /src/robot/output/listeners.py Thu Sep 15 06:39:05 2011
+++ /src/robot/output/listeners.py Fri Sep 23 01:48:29 2011
@@ -25,6 +25,16 @@
from java.util import HashMap
+def listener_method(method):
+ """Decorator to prevent listeners causing recursion by logging"""
+ def decorated_method(self, *args):
+ if not self._calling_method:
+ self._calling_method = True
+ method(self, *args)
+ self._calling_method = False
+ return decorated_method
+
+
class Listeners:
_start_attrs = ['doc', 'starttime', 'longname']
_end_attrs = _start_attrs +
['endtime', 'elapsedtime', 'status', 'message']
@@ -32,8 +42,8 @@
def __init__(self, listeners):
self._listeners = self._import_listeners(listeners)
self._running_test = False
- self._calling_log_message = False
self._setup_or_teardown_type = None
+ self._calling_method = False
def __nonzero__(self):
return bool(self._listeners)
@@ -52,6 +62,7 @@
LOGGER.info("Details:\n%s" % details)
return listeners
+ @listener_method
def start_suite(self, suite):
for li in self._listeners:
if li.version == 1:
@@ -63,6 +74,7 @@
'totaltests': suite.get_test_count()})
li.call_method(li.start_suite, suite.name, attrs)
+ @listener_method
def end_suite(self, suite):
for li in self._listeners:
if li.version == 1:
@@ -73,6 +85,7 @@
attrs['statistics'] = suite.get_stat_message()
li.call_method(li.end_suite, suite.name, attrs)
+ @listener_method
def start_test(self, test):
self._running_test = True
for li in self._listeners:
@@ -83,6 +96,7 @@
attrs['template'] = test.template or ''
li.call_method(li.start_test, test.name, attrs)
+ @listener_method
def end_test(self, test):
self._running_test = False
for li in self._listeners:
@@ -93,6 +107,7 @@
attrs['template'] = test.template or ''
li.call_method(li.end_test, test.name, attrs)
+ @listener_method
def start_keyword(self, kw):
for li in self._listeners:
if li.version == 1:
@@ -102,6 +117,7 @@
attrs['type'] = self._get_keyword_type(kw, start=True)
li.call_method(li.start_keyword, kw.name, attrs)
+ @listener_method
def end_keyword(self, kw):
for li in self._listeners:
if li.version == 1:
@@ -125,17 +141,13 @@
return '%s %s' % (('Test' if self._running_test else 'Suite'),
kw.type.title())
+ @listener_method
def log_message(self, msg):
- if not self._calling_log_message:
- self._calling_log_message = True
- self._log_message(msg)
- self._calling_log_message = False
-
- def _log_message(self, msg):
for li in self._listeners:
if li.version == 2:
li.call_method(li.log_message, self._create_msg_dict(msg))
+ @listener_method
def message(self, msg):
for li in self._listeners:
if li.version == 2:
@@ -145,10 +157,12 @@
return {'timestamp': msg.timestamp, 'message': msg.message,
'level': msg.level, 'html': 'yes' if msg.html else 'no'}
+ @listener_method
def output_file(self, name, path):
for li in self._listeners:
li.call_method(getattr(li, '%s_file' % name.lower()), path)
+ @listener_method
def close(self):
for li in self._listeners:
li.call_method(li.close)
@@ -219,13 +233,13 @@
try:
method(*args)
except:
- disabled =
self._disable_message_method_if_it_failed(method.__name__)
+ disabled = self._disable_message_method_if_it_failed(method)
self._report_error(method.__name__, disabled)
- def _disable_message_method_if_it_failed(self, name):
+ def _disable_message_method_if_it_failed(self, method):
# This avoids recursion caused by message method failing
repeatingly:
# http://code.google.com/p/robotframework/issues/detail?id=832
- if name == 'message':
+ if method is self.message:
self.message = lambda msg: None
return True
return False
=======================================
--- /src/robot/output/logger.py Wed Sep 21 08:28:05 2011
+++ /src/robot/output/logger.py Fri Sep 23 01:48:29 2011
@@ -61,7 +61,7 @@
def _relay_cached_messages_to(self, logger):
if self._message_cache:
- for msg in self._message_cache:
+ for msg in self._message_cache[:]:
logger.message(msg)
def unregister_logger(self, *loggers):
@@ -118,7 +118,7 @@
def disable_library_import_logging(self):
self.log_message = self._prev_log_message
- def warn(self, msg, log=False):
+ def warn(self, msg, log=False): # TODO: Do we still need log=False?
method = self.log_message if log else self.message
method(Message(msg, 'WARN'))
