Robotframework: If library has listener but no keywords, other library listeners' `close` method is called multiple times

[aaltat]

When there is a library listener which implements closelistener API method, it works as expected if tests are not dynamically created. The close API is only called one time. But if there is an another library, which is also a listener and it dynamically creates tests, the close is called two times. This problem is seen in https://github.com/MarketSquare/robotframework-browser/issues/463 issue.

Here is small PoC from the problem. When there is this test

*** Settings ***
Library    Library1.py
Library    Library2.py

*** Test Cases ***
Example 1
    Lib_2

And Library1 contains this:

from copy import deepcopy

from robot.model import TestSuite


class Library1:
    ROBOT_LISTENER_API_VERSION = 3
    ROBOT_LIBRARY_SCOPE = "TEST SUITE"

    def __init__(self):
        self.ROBOT_LIBRARY_LISTENER = self

    def _start_suite(self, suite: TestSuite, result):
        template = suite.tests[0]
        temp_test_list = list()
        for index in range(3):
            new_test = deepcopy(template)
            new_test.name = f"{new_test.name} {index}"
            temp_test_list.append(new_test)
        suite.tests = temp_test_list

And Library2 contains this:

from robot.api import logger


class Library2:
    ROBOT_LISTENER_API_VERSION = 2
    ROBOT_LIBRARY_SCOPE = "GLOBAL"

    def __init__(self):
        self.ROBOT_LIBRARY_LISTENER = self

    def lib_2(self):
        logger.info("Lib2")
        return 1

    def _close(self):
        logger.warn("close on lib2")

Then warning message is displayed two times. This is seen in the console:

robot  .
==============================================================================
Tmp                                                                           
==============================================================================
Tmp.Test Me                                                                   
==============================================================================
Example 1 0                                                           | PASS |
------------------------------------------------------------------------------
Example 1 1                                                           | PASS |
------------------------------------------------------------------------------
Example 1 2                                                           | PASS |
------------------------------------------------------------------------------
Tmp.Test Me                                                           | PASS |
3 tests, 3 passed, 0 failed
==============================================================================
[ WARN ] close on lib2
Tmp                                                                   | PASS |
3 tests, 3 passed, 0 failed
==============================================================================
[ WARN ] close on lib2
Output:  /home/user/workspace/robotframework-playwright/tmp/output.xml
Log:     /home/user/workspace/robotframework-playwright/tmp/log.html
Report:  /home/user/workspace/robotframework-playwright/tmp/report.html

The log.html looks like this

I was able to reproduce the problem with RF 3.2.2 and 4.0a3.

[pekkaklarck]

Looks strange. Needs to be investigated.

[pekkaklarck]

First findings investigating this:

• Adding new tests doesn't affect this. The _start_suite() can be remove altogether from Library1 and the same thing still happens.

• If a keyword is added to Library1, the problem goes away. This is possible workaround.

• If you want to add tests based on a template like this, the code can be simplified:

  def _start_suite(self, model, result):
     template = model.tests[0]
     model.tests = [template.deepcopy(name=f"{template.name} {index}")
                    for index in range(3)]
  

[pekkaklarck]

Further findings:

• The fact that the problem only occurred with libraries not having keywords gave a hint that the problem is likely to have something to do with truth values. Sure enough we have this code in listenermethods.py

  def _get_methods(self, library=None):
      if not (self._method_stack and self._method_stack[-1]):
          return []
      methods = self._method_stack[-1]
      if library:
          return [m for m in methods if m.library is library]
      return methods
  

  and in the case causing the problem library is empty, it is considered false, and thus if library: branch is not executed. The problem can be fixed simply by changing the condition to if library is not None:, but it might be a better idea to make a library truthy always if it has a listener.

• The listener code is way too clever and thus complicated.

[aaltat]

Did not spot that example could be simplified more, but example is just simplified version of the DataDriver and Browser library working together. It is also true that DataDriver does not have keywords, ping @Snooz82

[pekkaklarck]

Yeah, the example to reproduce the problem can be simplified by removing _start_suite altogether. And creating tests in _start_suite could be simplified but that's totally unrelated to this issue.

Good news are that:

• I have a fix for this ready. Turned out TestLibrary objects have __len__ that returns the number of keywords and because they don't have explicit __bool__/__nonzero__ that's used to determine the truth value. Adding __bool__/__nonzero__ is easy and fixes the problem.

• If needed, DataDriver can workaround this problem with RF < 4 by adding a dummy keyword dynamically.