Skip to content

Output file can be corrupted if library keyword uses BuiltIn.run_keyword and timeout occurs #5417

@pekkaklarck

Description

@pekkaklarck

Output files can be corrupted if a timeout occurs when Robot is writing log messages. That is a serious issue, because it prevents creating normal log and report files. Investigating this kind of problems is also pretty annoying, because what happens depends on when exactly the timeout occurs. It could be that most times everything goes well, but now and then the output is corrupted.

To avoid these problems, we nowadays delay writing log messages when timeouts are enabled (#2839). Before we had this mechanism in place, the following example reproduced the problem pretty reliably regardless the operating system:

*** Settings ***
Library     lib.py

*** Test Cases ***
Test
    [Timeout]    0.1 sec
    Keyword
from robot.api import logger

MSG = 'A rather long message that is slow to write on the disk. ' * 10000

def keyword():
    while True:
        logger.info(MSG)

Unfortunately the current mechanism doesn't prevent the problem if a library keyword uses BuiltIn.run_keyword for executing other keywords that log messages. For example, this variation corrupts the output file nearly every time I run it on Windows:

from robot.api import logger
from robot.libraries.BuiltIn import BuiltIn

MSG = 'A rather long message that is slow to write on the disk. ' * 10000

def keyword():
    while True:
        BuiltIn().run_keyword('Log Huge Message')

def log_huge_message():
    logger.info(MSG)

I haven't been able to get the above example, or any variation of, to fail on Linux. This is most likely due to the platform specific timeout implementation, but looking at the related code, it seems the problem could happen anywhere. Anyway, this is a serious issue even if it would occur only on Windows.

Metadata

Metadata

Assignees

Type

Projects

No projects

Milestone

Relationships

None yet

Development

No branches or pull requests

Issue actions