Log full exception information when calling JSR223 scripts #3176
Conversation
The scripts are user code, so in order to help them debug their code, the full stack trace is very useful. Signed-off-by: Cody Cutrer <cody@cutrer.us>
| @@ -198,7 +198,7 @@ public void loadScript(String engineIdentifier, InputStreamReader scriptData, | |||
| logger.trace("ScriptEngine does not support Invocable interface"); | |||
| } | |||
| } catch (Exception ex) { | |||
| logger.error("Error during evaluation of script '{}': {}", engineIdentifier, ex.getMessage()); | |||
| logger.error("Error during evaluation of script '{}'", engineIdentifier, ex); | |||
There was a problem hiding this comment.
on the JRuby side, this will always be a ScriptException, and it will always have a cause, and the cause will only have the stack trace from the Ruby code. So it'd be most useful to automatically unwrap one level down. But I'm not familiar with other script engines, and didn't want to lose information, so I just left it exposing the main exception.
There was a problem hiding this comment.
At JS Scripting, this will also be very useful for debugging.
We have a new issue, that relates to this (openhab/openhab-js#176).
I haven’t tested how the stack trace looks for JS Scripting here, but in our case, the exception is thrown because the user passes a parameter of wrong type to a Java method.
I‘ll try to have check the stack trace later.
There was a problem hiding this comment.
FYI: Wrapping down wouldn’t work here, because for example in JS Scripting we can also have a IllegalArgumentException in the case described above.
There was a problem hiding this comment.
FYI: Wrapping down wouldn’t work here, because for example in JS Scripting we can also have a
IllegalArgumentExceptionin the case described above.
In the jrubyscripting addon there are a couple of places that the engine is called directly to set things up, and exceptions are caught there. I did do unwrapping of those, but did it in a safe manner in case there isn't a cause:
There was a problem hiding this comment.
I‘ve just checked the JS Scripting code, there is already some code for the logging in place, I‘ll see if I can improve it.
|
Here's some examples of what's logged for JRuby: For this Ruby code (throwing a Ruby exception) def throws_exception
x.nil?
end
throws_exceptionYou get: For this Ruby code (throwing a Java NPE): java.util.ArrayList.new(nil)You get: |
|
In the first case I think that would be logged with the current code. That's pretty clear and the stack trace does not provide any additional information. In the second case it's true that the source of the NPE is not visible. However I wonder if someone without knowledge of Java is able to figure out what the relevant information from that stack trace is and if the stack trace in the first case is not adding confusion instead of removing it. |
Log line under the current code is Except that entity_lookup.rb is a line inside the helper library, and does not point at all to what in the user code caused it (test.rb:7).
Even myself have no idea what all the intervening java-ish stack frames are, but it's easy enough for me to search it for which tells me exactly where the problem is. Maybe a compromise would be to do it like RuleEngineImpl.java does, only logging the stack trace if set to debug level?: } catch (Throwable t) {
logger.error("Failed to execute rule '{}': {}", ruleUID, t.getMessage());
logger.debug("", t);
} |
|
Sounds good. |
The split logging (exception message at error level, full stack trace at debug level)? |
exception message at error level; full exception details at debug level Signed-off-by: Cody Cutrer <cody@cutrer.us>
|
Yes |
I'm assuming that's what you meant. I've tested that configuration, and updated the PR. |
wborn
changed the title
) * log full exception information when calling JSR223 scripts The scripts are user code, so in order to help them debug their code, the full stack trace is very useful. Signed-off-by: Cody Cutrer <cody@cutrer.us> GitOrigin-RevId: 0cceb5b
The scripts are user code, so in order to help them debug their code, the full stack trace is very useful.