openhab / openhab-js

openHAB JavaScript Library for JavaScript Scripting Automation
https://www.openhab.org/addons/automation/jsscripting/
Eclipse Public License 2.0
38 stars 31 forks source link

Handling ZonedDateTime with js-joda is extremely slow #395

Open dandjo opened 19 hours ago

dandjo commented 19 hours ago

Expected Behavior

When using ZonedDateTime wrappers via js-joda in ECMAScript (Rules and Scripts), I would expect a similar performance as with all other properties.

Current Behavior

Looping over a large set of states and using js-joda wrappers within the loop, the loop gets extremely slow. Imagine this example:

const logger = log('org.openhab.rule.' + ctx.ruleUID);
// LOCF - last observation carried forward weighting
const midnight = time.toZDT('00:00');
const now = time.toZDT();
const states = items.getItem('some_item').persistence.getAllStatesBetween(midnight, now);
let sum = 0;
let previousTimestamp = midnight;
let previousValue = 0;
for (state of states) {
  const dt = time.Duration.between(previousTimestamp, state.timestamp).toNanos() / 3600000000000;
  sum += previousValue * dt;
  previousTimestamp = state.timestamp;
  previousValue = state.numericState;
}
logger.info(sum + ' (took: ' + time.Duration.between(now, time.toZDT()).toMillis() / 1000 + ' sec)');

The output with a state every 5 seconds leads to more than 14 seconds, whereas the following function costs 0.5 seconds.

const logger = log('org.openhab.rule.' + ctx.ruleUID);
const midnight = time.toZDT('00:00');
const now = time.toZDT();
const avg = items.getItem('some_item').persistence.averageBetween(midnight, now).numericState;
const hours = time.Duration.between(midnight, now).toNanos() / 3600000000000;
const sum = avg * hours;
logger.info(sum + ' (took: ' + time.Duration.between(now, time.toZDT()).toMillis() / 1000 + ' sec)');

Context

I'm trying to get a "Riemann Sum" implementation of measured power. See discussion here:

Arithmetic mean vs average linear/step interpolation

Your Environment

runtimeInfo:
  version: 4.3.0
  buildString: "Build #4362"
locale: en-AT
systemInfo:
  configFolder: /etc/openhab
  userdataFolder: /var/lib/openhab
  logFolder: /var/log/openhab
  javaVersion: 17.0.12
  javaVendor: Ubuntu
  osName: Linux
  osVersion: 6.8.0-1013-raspi
  osArchitecture: aarch64
  availableProcessors: 4
  freeMemory: 83704192
  totalMemory: 605028352
  uptime: 29022
  startLevel: 100
addons:
  - automation-jsscripting
  - binding-enigma2
  - binding-http
  - binding-mielecloud
  - binding-modbus
  - binding-mqtt
  - binding-netatmo
  - binding-tado
  - misc-openhabcloud
  - persistence-influxdb
  - persistence-mapdb
  - transformation-jsonpath
  - transformation-regex
  - ui-basic
clientInfo:
  device:
    ios: false
    android: false
    androidChrome: false
    desktop: true
    iphone: false
    ipod: false
    ipad: false
    edge: false
    ie: false
    firefox: false
    macos: false
    windows: false
    cordova: false
    phonegap: false
    electron: false
    nwjs: false
    webView: false
    webview: false
    standalone: false
    pixelRatio: 1
    prefersColorScheme: dark
  isSecureContext: false
  locationbarVisible: true
  menubarVisible: true
  navigator:
    cookieEnabled: true
    deviceMemory: N/A
    hardwareConcurrency: 12
    language: en-AT
    languages:
      - en-AT
      - en-GB
      - en-US
      - en
      - de
    onLine: true
    platform: Linux x86_64
  screen:
    width: 3440
    height: 1440
    colorDepth: 24
  support:
    touch: false
    pointerEvents: true
    observer: true
    passiveListener: true
    gestures: false
    intersectionObserver: true
  themeOptions:
    dark: dark
    filled: true
    pageTransitionAnimation: default
    bars: light
    homeNavbar: default
    homeBackground: default
    expandableCardAnimation: default
    blocklyRenderer: geras
  userAgent: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like
    Gecko) Chrome/130.0.0.0 Safari/537.36
timestamp: 2024-11-04T16:39:30.697Z
florian-h05 commented 18 hours ago

Does this improve with more executions? I wonder if dynamic optimisation/Graal‘s script compilation improves anything here.

The performance problem is unfortunately nothing new with JS-Joda — it definitely is not the fastest library. If you run into such performance bottlenecks, consider importing the Java counterparts. I doubt we can do anything here on the openhab-js side of things, but it would be nice if you could try the different installation methods of the library:

  1. included in add-on, with injection caching enabled
  2. included in the add-on, without injection caching enabled
  3. manually installed through npm, without injection caching enabled

BTW, you don’t need to create your own logger, just use console log — it automatically uses a logger name based on your rule UID.

dandjo commented 17 hours ago

Injection caching does not change the behavior. It's the call to state.timestamp which costs a lot of time.

florian-h05 commented 15 hours ago

state.timestamp internally uses

https://github.com/openhab/openhab-js/blob/63eb57b92c5a562785817a9636a1527e61e09426/src/time.js#L215-L220

to convert the Java ZDT to a JS-Joda ZDT.

I have benchmarked this method when it was initially added in #267, just repeated the benchmark with 10000 iterations:

Benchmark Script ```js var javaInstantToJsInstant = function (instant) { return time.Instant.ofEpochMilli(instant.toEpochMilli()); } var javaZDTToJsZDT = function (zdt) { const epoch = zdt.toInstant().toEpochMilli(); const instant = time.Instant.ofEpochMilli(epoch); const zone = time.ZoneId.of(zdt.getZone().toString()); return time.ZonedDateTime.ofInstant(instant, zone); } var iters = 10000; var Instant = Java.type('java.time.Instant'); var ins = Instant.now(); console.log('Benchmarking Instant.parse conversion ...') var start = time.Instant.now().toEpochMilli(); for (var i = 0; i < iters; i++) { time.Instant.parse(ins.toString()) } var end = time.Instant.now().toEpochMilli(); console.log('Benchmark finshed, took ' + (end - start) + ' ms') console.log('Benchmarking advanced Instant conversion ...') var start = time.Instant.now().toEpochMilli(); for (var i = 0; i < iters; i++) { javaInstantToJsInstant(ins) } var end = time.Instant.now().toEpochMilli(); console.log('Benchmark finshed, took ' + (end - start) + ' ms') var ZonedDateTime = Java.type('java.time.ZonedDateTime'); var zdt = ZonedDateTime.now(); console.log('Benchmarking ZonedDateTime.parse conversion ...') var start = time.Instant.now().toEpochMilli(); for (var i = 0; i < iters; i++) { time.ZonedDateTime.parse(zdt.toString()) } var end = time.Instant.now().toEpochMilli(); console.log('Benchmark finshed, took ' + (end - start) + ' ms') console.log('Benchmarking advanced ZonedDateTime conversion ...') var start = time.Instant.now().toEpochMilli(); for (var i = 0; i < iters; i++) { javaZDTToJsZDT(zdt) } var end = time.Instant.now().toEpochMilli(); console.log('Benchmark finshed, took ' + (end - start) + ' ms') ```
21:55:08.803 [INFO ] [enhab.automation.script.ui.scratchpad] - Benchmarking Instant.parse conversion ...
21:55:15.110 [INFO ] [enhab.automation.script.ui.scratchpad] - Benchmark finshed, took 6306 ms
21:55:15.111 [INFO ] [enhab.automation.script.ui.scratchpad] - Benchmarking advanced Instant conversion ...
21:55:15.170 [INFO ] [enhab.automation.script.ui.scratchpad] - Benchmark finshed, took 59 ms
21:55:15.171 [INFO ] [enhab.automation.script.ui.scratchpad] - Benchmarking ZonedDateTime.parse conversion ...
21:55:33.975 [INFO ] [enhab.automation.script.ui.scratchpad] - Benchmark finshed, took 18804 ms
21:55:33.977 [INFO ] [enhab.automation.script.ui.scratchpad] - Benchmarking advanced ZonedDateTime conversion ...
21:55:35.151 [INFO ] [enhab.automation.script.ui.scratchpad] - Benchmark finshed, took 1172 ms

Now the question is, how many datapoints do you handle? Anyway, seems like it would be better to work with Instant, and IIRC core supports that since a few days or weeks.

dandjo commented 15 hours ago

I am handling between 80.000 and 160.000 datapoints. As you can read on the linked discussion, I tried with Java imports. This accelerates it by a factor of 14.

florian-h05 commented 15 hours ago

I will add support for getting the instant from the PersistedItem, Java to JS Instant conversion is much faster:

2024-11-04 22:17:48.018 [INFO ] [nhab.automation.script.ui.scratchpad] - Running benchmarks for 1477 states ---------------------------------------------------
2024-11-04 22:17:48.021 [INFO ] [nhab.automation.script.ui.scratchpad] - Benchmarking Java getTimestamp() ...
2024-11-04 22:17:48.038 [INFO ] [nhab.automation.script.ui.scratchpad] - Benchmark finshed, took 17 ms
2024-11-04 22:17:48.043 [INFO ] [nhab.automation.script.ui.scratchpad] - Benchmarking Java getTimestamp() converted to JS-Joda ...
2024-11-04 22:17:49.008 [INFO ] [nhab.automation.script.ui.scratchpad] - Benchmark finshed, took 965 ms
2024-11-04 22:17:49.010 [INFO ] [nhab.automation.script.ui.scratchpad] - Benchmarking Java getInstant() ...
2024-11-04 22:17:49.019 [INFO ] [nhab.automation.script.ui.scratchpad] - Benchmark finshed, took 10 ms
2024-11-04 22:17:49.021 [INFO ] [nhab.automation.script.ui.scratchpad] - Benchmarking Java getInstant() converted to JS-Joda ...
2024-11-04 22:17:49.103 [INFO ] [nhab.automation.script.ui.scratchpad] - Benchmark finshed, took 82 ms

These benchmarks work on the raw Java Persistence Extensions as I need access to the raw Java stuff which is not exposed by the library, as you can see the Java ZDT to JS ZDT conversion is what is time consuming.

dandjo commented 15 hours ago

That's what I suspected, since I read that js-joda has performance issues in general.

So you would offer state.instant in addition to state.timestamp?

dandjo commented 15 hours ago

Here's also a feature request for providing an implementation which would solve my requirement. Maybe think about exposing a persistence function in openhab-js like item.persistence.riemannSumBetween(). This would make such calculations obsolete.

https://github.com/openhab/openhab-core/issues/4439

florian-h05 commented 14 hours ago

openhab-js ItemPersistence class wraps anything that https://www.openhab.org/javadoc/latest/org/openhab/core/persistence/extensions/persistenceextensions provides. So if it gets added there, I will provide a JS wrapper for it.

florian-h05 commented 14 hours ago

396 adds access to Instant, however you need to wait for openHAB 4.3.0 M3 or install a current snapshot to have a new enough core version.

dandjo commented 14 hours ago

I'm using unstable builds. Thanks!