Automated build process (buster)

hestia_hacker · March 11, 2023, 6:20pm

@HestiaPi I’ve kicked off a new build which will pull in your git commit.

I. Can you confirm that the chip on the back of your LCD has “2046 H1526” printed on it? I’d like to see if I can find some way to reproduce the issue so we can see if there’s a way to get a unified config that works for everyone. It may be unlikely, but I’m still interested in solving it. Failing that, maybe we can make it easy to patch.

II. Can you confirm that you are not seeing the boost countdown like I’m seeing on my pi? I want to make sure I didn’t misundersand and have it be an issue where the countdown occurs but the heat doesn’t shut off after 10 minutes or something like that.

@jrtaylor71’ I am able to reproduce all of your findings. In my experience they do not interfere with the normal operation of the thermostat, but they are areas for improvement.

A. I’ve verified that running kiosk-xinit.sh in the background does not cause any problems. I’ll put this in the next round of changes.

B. I can see turnkey is still running as well. I checked and after the setup process I see that cat /home/pi/scripts/raspberry-pi-turnkey/status.json says the status is “connected”, which is what I would expect. When I traced through the code, I see that this is behaving as designed (but not as expected, IMO). If you look near the bottom of /home/pi/scripts/raspberry-pi-turnkey/startup.py, you’ll see a while True: time.sleep(60000).

My guess is that the author is concerned about startup.sh taking a long time to execute and if startup.py (which is the parent process) exits, it might kill the children. I can patch around that by having startup.sh kill startup.py.

I also see an attempt to reach out to a server run by Google, which is going to fail on any environment where the thermostat is blocked from reaching out to the internet. It’s a completely useless call, as it supposedly determines the IP address, which it then does nothing with. I’ll likely remove that as well.

C. I don’t think we need avahi-daemon, bluetooth, ModemManager, alsa-state, or alsa-restore. I will disable them in my next round of changes.

Thank you both for testing and providing the feedback! I’ll get these things fixed and post back here when I have an updated image ready for the next (and hopefully final) round of testing.

hestia_hacker · March 11, 2023, 6:52pm

Oh, since we’re updating the hestia-touch-openhab repo, I just realized I another request.

Currently I’m replacing the sleep 20 in kiosk-xinit.sh with:

if grep -q "hostapd" /home/pi/scripts/raspberry-pi-turnkey/status.json; then sleep 500; else sleep 21; fi

This is because the LCD screen flips over to the thermostat UI instead of continuing to display the page instructing the user to enter their wifi credentials. This behavior of flipping away from the “enter your creds” after 20 seconds is not new, it was also present in the 1.2-dev image.

In case you’re wondering why I’m replacing the sleep 20 with a sleep 21 for the code path of “we have wifi already set up”, it’s because I want to make sure my script is idempotent. I don’t want to make this replacement multiple times in the event my ansible playbook was run multiple times. If the change is put in the hestia-touch-openhab repo it can remain a sleep 20 and I’ll remove the patch-up process from my image building scripts.

hestia_hacker · March 17, 2023, 5:00pm

New image is available for testing. Setup and boot times are about the same as the previous image.

Changes from the last iteration:

Hot water control fix that was committed to the hestia-touch-openhab repo should be in here
Run kiosk-xinit.sh in the background so rc.local exits
Disabled unnecessary services (avahi-daemon, bluetooth, ModemManager, alsa-state, and alsa-restore)
Turnkey process no longer runs forever when wifi is already set up

Issues that I am still unable to reproduce:
A. LCD touch screen issues. All of my screens work fine. @HestiaPi’s screen does not. @jrtaylor71 Can you tell us what LCD touchscreen you are using and whether it works?
B. Boost timer. It works fine for me. @HestiaPi reports the timer doesn’t count down. @jrtaylor71 Can you test this and confirm it works or let us know is you can reproduce the issue?

jrtaylor71 · March 18, 2023, 3:28pm

I have not had any display problems. Here are the 2 that I am using.

Downloading and testing now.

jrtaylor71 · March 19, 2023, 8:13pm

Basic testing and every looks okay. You can also remove accounts-daemon.service.

Suggestion: Add decimal place to Fahrenheit Temp and Humidity. Allow .5 step for temp differential step.

jrtaylor71 · March 21, 2023, 1:46am

Changes to add decimal to temp and humidity for both C and F.

diff scripts/oneui/js/app.8debb52b.js.orig scripts/oneui/js/app.8debb52b.js
1670d1669
<       if (store.state.info.tempunit === 'C') {
1672,1674d1670
<       } else {
<         store.state.currentTemperature = parseInt(message);
<       }
1683c1679
<       store.state.currentHumidity = parseInt(message);
---
>       store.state.currentHumidity = message;
1686c1682
<       store.state.modes.humidity.setValue = parseInt(message);
---
>       store.state.modes.humidity.setValue = message;

diff scripts/bme280F.py.orig scripts/bme280F.py
167c176
<   print "Temperature : ", int((temperature*1.8)+32), "F"
---
>   print "Temperature : ", round(((temperature*1.8)+32),1), "F"

Remeber to copy the bme280F.py to bme280.py

Derekjon94 · March 21, 2023, 2:12am

If I had a spare Raspberry Pi 3 laying around I would be more than happy to help test, but since those are all out of stock as well I don’t want to do too much testing with my current thermostat setup! If I can scare one up I’ll jump in and help as much as I can!

hestia_hacker · March 21, 2023, 5:23am

If you have an extra micro SD card, you can flash that with this testing image and then just swap SD cards. Give the new one a try and then swap back yo your main system. This is the safest way to test it out.

hestia_hacker · March 21, 2023, 5:27am

Updated image disables the accounts-daemon.service. No other changes.

hestia_hacker · March 21, 2023, 5:33am

If you have a GitHub account and can submit this chsnge as a merge request from the HestiaPi/hestia-touch-openhab repo, I can just rebuild the image and it’ll have this feature.

If not, I can submit your patch at some point. I’m just not sure when I’ll get to it.

HestiaPi · March 21, 2023, 7:18am

I can confirm that the countdown starts showing the, say, 10 min, and stays there. No countdown, no triggered action after the time has elapsed (even though the minutes never go down).

hestia_hacker:

Oh, since we’re updating the hestia-touch-openhab repo, I just realized I another request.

Currently I’m replacing the sleep 20 in kiosk-xinit.sh with:
if grep -q "hostapd" /home/pi/scripts/raspberry-pi-turnkey/status.json; then sleep 500; else sleep 21; fi

Committed just now.

This call is to determine the public IP of HestiaPi to help you setup external access without using OpenHAB’s (free) cloud service. It is then shown on the LCD on the information screen (i icon top right). Ideally it should be easily enabled/disabled from UI with disabled as the default. In terms of privacy/security I doubt it adds any risk.

Downloading… I expect the LCD to behave the same…

I need to check that a little bit more as I don’t think humidity is often expressed with decimals. It sure adds accuracy but also may clutter the UI. Looking around many commercial UIs, I only see decimals in Celsius which are much larger units (20C is 68F while 21C is ~70F) and need more precision. Humidity on the other hand has always been shown as integers. I’d rather leave it as it is unless others need it too.

jrtaylor71 · March 21, 2023, 5:26pm

Yes I have a git hub account. I will look at the source java files and submit a request.

HestiaPi · March 22, 2023, 6:21am

A post was split to a new topic: Decimal points for temperature and humidity

hestia_hacker · March 21, 2023, 10:01pm

I am able to reproduce the issue with the boost being stuck at 10 minutes. It doesn’t happen when the system is set to HVAC, only when it is set to “Generic”. To troubleshoot, I watched openhab.log as I clicked the boost button. This displayed an error message:

2023-03-21 10:23:23.727 [ERROR] [e.automation.internal.RuleEngineImpl] - Failed to execute rule '5635a61b-859b-48d5-82f4-a53f6e1c34d1': Fail to execute action: 2

I went into the PaperUI → Rules and clicked the run icon next to “Boost Looping Timer” and I saw a more detailed error message:

Details of the java.lang.ClassNotFoundException error

2023-03-21 10:24:01.331 [WARN ] [e.automation.internal.RuleEngineImpl] - Fail to execute action: 2
java.lang.RuntimeException: java.lang.ClassNotFoundException: org.eclipse.smarthome.model.script.actions.ScriptExecution cannot be found by com.eclipsesource.jaxrs.publisher_5.3.1.201602281253
        at jdk.nashorn.internal.runtime.ScriptRuntime.apply(ScriptRuntime.java:397) ~[nashorn.jar:?]
        at jdk.nashorn.internal.runtime.Context.evaluateSource(Context.java:1222) ~[nashorn.jar:?]
        at jdk.nashorn.internal.runtime.Context.load(Context.java:839) ~[nashorn.jar:?]
        at jdk.nashorn.internal.objects.Global.load(Global.java:1546) ~[nashorn.jar:?]
        at jdk.nashorn.internal.scripts.Script$125$\^eval\_.:program(<eval>:2) ~[?:?]
        at jdk.nashorn.internal.runtime.ScriptFunctionData.invoke(ScriptFunctionData.java:637) ~[nashorn.jar:?]
        at jdk.nashorn.internal.runtime.ScriptFunction.invoke(ScriptFunction.java:494) ~[nashorn.jar:?]
        at jdk.nashorn.internal.runtime.ScriptRuntime.apply(ScriptRuntime.java:393) ~[nashorn.jar:?]
        at jdk.nashorn.api.scripting.NashornScriptEngine.evalImpl(NashornScriptEngine.java:449) ~[nashorn.jar:?]
        at jdk.nashorn.api.scripting.NashornScriptEngine.evalImpl(NashornScriptEngine.java:406) ~[nashorn.jar:?]
        at jdk.nashorn.api.scripting.NashornScriptEngine.evalImpl(NashornScriptEngine.java:402) ~[nashorn.jar:?]
        at jdk.nashorn.api.scripting.NashornScriptEngine.eval(NashornScriptEngine.java:155) ~[nashorn.jar:?]
        at javax.script.AbstractScriptEngine.eval(AbstractScriptEngine.java:264) ~[?:1.8.0_222]
        at org.openhab.core.automation.module.script.internal.handler.ScriptActionHandler.lambda$0(ScriptActionHandler.java:62) ~[?:?]
        at java.util.Optional.ifPresent(Optional.java:159) ~[?:1.8.0_222]
        at org.openhab.core.automation.module.script.internal.handler.ScriptActionHandler.execute(ScriptActionHandler.java:59) ~[?:?]
        at org.openhab.core.automation.internal.RuleEngineImpl.executeActions(RuleEngineImpl.java:1189) [bundleFile:?]
        at org.openhab.core.automation.internal.RuleEngineImpl.runNow(RuleEngineImpl.java:1037) [bundleFile:?]
        at org.openhab.core.automation.internal.RuleEngineImpl.runNow(RuleEngineImpl.java:1053) [bundleFile:?]
        at org.openhab.core.automation.rest.internal.RuleResource.runNow(RuleResource.java:288) [bundleFile:?]
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:1.8.0_222]
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[?:1.8.0_222]
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:1.8.0_222]
        at java.lang.reflect.Method.invoke(Method.java:498) ~[?:1.8.0_222]
        at org.glassfish.jersey.server.model.internal.ResourceMethodInvocationHandlerFactory$1.invoke(ResourceMethodInvocationHandlerFactory.java:81) [bundleFile:?]
        at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher$1.run(AbstractJavaResourceMethodDispatcher.java:144) [bundleFile:?]
        at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.invoke(AbstractJavaResourceMethodDispatcher.java:161) [bundleFile:?]
        at org.glassfish.jersey.server.model.internal.JavaResourceMethodDispatcherProvider$ResponseOutInvoker.doDispatch(JavaResourceMethodDispatcherProvider.java:160) [bundleFile:?]
        at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.dispatch(AbstractJavaResourceMethodDispatcher.java:99) [bundleFile:?]
        at org.glassfish.jersey.server.model.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:389) [bundleFile:?]
        at org.glassfish.jersey.server.model.ResourceMethodInvoker.apply(ResourceMethodInvoker.java:347) [bundleFile:?]
        at org.glassfish.jersey.server.model.ResourceMethodInvoker.apply(ResourceMethodInvoker.java:102) [bundleFile:?]
        at org.glassfish.jersey.server.ServerRuntime$2.run(ServerRuntime.java:326) [bundleFile:?]
        at org.glassfish.jersey.internal.Errors$1.call(Errors.java:271) [bundleFile:?]
        at org.glassfish.jersey.internal.Errors$1.call(Errors.java:267) [bundleFile:?]
        at org.glassfish.jersey.internal.Errors.process(Errors.java:315) [bundleFile:?]
        at org.glassfish.jersey.internal.Errors.process(Errors.java:297) [bundleFile:?]
        at org.glassfish.jersey.internal.Errors.process(Errors.java:267) [bundleFile:?]
        at org.glassfish.jersey.process.internal.RequestScope.runInScope(RequestScope.java:317) [bundleFile:?]
        at org.glassfish.jersey.server.ServerRuntime.process(ServerRuntime.java:305) [bundleFile:?]
        at org.glassfish.jersey.server.ApplicationHandler.handle(ApplicationHandler.java:1154) [bundleFile:?]
        at org.glassfish.jersey.servlet.WebComponent.serviceImpl(WebComponent.java:473) [bundleFile:?]
        at org.glassfish.jersey.servlet.WebComponent.service(WebComponent.java:427) [bundleFile:?]
        at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:388) [bundleFile:?]
        at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:341) [bundleFile:?]
        at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:228) [bundleFile:?]
        at com.eclipsesource.jaxrs.publisher.internal.ServletContainerBridge.service(ServletContainerBridge.java:76) [bundleFile:?]
        at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:852) [bundleFile:9.4.20.v20190813]
        at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:544) [bundleFile:9.4.20.v20190813]
        at org.ops4j.pax.web.service.jetty.internal.HttpServiceServletHandler.doHandle(HttpServiceServletHandler.java:71) [bundleFile:?]
        at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:143) [bundleFile:9.4.20.v20190813]
        at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:536) [bundleFile:9.4.20.v20190813]
        at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127) [bundleFile:9.4.20.v20190813]
        at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:235) [bundleFile:9.4.20.v20190813]
        at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1581) [bundleFile:9.4.20.v20190813]
        at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:233) [bundleFile:9.4.20.v20190813]
        at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1307) [bundleFile:9.4.20.v20190813]
        at org.ops4j.pax.web.service.jetty.internal.HttpServiceContext.doHandle(HttpServiceContext.java:293) [bundleFile:?]
        at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:188) [bundleFile:9.4.20.v20190813]
        at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:482) [bundleFile:9.4.20.v20190813]
        at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1549) [bundleFile:9.4.20.v20190813]
        at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:186) [bundleFile:9.4.20.v20190813]
        at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1204) [bundleFile:9.4.20.v20190813]
        at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141) [bundleFile:9.4.20.v20190813]
        at org.ops4j.pax.web.service.jetty.internal.JettyServerHandlerCollection.handle(JettyServerHandlerCollection.java:80) [bundleFile:?]
        at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127) [bundleFile:9.4.20.v20190813]
        at org.eclipse.jetty.server.Server.handle(Server.java:494) [bundleFile:9.4.20.v20190813]
        at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:374) [bundleFile:9.4.20.v20190813]
        at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:268) [bundleFile:9.4.20.v20190813]
        at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:311) [bundleFile:9.4.20.v20190813]
        at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:103) [bundleFile:9.4.20.v20190813]
        at org.eclipse.jetty.io.ChannelEndPoint$2.run(ChannelEndPoint.java:117) [bundleFile:9.4.20.v20190813]
        at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.runTask(EatWhatYouKill.java:336) [bundleFile:9.4.20.v20190813]
        at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:313) [bundleFile:9.4.20.v20190813]
        at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.tryProduce(EatWhatYouKill.java:171) [bundleFile:9.4.20.v20190813]
        at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.run(EatWhatYouKill.java:129) [bundleFile:9.4.20.v20190813]
        at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:367) [bundleFile:9.4.20.v20190813]
        at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:782) [bundleFile:9.4.20.v20190813]
        at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:918) [bundleFile:9.4.20.v20190813]
        at java.lang.Thread.run(Thread.java:748) [?:1.8.0_222]
Caused by: java.lang.ClassNotFoundException: org.eclipse.smarthome.model.script.actions.ScriptExecution cannot be found by com.eclipsesource.jaxrs.publisher_5.3.1.201602281253
        at org.eclipse.osgi.internal.loader.BundleLoader.findClassInternal(BundleLoader.java:484) ~[org.eclipse.osgi-3.12.100.jar:?]
        at org.eclipse.osgi.internal.loader.BundleLoader.findClass(BundleLoader.java:395) ~[org.eclipse.osgi-3.12.100.jar:?]
        at org.eclipse.osgi.internal.loader.BundleLoader.findClass(BundleLoader.java:387) ~[org.eclipse.osgi-3.12.100.jar:?]
        at org.eclipse.osgi.internal.loader.ModuleClassLoader.loadClass(ModuleClassLoader.java:150) ~[org.eclipse.osgi-3.12.100.jar:?]
        at java.lang.ClassLoader.loadClass(ClassLoader.java:357) ~[?:1.8.0_222]
        at org.eclipse.osgi.internal.framework.EquinoxBundle.loadClass(EquinoxBundle.java:564) ~[org.eclipse.osgi-3.12.100.jar:?]
        at org.ops4j.pax.swissbox.core.BundleClassLoader.findClass(BundleClassLoader.java:176) ~[bundleFile:?]
        at java.lang.ClassLoader.loadClass(ClassLoader.java:424) ~[?:1.8.0_222]
        at org.ops4j.pax.swissbox.core.BundleClassLoader.loadClass(BundleClassLoader.java:192) ~[bundleFile:?]
        at java.lang.ClassLoader.loadClass(ClassLoader.java:357) ~[?:1.8.0_222]
        at java.lang.Class.forName0(Native Method) ~[?:1.8.0_222]
        at java.lang.Class.forName(Class.java:348) ~[?:1.8.0_222]
        at jdk.nashorn.internal.runtime.Context.findClass(Context.java:1051) ~[nashorn.jar:?]
        at jdk.nashorn.internal.objects.NativeJava.simpleType(NativeJava.java:498) ~[nashorn.jar:?]
        at jdk.nashorn.internal.objects.NativeJava.type(NativeJava.java:322) ~[nashorn.jar:?]
        at jdk.nashorn.internal.objects.NativeJava.type(NativeJava.java:314) ~[nashorn.jar:?]
        at jdk.nashorn.internal.objects.NativeJava.type(NativeJava.java:310) ~[nashorn.jar:?]
        at jdk.nashorn.internal.scripts.Script$Recompilation$127$34A$utils.L:3(/etc/openhab2/automation/lib/hestia/utils.js:31) ~[?:?]
        at jdk.nashorn.internal.scripts.Script$126$utils.:program(/etc/openhab2/automation/lib/hestia/utils.js:3) ~[?:?]
        at jdk.nashorn.internal.runtime.ScriptFunctionData.invoke(ScriptFunctionData.java:637) ~[nashorn.jar:?]
        at jdk.nashorn.internal.runtime.ScriptFunction.invoke(ScriptFunction.java:494) ~[nashorn.jar:?]
        at jdk.nashorn.internal.runtime.ScriptRuntime.apply(ScriptRuntime.java:393) ~[nashorn.jar:?]
        ... 79 more

This looks like it might be a bigger issue than just the boost not working as expected. It’s also worth noting that this is the same problem as the Can’t stop boosting thread which was experienced on the official 1.2-dev image. We never really got to a root cause or resolved that one, but rather just worked around it. I just restored the stock 1.2-dev image, which does not have this issue. I’ll try to get to the bottom of this issue this time around.

Before going any further, I switched back into HVAC mode to run these same tests and see if the error message and stacktrace also appears when the timer is working properly. If so, then they can likely be ignored. It turned out, the error & stracktrace did not appear.

Logs when boost is working properly

2023-03-21 10:47:00.544 [INFO ] [.eclipse.smarthome.model.script.mode] - Heating mode changed from OFF to Boost
2023-03-21 10:47:02.439 [INFO ] [eclipse.smarthome.model.script.boost] - Starting Heating boost
2023-03-21 10:47:03.699 [INFO ] [eclipse.smarthome.model.script.boost] - 10 minutes remaining on boost for Heating
2023-03-21 10:47:10.849 [INFO ] [marthome.model.script.heatingcooling] - TURN ON Heating: heating delta is 14 cooling delta is -18 hysteresis is 1
2023-03-21 10:47:14.353 [INFO ] [lipse.smarthome.model.script.heating] - Turning ON the heater: curr temp = 56 setpoint = 70 mode = Boost
2023-03-21 10:47:25.839 [INFO ] [.eclipse.smarthome.model.script.mode] - Fan mode changed from OFF to AUTO
2023-03-21 10:47:28.890 [INFO ] [g.eclipse.smarthome.model.script.fan] - FanMode is AUTO
2023-03-21 10:47:31.938 [INFO ] [g.eclipse.smarthome.model.script.fan] - Turning ON the fan: fan mode = AUTO
2023-03-21 10:47:33.563 [INFO ] [.eclipse.smarthome.model.script.pins] - Commanding Pin12 to ON for HeatingPin
2023-03-21 10:47:33.899 [INFO ] [.eclipse.smarthome.model.script.pins] - FanPin commanded to ON
2023-03-21 10:47:34.270 [INFO ] [.eclipse.smarthome.model.script.pins] - Commanding Pin18 to ON for FanPin
2023-03-21 10:48:04.858 [INFO ] [eclipse.smarthome.model.script.boost] - 9 minutes remaining on boost for Heating

I switched back into Generic mode and did a few hours worth of debugging. I didn’t solve this one, but here’s a summary of what I learned:

“Hot Water Control” and “TempUnit changed” rules had this same stacktrace when run, but “Process Sensor Changes” did not. I didn’t see any pattern in which rules raised an exception and which ones did not
I found that if I load util.js in the Boost Looping Timer rule, I get the exception and if I don’t load utils.js, I don’t. Digging further, the two lines that will cause this exception are Java.type("org.eclipse.smarthome.model.script.actions.ScriptExecution") and Java.type("org.eclipse.smarthome.io.net.exec.ExecUtil"). However, Java.type("org.slf4j.LoggerFactory") did not cause any exception.
I found two ScriptExecution classes online. The one our code is trying to load is in the (now archived) smarthome project. The other is in OpenHAB. They look similar, but they are not the same. Calling Java.type("org.openhab.core.io.net.exec.ExecUtil") also raised a ClassDefNotFound exception.
I noticed that jaxrs seems to be the thing trying to load ExecUtil (from the error: org.eclipse.smarthome.io.net.exec.ExecUtil cannot be found by com.eclipsesource.jaxrs.publisher_5.3.1.201602281253). I found the Maven page about this version of this library. Going to the project HomePage shows us this project is also archived and no longer maintained.
Running dpkg -L openhab2 shows some config related to “smarthome”, but no jar file. The jaxrs v5.3.1 jar file does appear in this list. /usr/share/openhab2/runtime/system/com/eclipsesource/jaxrs/publisher/5.3.1/publisher-5.3.1.jar. I don’t see any jar files that look like they would have the Eclipse of version of ExecUtil, but I did find /usr/share/openhab2/runtime/system/org/openhab/core/bundles/org.openhab.core.io.net/2.5.0/org.openhab.core.io.net-2.5.0.jar which I would expect to contain the OpenHAB version of ExecUtil.

The glaring questions remain: why can the Boost Looping Timer rule find this Class in the US mode (HVAC), but not in the EU mode (Generic)? and why don’t all rules have this issue in EU mode?

I’ll keep plugging away and see if I can make any progress at answering these.

As for the LCD screen, I’m perplexed. Our screens look identical as far as I can tell. It doesn’t make any sense why they are behaving differently. Since we currently have two people reporting that it’s working as expected, I think what is in the image now should be the default, but we should have a single command that anyone having issues can run to swap over to the alternative configuration.

Maybe call it something like ./fix_LCD.sh, put it in the scripts directory and make the content something like the following?

echo 'Section "InputClass"
        Identifier      "calibration"
        MatchProduct    "ADS7846 Touchscreen"
        Option  "Calibration"   "254 3910 3716 1476"
        Option  "SwapAxes"      "1"
        Option "InvertX" "1"
        Option "InvertY" "1"
EndSection' | sudo tee /etc/X11/xorg.conf.d/99-calibration.conf > /dev/null
sudo shutdown -r now

HestiaPi · March 22, 2023, 6:16am

Rich @rlkoshak do you have any clues as to where to look at? Boost (rule Boost Looping Timer) works fine on HVAC mode but not on Generic (EU) and stays on the initial time indefinitely.

Will try and troubleshoot a bit more on this but till we actually manufacture/sell devices, users will buy “whatever” they can source locally/from China and minor tweaks like these will always be needed, so I’m not sure if this will end up being only 2 options like it is now or we will simply suggest a method (like the calibration tool) for users to find their needed settings. Also CPU is a little high and I don’t know if this would affect anything…
So far the latest image, is looking good apart from my previous issues 1 & 3 mentioned.

hestia_hacker · March 22, 2023, 1:49pm

I have added enough debug statements to see in the logs that in some rules, the ScriptExecution and ExecUtil classes are getting loaded just fine when in EU mode. I believe it is the Process Sensor Changes rule that is firing frequently which is outputting these log messages, but whatever rule it is, it’s clear that it’s working properly.

I believe part of my issue in troubleshooting is that the context in which rule execution happens makes a difference. Pressing the “run” button is not the same as an event being triggered by something in the “When…” clause.

To be clear: I’m saying that it is possible that the ClassNotFound issue only occurs when attempting to manually run the test. If so, that’s incredibly annoying, but it is not the cause of the boost timer not working.

My debugging continues, just wanted to post an update so nobody goes down rabbit holes on account of the fuzzy picture of what’s going on that I painted in my previous post.

rlkoshak · March 22, 2023, 4:59pm

Note, it’s easier to read stack traces and logs when code fences are used.

```
code goes here
```

That will preserve the spacing and keep the text contained.

Just to confirm, this is still running on OH 2, correct? If it’s OH 3 than this is another breaking change that I forgot about when listing the breaking changes previously. One of the primary drivers of OH 3 in the first place was the fact that Eclipse Smarthome was essentially closed down and all that stuff was brought back over to be part of openHAB core. That means everywhere where you see “org.eclipse.smarthome” in a rule it needs to be replaced with “org.openhab”. Beyond that everything else is the same. So org.eclipse.smarthome.model.script.actions.ScriptExecution becomes org.openhab.model.script.actions.ScriptExecution

If this is OH 2 still (which seems to be the case since you mentioned PaperUI) I can’t imagine what would cause these to fail loading sometimes but not all the time. Those Java.type lines of code are basically importing Java Classes from openHAB itself and they are definitely in the org.eclipse.smarthome package for OH 2. The fact that OH is up and running at all means those Classes exist and there shouldn’t be anything preventing their import. There doesn’t appear to be a typo on the imports.

This isn’t surprising really. IIRC the “Process Sensor Changes” is mainly a traffic cop, deciding what to do based on the change and the current state. It’s the “Control” rules that actually take action.

I can’t remember why I used ExecUtil instead of the executeCommandLine Action. there had to be a good reason but it’s been years. But what ever is going on it’s the same reason ScriptExecution is failing.

Yes, everything moved to the org.openhab but only for OH 3. In OH 2 it’s still in the org.eclipse.smarthome packages. But ExecUtil is sort of an internal class so it may have moved or changed between OH 2 and OH 3 beyond just moving packages. That code should probably be changed to use executeCommandLine instead.

OH 2.5 is approaching 2.5 years old at this point so a lot of things it depends upon will be no longer maintained. However, the installation package comes with all the libraries it depends on so that shouldn’t matter. But the root problem is that for some reason the rules engine simply cannot find classes that are part of OH itself which is weird in the extreme.

I’m not sure if dpkg looks inside .kar files. That’s where you’d find it, inside openhab.kar.

Indeed that’s the question. It’s the same code for the most part. I don’t recall any reports of a problem like this reported on the OH forum and I never experienced it myself. Later today I will try some tests and see if I can reproduce but it’s looking like something outside of our control buried deep in OH code which means upgrading is going to be the only way to fix it.

Note that manually running a rule does indeed work differently. Many of the rules require information from the Item that triggered it. So it’s not always possible to trigger a rule manually in any meaningful way. It differs on a rule by rule basis.

But that should not cause those Java.type lines to fail. Those should work no matter how the rule is executed.

hestia_hacker · March 22, 2023, 6:18pm

Yeah, this is still OpenHAB 2.

Good news: It’s possible to fix this issue. I have done so on my test system.

Bad news: I’m not sure what I changed to make it work, and now I can’t reproduce the issue.

I was keeping notes here, which I’ll post below so I (or others) can pick up where I’m leaving off in case we are able to reproduce this again later. The short version, is that I did a lot of debugging and I was understanding how all these rules work when I uncommented the code for the Boost Looping Timer rule and it started working. So flashed the latest buster image (Job #4861 in pipeline #1524), set up wifi, switched it to Generic mode, and the boost timer works just fine. I don’t see any errors in the logs either.

If anyone can repro this issue with the latest image, if you can check /var/log/openhab2/openhab.log to see what’s going on and post all the output from the time you press the boost button, it could be helpful in allowing me to get to the bottom of this.

Debugging notes

The Boost Looping Timer rule only fires when one of the following items changes: Heating/Cooling/Hot Water/Humidity boost time remaining.

The Boost rule will update the previous mode, turn on the check, and set the boost time. For example, when boosting the heat, the HeatingPrevMode is set without triggering any other rules. HeatingCheck is set to “ON” (triggering any updates that are set to happen when the heat is turned on). And the HeatingRemBoostTime item is updated to items[“HeatingBoostTime”], which is 10 (minutes).

Updating HeatingCheck should cause the Heating/Cooling Check rule to fire, which it does. This rule correctly determines that we’re in boost mode and sets HeatingCtl to “ON”.

The Heat Control rule then fires on account of the HeatingCtl command being sent. It turns the main switch on if it wasn’t already on. This is where the functionality differs in the US mode versus the EU mode. In the EU mode, it turns the heat on (HeatingPin = ON), but in US mode it turns the Fan off and then ten seconds later it’ll turn on the heat (HeatingPin = ON) and set the fan to auto. Finally, in either case, it sets HeatingMode to “Boost” (with a comment that this updates the LCD screen).

Turning the heat on will trigger the Map Pin to GPIO rule, which uses the SystemType (US or EU) to get the pin mapping. This ends up turning ON Pin23. I can’t find the code that executes when “Pin23” is sent the command of “ON”, but as far as I understand the heat is turning on, so I am not diving deeper into this.

Updating HeatingRemBoostTime, which is the last thing the Boost rule does, should trigger “Boost Loop Timer”.

The BoostLoopTimer rule should create a timer that fire in 60 seconds. The action to occur when the timer fires is to decrement the boost time by 1. This is the part that is not happening when in EU mode.

Debugging rules

Here are some snippets of JS that can be put into the rules to better understand what’s happening at runtime. These should be entered in the Paper UI → Rules → Click the rule to edit → Click the gear under the “then…” clause → read the code and replace only the appropriate parts (these are not the entire script, just snippets).

Boost Looping Timer:

var OPENHAB_CONF = Java.type('java.lang.System').getenv('OPENHAB_CONF');

// BEGIN debugging info
var LOG_ROOT = "";
var logger = Java.type("org.slf4j.LoggerFactory").getLogger(LOG_ROOT+"boost");
logger.info("Executing the boost loop timer now");
// END debugging info

load(OPENHAB_CONF + '/automation/lib/hestia/utils.js');
// BEGIN debugging info
logger.info("Loaded utils.js");
// END debugging info

var logName = "boost";

var mode = event.itemName.replace("RemBoostTime", "");

rlkoshak · March 22, 2023, 7:49pm

It’s “Map Pin to GPIO” which takes the name of the Item that triggered the rule and sends a command to the Item linked to the GPIO pin through the GPIO binding.

I just had a chance to look at the rules a little. My goodness I forgot how far we’ve come in OH 3 when it comes to UI rules and the helper functions.

Which part? The rule isn’t triggering at all? The timer isn’t being created, or the boost time isn’t being decremented?

Or is that still to be determined?

Looking at the code for Boost Looping Timer, it doesn’t even know whether it’s in US or EU mode so it’s weird that that makes a difference. The only thing I can think of is if perhaps in EU mode, the items[mode+"BoostTimer"] Item (e.g. HeatingBoostTimer) isn’t being commanded to ON so the timer isn’t created, or maybe it’s already ON because of a restoreOnStartup or something?

But this is the same rule that commands the BoostTimer Item in the first place, but it’s something to check. What’s the state of the BoostTimer Item when the BoostLoopTimer Rule triggers the first time in EU mode? If it’s already ON before the rule gets called the first time, it will never set the looping timer and will never return to OFF, breaking the looping timer entirely.

If that’s the case, the quick and easy fix is to simply update the BoostTimer Item to OFF. The long term fix is going to be complicated to capture this error case and frankly, when/if we move to OH 3 I’ll volunteer to rewrite the rules and hopefully simplify them significantly. There is a lot of code here that is only here to avoid duplicating a lot of code and to deal with limitations in OH 2 and ECMAScript 5.1 which do not exist in OH 3 and ECMAScript 2021 with the helper library.

hestia_hacker · March 24, 2023, 3:23am

I’ve switched back and forth between US and EU with this latest build (pipeline 1524), and I can’t reproduce the issue now.

Thinking it may be some silent, intermittent failure in the build process, I flashed the previous buster testing image (pipeline 1520) onto another card, but I was also unable to reproduce the issue there either.

I think the loop rule was being triggered once, and only once, that being why the timer was set to 10 minutes (first run of the rule) but never decremented (because the rule wasn’t repeating, for reasons unknown).

The only thing that comes to mind with an intermittent failure like this is that it’s happening when there is memory pressure, hitting I/O limits, CPU load causing interrupts not to fire properly, or something along these lines. But I can’t even reproduce the issue immediately after boot, which is when the system is under the heaviest load (initialization routines running, caches having not been filled, etc.).

If I can just get it to happen again, I understand the rules well enough now to do much better troubleshooting.