Logging from listener hooks outside of keywords

[mkorpela]

Status

Currently logging fails silently when doing it from many listener interface test lifecycle methods

• start_suite
• end_suite
• start_test
• end_test
• start_keyword
• end_keyword
  ..

This is problematic for example for Browser library where logging of automatic cleanup of opened pages done on debug level would be beneficial MarketSquare/robotframework-browser#664 .

Proposed solution

Add position to log.html to show these messages. Add the messages to output.xml.

[pekkaklarck]

Would be handy but not trivial. Recent changes in RF 4.0 to merge keywords, messages, IFs and FORs into single body ought to make this reasonable easy with start/end_keyword, though. These messages could go to the body of the current or possibly parent keyword/test. If messages in start/end_xxx would go the body of the current keyword/test, then messages logged by start/end_test could possibly go to the current test. With start/end_suite there's a problem that suites themselves have no body, so these messages needed to go to setup/teardown. They may not always have setup/teardown an we possibly needed to created them. We had the same problem recently when handling start/end_suite executing keywords, so that ought to be doable as well.

The possible really big problem is that output.xml gets broken really easily if we write things there in wrong order. For example, if we want to log a message by start_suite, we needed to have <suite> element created in output.xml. I believe we write it before calling listeners, but because it would be handy for listeners also to be modify the logged suite that may not be the case. I don't have time to look at the code or test this right now.

If there are no problems with the order we write info to output.xml, this could possibly be still done before RF 4.1.