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

Handling ZonedDateTime with js-joda is extremely slow #395

Closed
dandjo opened this issue Nov 4, 2024 · 11 comments
Closed

Handling ZonedDateTime with js-joda is extremely slow #395

dandjo opened this issue Nov 4, 2024 · 11 comments
Labels
bug Something isn't working

Comments

@dandjo
Copy link

dandjo commented Nov 4, 2024

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
@dandjo dandjo added the bug Something isn't working label Nov 4, 2024
@florian-h05
Copy link
Contributor

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
Copy link
Author

dandjo commented Nov 4, 2024

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

@florian-h05
Copy link
Contributor

state.timestamp internally uses

openhab-js/src/time.js

Lines 215 to 220 in 63eb57b

function javaZDTToJsZDT (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);
}

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
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
Copy link
Author

dandjo commented Nov 4, 2024

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
Copy link
Contributor

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
Copy link
Author

dandjo commented Nov 4, 2024

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
Copy link
Author

dandjo commented Nov 4, 2024

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.

openhab/openhab-core#4439

@florian-h05
Copy link
Contributor

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
Copy link
Contributor

#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
Copy link
Author

dandjo commented Nov 4, 2024

I'm using unstable builds. Thanks!

@florian-h05
Copy link
Contributor

I just published version 5.8.0, which includes PersistedState::instant, will update the add-on soon to use that version.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Something isn't working
Projects
None yet
Development

No branches or pull requests

2 participants