Skip to content
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

Using cache.shared in JavaScript rules can lead to unexpected java.lang.IllegalStateException: Multi threaded access requested by thread #4413

Open
SkyLined opened this issue Oct 9, 2024 · 0 comments
Labels
bug An unexpected problem or unintended behavior of the Core

Comments

@SkyLined
Copy link

SkyLined commented Oct 9, 2024

Expected Behavior

The cache.shared object is documented as allowing any script to access it and "share" information. The documentation comes with an example for cache.private that we can adjust to use cache.shared:

var counter = cache.private.get('counter');
if (counter === null) {
  counter = { times: 0 };
  cache.private.put('counter', counter);
}
console.log('Count', counter.times++);

We would expect the above code to work when used by two rules; every time either of the rules fires, the code is executed, the counter increased and the old value logged.

Current Behavior

cache.shared allows sharing JavaScript objects between two rules. JavaScript code for two different rules will get executed in two different threads. The JavaScript engine used by OpenHAB is not designed to be run in multiple threads simultaneously. The Java code is aware of this and will throw a java.lang.IllegalStateException exception when two threads attempt to access the same JavaScript object. The message associate with this exception is:

Multi threaded access requested by thread Thread[<thread details>] but is not allowed for language(s) js.

This exception unexpectedly stop the execution of the rule using cache.shared and breaks its functionality.

Possible Solution

  • Create a lock that is acquired when JavaScript code accesses a shared object and released once that objects is garbage collected. This prevents two scripts accessing the same object simultaneously but does potentially introduce unexpected delays because scripts may end up waiting for each other to finish execution. If a script never releases a shared object, this might introduce a deadlock: other scripts that attempt to use the object will never be able to do so, as the lock is permanently held.
  • Create a global lock that is acquired before executing any JavaScript code and release the lock after. This makes sure JavaScript code never runs simultaneously in multiple threads. This can also introduce delays in rule execution, as one rule has to wait for another to finish. There is less risk of a deadlock, because if one script never releases a reference to an object, another can still execute and access the object. Only if a script gets into an infinite loop will no other scripts ever be able to execute. That itself seems like a bug in the script that should already be detected and the script terminated.
  • Document this behavior and advise people not to use cache.shared to share information between multiple rules. Obviously, limiting the amount of sharing seriously reduces the usefulness of cache.shared, so this is more of a stop-gap than a solution IMHO.

Steps to Reproduce (for Bugs)

This issue quite easy to reproduce If we create two JavaScript rules that accesses a shared object over a prolonged period and execute them at nearly the same time. In this set-up, the JavaScript code is almost guaranteed to simultaneously attempt to access the object, which triggers the exception. Here's a step by step guide to do this:

  1. Create two rules named Test1 and Test2
  2. Create a trigger for Test1 that fires every second (cron: * * * * * ? *)
  3. Test2 does not need a trigger: you will run it manually later.
  4. Add an action to both Test1 and Test2 to execute the same JavaScript code (found below).
  5. Start Test1 (the cron rule)
  6. Manually run Test2
  7. Check the log for exception reports.

Here is the code used in both rules:

step = "try {...}";
try {
  step = "cache.shared.get(...)"
  var counter = cache.shared.get('counter');
  if (counter === null) {
    counter = { times: 0 };
    step = "cache.shared.put(...)"
    cache.shared.put('counter', counter);
  }
  // repeatedly access the shared object for half a second to create a large time window
  // in which two threads are likely to attempt to access the shared object.
  for (const end_time = new Date().valueOf() + 500; new Date().valueOf() < end_time;) {
    step = "counter.times++";
    counter.times++;
  };
} catch (exception) {
  // Log in which step the exception happened and what event we were passed (timer or manual).
  console.log(`Error in step ${step} for event ${event}`);
  throw exception;
};

Here is an example log output showing the exception after starting the first rule and manually running the second:

2024-10-08 17:12:45.019 [INFO ] [g.openhab.automation.script.ui.Test1] - Error in step cache.shared.get(...) for event Timer 1 triggered.
2024-10-08 17:12:45.022 [ERROR] [internal.handler.ScriptActionHandler] - Script execution of rule with UID 'Test1' failed: java.lang.IllegalStateException: Multi threaded access requested by thread Thread[OH-rule-Test1-1,5,main] but is not allowed for language(s) js.
<snip: exception details and stack follow>

The exception can happen in either Test1 or Test2 depending on timing.

Context

I am creating a queue for audio files to be played. The queue is stored in an Array in cache.shared. Any rule can use Array.push() to add a file to the queue. A dedicated rule uses a timer to repeatedly check if it is time to play the next file and uses Array.shift() to get the next file from the queue and send it to the player. This system breaks when two rules try to add or remove files to/from the queue at the same time. These exceptions make the system unreliable.

Your Environment

  • openHAB 4.2.1 (Release Version)
  • Java 17.0.12
  • OS Linux/6.1.21-v8+ (aarch64) (Raspbian bullseye)
@SkyLined SkyLined added the bug An unexpected problem or unintended behavior of the Core label Oct 9, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug An unexpected problem or unintended behavior of the Core
Projects
None yet
Development

No branches or pull requests

1 participant