Skip to content

Writing messages to debug file and to console is delayed when timeouts are used #3644

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Closed
gajendraks opened this issue Aug 30, 2020 · 6 comments

Comments

@gajendraks
Copy link

gajendraks commented Aug 30, 2020

Steps to reproduce:

  • Include [Timeout] in the test case
  • Execute the robot suite
*** Settings ***
Library     lib.py

*** Test Cases ***
Test
    [Timeout]    20 sec
    Keyword

Observed

  • The logs are not getting written into the the console output or the debugfile until keyword ends.

Expected

  • The logs should appear in console and debugfile in realtime.

Note: I see the realtime logging happening to console output and debugfile in the v3.0.4. But not in v3.2.1

@pekkaklarck
Copy link
Member

This is most likely caused by the fix to #2839 in RF 3.1. Could you also show what your Keyword in lib.py does?

@gajendraks
Copy link
Author

Note: I changed timeout to 20sec in the above comment and the Keyword in lib.py is defined as below

def keyword():
    logging.debug('before')
    time.sleep(5)
    logging.debug('after')

the logging happens in realtime when [Timeout] is removed

@smahantshetti
Copy link

i am facing the same exact issue.

$ robot --version
Robot Framework 5.0.1 (Python 3.6.8 on linux)

if i remove/comment out the timeout in test case, then logging is Realtime in logfile and everything works fine

    [Teardown]
#    [Timeout]    12h

also, same issue if i use a default timeout
ex:


*** Settings ***
Test Timeout    3h

is there a workaround or a fix in queue for this please ?
its very important especially when a keyword is stuck and i cannot tell if its really stuck or processing some statement in the code. i can only know after the keyword is complete or i abruptly cancel it.

@pekkaklarck
Copy link
Member

Logged messages are cached , not written directly to disk, when using timeouts to avoid corrupting output.xml if a timeout expires exactly when a message is written. See #2839 for details about that very severe problem.

To avoid caching, we needed to come up with some other way to protect logger from timeouts. Until that, a workaround is not using timeouts (they should in general be used only when absolutely necessary) or logging to some external file or to sys.__stdout__ to see messages in realtime.

@smahantshetti
Copy link

smahantshetti commented Sep 23, 2022

Thanks @pekkaklarck
we currently using built-in robot logger to log all debug messages (-b DEBUG.log -d logs) and logger statements are all over in almost all of the libraries in our code. so i think it may not be feasible to replace all that with some other way of logging.

from robot.api import logger
logger.debug()
logger.info()

i think one way would be to downgrade our robot to 3.0 version where this worked fine (And we had not issues with corrupt xml) until there is a fix.

@pekkaklarck
Copy link
Member

pekkaklarck commented May 7, 2025

This problems has been fixed as a byproduct of fixing a problem that logged messages do not respect the current log level when timeouts are used (#5395). Although the root cause in these two issues is exactly the same, the effect is different and I won't close this as a duplicate of the other issue. I also want to add a test to make sure the problem is gone and won't reappear.

@pekkaklarck pekkaklarck self-assigned this May 7, 2025
@pekkaklarck pekkaklarck added this to the v7.3 milestone May 7, 2025
@pekkaklarck pekkaklarck changed the title Realtime logging not available when [timeout] is used in a test case Writing messages to debug file and to console is delayed when timeouts are used May 7, 2025
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

No branches or pull requests

3 participants