[jsscripting] Improve logging on JS error (#16445)

* [jsscripting] Improve script error logging
* [jsscripting] Suppress some warnings
* [jsscripting] Throw ISE instead of RE
* [jsscripting] Minor null annotation improvements

Include fileName or ruleUID or transformation UID in the logger name used by the logged error stack trace.

Signed-off-by: Florian Hotze <florianh_dev@icloud.com>
Signed-off-by: Ciprian Pascu <contact@ciprianpascu.ro>
This commit is contained in:
Florian Hotze 2024-02-25 00:39:57 +01:00 committed by Ciprian Pascu
parent 7a3897e366
commit c153944f6f
2 changed files with 44 additions and 12 deletions

View File

@ -15,6 +15,7 @@ package org.openhab.automation.jsscripting.internal;
import javax.script.Invocable;
import javax.script.ScriptEngine;
import org.eclipse.jdt.annotation.Nullable;
import org.graalvm.polyglot.PolyglotException;
import org.openhab.automation.jsscripting.internal.scriptengine.InvocationInterceptingScriptEngineWithInvocableAndAutoCloseable;
import org.slf4j.Logger;
@ -28,8 +29,9 @@ import org.slf4j.LoggerFactory;
class DebuggingGraalScriptEngine<T extends ScriptEngine & Invocable & AutoCloseable>
extends InvocationInterceptingScriptEngineWithInvocableAndAutoCloseable<T> {
private static final Logger STACK_LOGGER = LoggerFactory
.getLogger("org.openhab.automation.script.javascript.stack");
private static final String SCRIPT_TRANSFORMATION_ENGINE_IDENTIFIER = "openhab-transformation-script-";
private @Nullable Logger logger;
public DebuggingGraalScriptEngine(T delegate) {
super(delegate);
@ -37,13 +39,42 @@ class DebuggingGraalScriptEngine<T extends ScriptEngine & Invocable & AutoClosea
@Override
public Exception afterThrowsInvocation(Exception e) {
if (logger == null) {
initializeLogger();
}
Throwable cause = e.getCause();
if (cause instanceof IllegalArgumentException) {
STACK_LOGGER.error("Failed to execute script:", e);
logger.error("Failed to execute script:", e);
}
if (cause instanceof PolyglotException) {
STACK_LOGGER.error("Failed to execute script:", cause);
logger.error("Failed to execute script:", cause);
}
return e;
}
/**
* Initializes the logger.
* This cannot be done on script engine creation because the context variables are not yet initialized.
* Therefore, the logger needs to be initialized on the first use after script engine creation.
*/
private void initializeLogger() {
Object fileName = delegate.getContext().getAttribute("javax.script.filename");
Object ruleUID = delegate.getContext().getAttribute("ruleUID");
Object ohEngineIdentifier = delegate.getContext().getAttribute("oh.engine-identifier");
String identifier = "stack";
if (fileName != null) {
identifier = fileName.toString().replaceAll("^.*[/\\\\]", "");
} else if (ruleUID != null) {
identifier = ruleUID.toString();
} else if (ohEngineIdentifier != null) {
if (ohEngineIdentifier.toString().startsWith(SCRIPT_TRANSFORMATION_ENGINE_IDENTIFIER)) {
identifier = ohEngineIdentifier.toString().replaceAll(SCRIPT_TRANSFORMATION_ENGINE_IDENTIFIER,
"transformation.");
}
}
logger = LoggerFactory.getLogger("org.openhab.automation.script.javascript." + identifier);
}
}

View File

@ -72,24 +72,24 @@ public class OpenhabGraalJSScriptEngine
extends InvocationInterceptingScriptEngineWithInvocableAndAutoCloseable<GraalJSScriptEngine> {
private static final Logger LOGGER = LoggerFactory.getLogger(OpenhabGraalJSScriptEngine.class);
private static Source GLOBAL_SOURCE;
private static final Source GLOBAL_SOURCE;
static {
try {
GLOBAL_SOURCE = Source.newBuilder("js", getFileAsReader("node_modules/@jsscripting-globals.js"),
"@jsscripting-globals.js").cached(true).build();
} catch (IOException e) {
throw new RuntimeException("Failed to load @jsscripting-globals.js", e);
throw new IllegalStateException("Failed to load @jsscripting-globals.js", e);
}
}
private static Source OPENHAB_JS_SOURCE;
private static final Source OPENHAB_JS_SOURCE;
static {
try {
OPENHAB_JS_SOURCE = Source
.newBuilder("js", getFileAsReader("node_modules/@openhab-globals.js"), "@openhab-globals.js")
.cached(true).build();
} catch (IOException e) {
throw new RuntimeException("Failed to load @openhab-globals.js", e);
throw new IllegalStateException("Failed to load @openhab-globals.js", e);
}
}
private static final String OPENHAB_JS_INJECTION_CODE = "Object.assign(this, require('openhab'));";
@ -134,7 +134,7 @@ public class OpenhabGraalJSScriptEngine
private final JSRuntimeFeatures jsRuntimeFeatures;
// these fields start as null because they are populated on first use
private String engineIdentifier;
private @Nullable String engineIdentifier;
private @Nullable Consumer<String> scriptDependencyListener;
private boolean initialized = false;
@ -239,10 +239,11 @@ public class OpenhabGraalJSScriptEngine
}
// these are added post-construction, so we need to fetch them late
this.engineIdentifier = (String) ctx.getAttribute(CONTEXT_KEY_ENGINE_IDENTIFIER);
if (this.engineIdentifier == null) {
String localEngineIdentifier = (String) ctx.getAttribute(CONTEXT_KEY_ENGINE_IDENTIFIER);
if (localEngineIdentifier == null) {
throw new IllegalStateException("Failed to retrieve engine identifier from engine bindings");
}
engineIdentifier = localEngineIdentifier;
ScriptExtensionAccessor scriptExtensionAccessor = (ScriptExtensionAccessor) ctx
.getAttribute(CONTEXT_KEY_EXTENSION_ACCESSOR);
@ -262,7 +263,7 @@ public class OpenhabGraalJSScriptEngine
// Wrap the "require" function to also allow loading modules from the ScriptExtensionModuleProvider
Function<Function<Object[], Object>, Function<String, Object>> wrapRequireFn = originalRequireFn -> moduleName -> scriptExtensionModuleProvider
.locatorFor(delegate.getPolyglotContext(), engineIdentifier).locateModule(moduleName)
.locatorFor(delegate.getPolyglotContext(), localEngineIdentifier).locateModule(moduleName)
.map(m -> (Object) m).orElseGet(() -> originalRequireFn.apply(new Object[] { moduleName }));
delegate.getBindings(ScriptContext.ENGINE_SCOPE).put(REQUIRE_WRAPPER_NAME, wrapRequireFn);
delegate.put("require", wrapRequireFn.apply((Function<Object[], Object>) delegate.get("require")));