-
Notifications
You must be signed in to change notification settings - Fork 2.4k
Change of logging does not work under some conditions #3336
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
Comments
The fix for #2839 delays logging messages when timeouts are used. I guess it could be possible that log level changes before messages actually are logged. It would require a pretty interesting setup, though, and it might also be pretty complicated to fix. Anyway, cannot really comment more until you can provide a simple executable example demonstrating the issue. |
Timeouts are what I missed. Thank. Now a very simple example demonstrates this problem. test.robot
Lib.py
|
The reason this occurs is that messages that are logged during timeouts (after #2839 was fixed) are delayed and forwarded to various loggers (output.xml, syslog, listeners, ...) only after the executed keyword finishes. Loggers have different log levels and make decision about actually logging or not logging messages independently. With the current design loggers make the decision about logging (when timeouts are enabled) after the keyword finishes and the active log level with output.xml may be different than when the message actually was logged by the keyword. Unfortunately changing this would not be easy. It would basically re-implementing the fix for #2839 so that delaying messages would be moved from our top-level logger to the logger responsible on writing output.xml. Then other loggers would get messages immediately, and the output.xml logger could make the decision about either dropping or delaying the message based on the current log level. Now that I think about this, this would be a better solution to #2839 than the current one. Only the output.xml logger actually needs to delay these messages as the original problem with #2839 was corrupting output.xml. Other loggers, especially listeners, getting messages immediately would be better. Because the change would be somewhat big, and I don't consider the problem too sever, I cannot promise when I'd have time to fix it. It certainly won't be included into the scope of the already overdue RF 3.2 unless someone else is interested to look at it. One possible way to avoid this problem would me marking the keyword executing other keywords as "run keyword variant". Unfortunately the API to do so is pretty awkward and the whole functionality isn't too well documented. We have issue #2190 about enhancing the API (and the docs), but although it's scoped for RF 3.2 there's a risk it will still be dropped. That issue ought to contain enough information about that API to test does it help in this case. |
I tried using register_run_keyword. This works for a normal keyword call, but in the case of a call from a python function, the behavior remains the same.
|
This was reported again as #5395. The problem has now been fixed and the fix will be in the forthcoming RF 7.3. I should have closed the new issue as a duplicate of this issue, but I had totally forgotten about this one. Now that the other is already closed, I think it's best to close this one as its dupe. Anyway, what really matters is that the problems has been finally fixed. |
Hello!

We use logging a lot when calling some keywords. Since version 3.1, some of these places have stopped working. I was not able to reproduce the problem with a small example, so please help with finding the cause. I assume the reason may be a change in #2839
The text was updated successfully, but these errors were encountered: