RFStream Warning: keyword - BuiltIn.Sleep did not have a corresponding pop

[dzvancuks]

For some reason library triggers unexpected warning when I try async in test setup

*** Settings ***
Library      AsyncLibrary

Test Setup       Test Async

*** Variables ***

*** Test Cases ***
My super mega test
    Log    Hello

*** Keywords ***
Test Async
    ${tmp handle}=    Async Run    Tmp Test
    Async Get    ${tmp handle}    timeout=5s

Tmp Test
    Sleep    3s

After running test I get

==============================================================================
Tmp                                                                           
==============================================================================
My super mega test                                                    RFStream Warning: keyword - BuiltIn.Sleep did not have a corresponding pop.
RFStream Warning: keyword - .Tmp Test did not have a corresponding pop.
My super mega test                                                    | PASS |
------------------------------------------------------------------------------
Tmp                                                                   | PASS |
1 test, 1 passed, 0 failed
==============================================================================

[rlehfeld]

hm, this one I can't reproduce. Can you comment please with information

1. which python version
2. which robot framework version
3. exact command of robot you used to run the tests.

[rlehfeld]

sorry,

[rlehfeld]

I thinks I know what the problem is and why I cannot reproduce it on the other hand.

Could it be that you are using https://pypi.org/project/robotframework-output-stream/ (Please confirm)

The problem keywords are running in parallel and this make the output into disorder. The module is not prepared for this I believe and I only implemented a solution for the buildin logging functionality which comes with robot framework. Others will most likely not work and will be difficult to support as no access to the internal structure so easily.

[rlehfeld]

just checked the source code of RFStream linked by me and indeed the message comes from there. The code which produces it checkes that certain messages come in a certain order which mean also that keywords are not run in parallel. As a consequence the RFSteam and my solution are and will always be incompatible to use together, I am sorry.

[dzvancuks]

@rlehfeld Hello again.

To answer your questions, I think this is related to VSCode extension. So to break it down

1. No, I didn't use https://pypi.org/project/robotframework-output-stream/
2. I did search for this warning message. And it seems to be coming from VSC extension robocorp.robotframework-lsp

   $ grep "RFStream Warning" -r .vscode/
   .vscode/extensions/robocorp.robotframework-lsp-1.12.0/src/robotframework_ls/vendored/robot_out_stream/_impl.py:                    f"RFStream Warning: unable to pop {entry_type} - {entry_id} (empty queue).\n"
   .vscode/extensions/robocorp.robotframework-lsp-1.12.0/src/robotframework_ls/vendored/robot_out_stream/_impl.py:                                    f"RFStream Warning: {stack_entry.entry_type} - {stack_entry.entry_id} did not have a corresponding pop.\n"
   .vscode/extensions/robocorp.robotframework-lsp-1.12.0/src/robotframework_ls/vendored/robot_out_stream/_impl.py:                                        f"RFStream Warning: {stack_entry.entry_type} - {stack_entry.entry_id} did not have a corresponding pop.\n"
   .vscode/extensions/robocorp.robotframework-lsp-1.12.0/src/robotframework_ls/vendored/robot_out_stream/_impl.py:                                    f"RFStream Warning: {stack_entry.entry_type} - {stack_entry.entry_id} pop just by type. Actual request: {entry_type} - {entry_id}\n"
   .vscode/extensions/robocorp.robotframework-lsp-1.12.0/src/robotframework_ls/vendored/robot_out_stream/_impl.py:                        f"RFStream Warning: unable to pop {entry_type} - {entry_id} because it does not match the current top: {stack_entry.entry_type} - {stack_entry.entry_id}\n"
   grep: .vscode/extensions/robocorp.robotframework-lsp-1.12.0/src/robotframework_ls/vendored/robot_out_stream/__pycache__/_impl.cpython-311.pyc: binary file matches
   grep: .vscode/extensions/robocorp.robotframework-lsp-1.12.0/src/robotframework_ls/vendored/robot_out_stream/__pycache__/_impl.cpython-310.pyc: binary file matches

   This is quite popular extension for VSC. Perhaps this still can be fixed so that lib and extension would be compatible.

[dzvancuks]

Also I found that triggering test from shell do not trigger this warning:

$ robot ./tests/tmp.robot 

==============================================================================
Tmp                                                                           
==============================================================================
My super mega test                                                    | PASS |
------------------------------------------------------------------------------
Tmp                                                                   | PASS |
1 test, 1 passed, 0 failed
==============================================================================

Only when I run it from VSC IDE, only then warning is triggered.

Also I didn't experience this warning with other extensions so far. Perhaps this can give you some clues.

[rlehfeld]

as I said, the code (from VS Code) assumes that keywords are executed in a certain predefined order BUT my changes make it complete random on purpose (as this is the purpose of this module). Thus no chance that I can do something from my end here.

[dzvancuks]

That's sad :(