demus/openhab-addons
1
0
Fork 0
mirror of https://github.com/openhab/openhab-addons.git synced 2025-01-10 15:11:59 +01:00
Code Issues Packages Projects Releases Wiki Activity

[jsscripting] Fix multi-threading issues in UI-based scripts (#17510)

Browse Source 
* [jsscripting] Make logger non-static
* [jsscripting] Log lock acquisition and release
* [jsscripting] Implement Lock in DebuggingGraalScriptEngine so openHAB Core can lock and unlock when executing the pre-compiled script
* [jsscripting] Improve comments in ThreadsafeTimers
* [jsscripting] Add a short sleep after unlocking the lock to fix multi-threading issues with UI-based scripts

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-10-24 19:04:34 +02:00 committed by Ciprian Pascu
parent 81ff220f6c
commit cfa65c68ee
3 changed files with 75 additions and 14 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

34
bundles/org.openhab.automation.jsscripting/src/main/java/org/openhab/automation/jsscripting/internal/DebuggingGraalScriptEngine.java
View File

@ -15,6 +15,8 @@ package org.openhab.automation.jsscripting.internal;
import static org.openhab.core.automation.module.script.ScriptTransformationService.OPENHAB_TRANSFORMATION_SCRIPT;
import java.util.Arrays;
import java.util.concurrent.TimeUnit;
import java.util.concurrent.locks.Condition;
import java.util.concurrent.locks.Lock;
import java.util.stream.Collectors;
@ -36,7 +38,7 @@ import org.slf4j.LoggerFactory;
* @author Florian Hotze - Improve logger name, Fix memory leak caused by exception logging
*/
class DebuggingGraalScriptEngine<T extends ScriptEngine & Invocable & AutoCloseable & Compilable & Lock>
extends InvocationInterceptingScriptEngineWithInvocableAndCompilableAndAutoCloseable<T> {
extends InvocationInterceptingScriptEngineWithInvocableAndCompilableAndAutoCloseable<T> implements Lock {
private static final int STACK_TRACE_LENGTH = 5;
@ -111,4 +113,34 @@ class DebuggingGraalScriptEngine<T extends ScriptEngine & Invocable & AutoClosea
logger = LoggerFactory.getLogger("org.openhab.automation.script.javascript." + identifier);
}
@Override
public void lock() {
delegate.lock();
}
@Override
public void lockInterruptibly() throws InterruptedException {
delegate.lockInterruptibly();
}
@Override
public boolean tryLock() {
return delegate.tryLock();
}
@Override
public boolean tryLock(long l, TimeUnit timeUnit) throws InterruptedException {
return delegate.tryLock(l, timeUnit);
}
@Override
public void unlock() {
delegate.unlock();
}
@Override
public Condition newCondition() {
return delegate.newCondition();
}
}

39
bundles/org.openhab.automation.jsscripting/src/main/java/org/openhab/automation/jsscripting/internal/OpenhabGraalJSScriptEngine.java
View File

@ -74,7 +74,6 @@ public class OpenhabGraalJSScriptEngine
extends InvocationInterceptingScriptEngineWithInvocableAndCompilableAndAutoCloseable<GraalJSScriptEngine>
implements Lock {
private static final Logger LOGGER = LoggerFactory.getLogger(OpenhabGraalJSScriptEngine.class);
private static final Source GLOBAL_SOURCE;
static {
try {
@ -132,6 +131,8 @@ public class OpenhabGraalJSScriptEngine
v -> v.getMember("rawQtyType").as(QuantityType.class), HostAccess.TargetMappingPrecedence.LOW)
.build();
private final Logger logger = LoggerFactory.getLogger(OpenhabGraalJSScriptEngine.class);
/** {@link Lock} synchronization of multi-thread access */
private final Lock lock = new ReentrantLock();
private final JSRuntimeFeatures jsRuntimeFeatures;
@ -155,8 +156,6 @@ public class OpenhabGraalJSScriptEngine
this.injectionCachingEnabled = injectionCachingEnabled;
this.jsRuntimeFeatures = jsScriptServiceUtil.getJSRuntimeFeatures(lock);
LOGGER.debug("Initializing GraalJS script engine...");
delegate = GraalJSScriptEngine.create(ENGINE,
Context.newBuilder("js").allowExperimentalOptions(true).allowAllAccess(true)
.allowHostAccess(HOST_ACCESS)
@ -230,7 +229,10 @@ public class OpenhabGraalJSScriptEngine
protected void beforeInvocation() {
super.beforeInvocation();
logger.debug("Initializing GraalJS script engine...");
lock.lock();
logger.debug("Lock acquired before invocation.");
if (initialized) {
return;
@ -257,7 +259,7 @@ public class OpenhabGraalJSScriptEngine
Consumer<String> localScriptDependencyListener = (Consumer<String>) ctx
.getAttribute(CONTEXT_KEY_DEPENDENCY_LISTENER);
if (localScriptDependencyListener == null) {
LOGGER.warn(
logger.warn(
"Failed to retrieve script script dependency listener from engine bindings. Script dependency tracking will be disabled.");
}
scriptDependencyListener = localScriptDependencyListener;
@ -274,33 +276,41 @@ public class OpenhabGraalJSScriptEngine
// Injections into the JS runtime
jsRuntimeFeatures.getFeatures().forEach((key, obj) -> {
LOGGER.debug("Injecting {} into the JS runtime...", key);
logger.debug("Injecting {} into the JS runtime...", key);
delegate.put(key, obj);
});
initialized = true;
try {
LOGGER.debug("Evaluating cached global script...");
logger.debug("Evaluating cached global script...");
delegate.getPolyglotContext().eval(GLOBAL_SOURCE);
if (this.injectionEnabled) {
if (this.injectionCachingEnabled) {
LOGGER.debug("Evaluating cached openhab-js injection...");
logger.debug("Evaluating cached openhab-js injection...");
delegate.getPolyglotContext().eval(OPENHAB_JS_SOURCE);
} else {
LOGGER.debug("Evaluating openhab-js injection from the file system...");
logger.debug("Evaluating openhab-js injection from the file system...");
eval(OPENHAB_JS_INJECTION_CODE);
}
}
LOGGER.debug("Successfully initialized GraalJS script engine.");
logger.debug("Successfully initialized GraalJS script engine.");
} catch (ScriptException e) {
LOGGER.error("Could not inject global script", e);
logger.error("Could not inject global script", e);
}
}
@Override
protected Object afterInvocation(Object obj) {
lock.unlock();
logger.debug("Lock released after invocation.");
// Fixes illegal multi-thread access requested in UI-based scripts, where the script is running and a timer is
// waiting to acquire the lock.
try {
Thread.sleep(10);
} catch (InterruptedException e) {
throw new RuntimeException("Thread interrupted while sleeping", e);
}
return super.afterInvocation(obj);
}
@ -353,6 +363,7 @@ public class OpenhabGraalJSScriptEngine
@Override
public void lock() {
lock.lock();
logger.debug("Lock acquired.");
}
@Override
@ -373,6 +384,14 @@ public class OpenhabGraalJSScriptEngine
@Override
public void unlock() {
lock.unlock();
logger.debug("Lock released.");
// Fixes illegal multi-thread access requested in UI-based scripts, where the script is running and a timer is
// waiting to acquire the lock.
try {
Thread.sleep(10);
} catch (InterruptedException e) {
throw new RuntimeException("Thread interrupted while sleeping", e);
}
}
@Override

16
bundles/org.openhab.automation.jsscripting/src/main/java/org/openhab/automation/jsscripting/internal/threading/ThreadsafeTimers.java
View File

@ -27,6 +27,8 @@ import org.openhab.core.automation.module.script.action.Timer;
import org.openhab.core.scheduler.ScheduledCompletableFuture;
import org.openhab.core.scheduler.Scheduler;
import org.openhab.core.scheduler.SchedulerTemporalAdjuster;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
/**
* A polyfill implementation of NodeJS timer functionality (<code>setTimeout()</code>, <code>setInterval()</code> and
@ -36,6 +38,8 @@ import org.openhab.core.scheduler.SchedulerTemporalAdjuster;
* Threadsafe reimplementation of the timer creation methods of {@link ScriptExecution}
*/
public class ThreadsafeTimers {
private final Logger logger = LoggerFactory.getLogger(ThreadsafeTimers.class);
private final Lock lock;
private final Scheduler scheduler;
private final ScriptExecution scriptExecution;
@ -81,11 +85,13 @@ public class ThreadsafeTimers {
public Timer createTimer(@Nullable String identifier, ZonedDateTime instant, Runnable closure) {
return scriptExecution.createTimer(identifier, instant, () -> {
lock.lock();
logger.debug("Lock acquired before timer execution");
try {
closure.run();
} finally { // Make sure that Lock is unlocked regardless of an exception is thrown or not to avoid
} finally { // Make sure that Lock is unlocked regardless of an exception being thrown or not to avoid
// deadlocks
lock.unlock();
logger.debug("Lock released after timer execution");
}
});
}
@ -103,12 +109,14 @@ public class ThreadsafeTimers {
long id = lastId.incrementAndGet();
ScheduledCompletableFuture<Object> future = scheduler.schedule(() -> {
lock.lock();
logger.debug("Lock acquired before timeout execution");
try {
callback.run();
idSchedulerMapping.remove(id);
} finally { // Make sure that Lock is unlocked regardless of an exception is thrown or not to avoid
} finally { // Make sure that Lock is unlocked regardless of an exception being thrown or not to avoid
// deadlocks
lock.unlock();
logger.debug("Lock released after timeout execution");
}
}, identifier + ".timeout." + id, Instant.now().plusMillis(delay));
idSchedulerMapping.put(id, future);
@ -146,11 +154,13 @@ public class ThreadsafeTimers {
long id = lastId.incrementAndGet();
ScheduledCompletableFuture<Object> future = scheduler.schedule(() -> {
lock.lock();
logger.debug("Lock acquired before interval execution");
try {
callback.run();
} finally { // Make sure that Lock is unlocked regardless of an exception is thrown or not to avoid
} finally { // Make sure that Lock is unlocked regardless of an exception being thrown or not to avoid
// deadlocks
lock.unlock();
logger.debug("Lock released after interval execution");
}
}, identifier + ".interval." + id, new LoopingAdjuster(Duration.ofMillis(delay)));
idSchedulerMapping.put(id, future);