openHAB2, MAX, cannot set temperature / question about various log messages

Add-ons Bindings
, ,
1

Hi all,

although I’m reading in this forum for quite some time, I’m new to actively participate and I hope somebody is able to give me a hint or help me getting my openhab2 installation running properly.

Just a quick summary on what I’m working with:

  • RaspBerryPi 2B+
  • Raspbian Jessie lite
  • openhab2, latest development release (via apt-get)
    – package = standard
    – binding = exec,max,ntp,systeminfo
    – ui = basic,paper
    – persistence = rrd4j
    – transformation = map,regex,scale
  • 2x MAX!Cube with lots of components

I read that one of the objectives set for openhab2 is to encourage use of the UI to configure, however I hesitate to do so for some reasons. As I want to be able to recover/reinstall easily I prefer to have as much as possible preconfigured in configuration files. Therefore, I did not configure anything on the UI at the moment.

What I’ve done so far is to create files for all of my things, items, transforms, a.s.o… While I was struggeling with some issues on syntax in the very beginning I was able to arrange a configuration that is generally working and allowing me to have a look at all the values available from my MAX! components as well as some system information I added.

In a next step I was starting to adjust my sitemap to allow me to set temperature values for the thermostats. There I got stuck now, which is the reason for me asking for your support.

Allthough I see all the things being online in the PaperUI, I can see all the values (like ‘window is open’), my openhab2 lacks some functionality like setting temperatures and I get the following warning messages in my log files.
Some comments to be considered:

  • I understand that these warnings might be related to different issues.

  • I only copied one of each message although they show up multiple times (eg. for all my MAX! components).

  • Serialnumbers, IP-addresses, etc. are not the ‘real’ ones.

    …
    2016-12-14 21:11:44.002 [WARN ] [home.core.thing.binding.ThingFactory] - Could not create channel ‘run’ for thing type ‘exec:command:temp_raspberrypi’, because channel type ‘exec:running’ could not be found.
    …
    2016-12-14 21:11:44.986 [WARN ] [.core.transform.TransformationHelper] - Cannot get service reference for transformation service of type REGEX
    2016-12-14 21:11:45.013 [WARN ] [hab.binding.exec.handler.ExecHandler] - Couldn’t transform response because transformationService of type ‘REGEX’ is unavailable
    …
    2016-12-14 21:11:49.229 [WARN ] [mon.registry.AbstractManagedProvider] - Could not update element with key ntp:ntp:local in ManagedThingProvider, because it does not exists.
    …
    2016-12-14 21:11:50.028 [WARN ] [ome.core.thing.internal.ThingManager] - Attempt to initialize a handler twice for thing ‘max:thermostat:MEQ1234567:LEQ1234567’ at the same time will be ignored.
    …
    2016-12-14 21:11:50.567 [WARN ] [ome.core.thing.internal.ThingManager] - Attempt to initialize a handler twice for thing ‘max:wallthermostat:KEQ1234567:LEQ1234567’ at the same time will be ignored.
    …
    2016-12-14 21:11:50.604 [WARN ] [ome.core.thing.internal.ThingManager] - Attempt to initialize a handler twice for thing ‘max:shuttercontact:KEQ1234567:LEQ1234567’ at the same time will be ignored.
    …
    2016-12-14 21:12:20.086 [WARN ] [mon.registry.AbstractManagedProvider] - Could not update element with key max:bridge:MEQ1234567 in ManagedThingProvider, because it does not exists.
    …
    2016-12-14 21:12:20.090 [WARN ] [.core.thing.binding.BaseThingHandler] - Error while applying configuration changes: ‘IllegalStateException: Could not update thing max:bridge:MEQ1234567. Most likely because it is read-only.’ - reverting configuration changes on thing ‘max:bridge:MEQ1234567’.
    2016-12-14 21:12:20.127 [WARN ] [mon.registry.AbstractManagedProvider] - Could not update element with key max:bridge:MEQ1234567 in ManagedThingProvider, because it does not exists.
    2016-12-14 21:12:20.129 [WARN ] [.core.thing.binding.BaseThingHandler] - Error while applying configuration changes: ‘IllegalStateException: Could not update thing max:bridge:MEQ1234567. Most likely because it is read-only.’ - reverting configuration changes on thing ‘max:bridge:MEQ1234567’.
    2016-12-14 21:12:20.134 [INFO ] [nternal.handler.MaxCubeBridgeHandler] - Error while handling message block: ‘M:00,01,…’ from MAX! Cube lan gateway: 192.168.xxx.xx:java.lang.IllegalStateException: Could not update thing max:bridge:MEQ1234567. Most likely because it is read-only.
    at org.eclipse.smarthome.core.thing.internal.ThingManager$1.thingUpdated(ThingManager.java:224)[103:org.eclipse.smarthome.core.thing:0.9.0.201612091054]
    at org.eclipse.smarthome.core.thing.binding.BaseThingHandler.updateConfiguration(BaseThingHandler.java:478)[103:org.eclipse.smarthome.core.thing:0.9.0.201612091054]
    at org.openhab.binding.max.internal.handler.MaxCubeBridgeHandler.setProperties(MaxCubeBridgeHandler.java:727)[175:org.openhab.binding.max:2.0.0.201612120809]
    at org.openhab.binding.max.internal.handler.MaxCubeBridgeHandler.processMessage(MaxCubeBridgeHandler.java:592)[175:org.openhab.binding.max:2.0.0.201612120809]
    at org.openhab.binding.max.internal.handler.MaxCubeBridgeHandler.readliness(MaxCubeBridgeHandler.java:536)[175:org.openhab.binding.max:2.0.0.201612120809]
    at org.openhab.binding.max.internal.handler.MaxCubeBridgeHandler.sendCubeCommand(MaxCubeBridgeHandler.java:482)[175:org.openhab.binding.max:2.0.0.201612120809]
    at org.openhab.binding.max.internal.handler.MaxCubeBridgeHandler.refreshData(MaxCubeBridgeHandler.java:364)[175:org.openhab.binding.max:2.0.0.201612120809]
    at org.openhab.binding.max.internal.handler.MaxCubeBridgeHandler.access$0(MaxCubeBridgeHandler.java:361)[175:org.openhab.binding.max:2.0.0.201612120809]
    at org.openhab.binding.max.internal.handler.MaxCubeBridgeHandler$1.run(MaxCubeBridgeHandler.java:159)[175:org.openhab.binding.max:2.0.0.201612120809]
    at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)[:1.8.0_65]
    at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)[:1.8.0_65]
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)[:1.8.0_65]
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)[:1.8.0_65]
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)[:1.8.0_65]
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)[:1.8.0_65]
    at java.lang.Thread.run(Thread.java:745)[:1.8.0_65]
    …
    2016-12-14 21:12:20.636 [WARN ] [.core.thing.binding.BaseThingHandler] - Error while applying configuration changes: ‘IllegalStateException: Could not update thing max:shuttercontact:KEQ1234567:LEQ1234567. Most likely because it is read-only.’ - reverting configuration changes on thing ‘max:shuttercontact:KEQ1234567:LEQ1234567’.
    …
    2016-12-14 21:12:20.848 [INFO ] [nternal.handler.MaxCubeBridgeHandler] - Error while handling message block: ‘F:ntp.homematic.com,ntp.homematic.com’ from MAX! Cube lan gateway: 192.168.xxx.xx:java.lang.IllegalStateException: Could not update thing max:bridge:MEQ1234567. Most likely because it is read-only.
    at org.eclipse.smarthome.core.thing.internal.ThingManager$1.thingUpdated(ThingManager.java:224)[103:org.eclipse.smarthome.core.thing:0.9.0.201612091054]
    at org.eclipse.smarthome.core.thing.binding.BaseThingHandler.updateConfiguration(BaseThingHandler.java:478)[103:org.eclipse.smarthome.core.thing:0.9.0.201612091054]
    at org.openhab.binding.max.internal.handler.MaxCubeBridgeHandler.setProperties(MaxCubeBridgeHandler.java:743)[175:org.openhab.binding.max:2.0.0.201612120809]
    at org.openhab.binding.max.internal.handler.MaxCubeBridgeHandler.processMessage(MaxCubeBridgeHandler.java:671)[175:org.openhab.binding.max:2.0.0.201612120809]
    at org.openhab.binding.max.internal.handler.MaxCubeBridgeHandler.readliness(MaxCubeBridgeHandler.java:536)[175:org.openhab.binding.max:2.0.0.201612120809]
    at org.openhab.binding.max.internal.handler.MaxCubeBridgeHandler.sendCubeCommand(MaxCubeBridgeHandler.java:482)[175:org.openhab.binding.max:2.0.0.201612120809]
    at org.openhab.binding.max.internal.handler.MaxCubeBridgeHandler.sendCommands(MaxCubeBridgeHandler.java:347)[175:org.openhab.binding.max:2.0.0.201612120809]
    at org.openhab.binding.max.internal.handler.MaxCubeBridgeHandler.access$1(MaxCubeBridgeHandler.java:334)[175:org.openhab.binding.max:2.0.0.201612120809]
    at org.openhab.binding.max.internal.handler.MaxCubeBridgeHandler$2.run(MaxCubeBridgeHandler.java:167)[175:org.openhab.binding.max:2.0.0.201612120809]
    at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)[:1.8.0_65]
    at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)[:1.8.0_65]
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)[:1.8.0_65]
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)[:1.8.0_65]
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)[:1.8.0_65]
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)[:1.8.0_65]
    at java.lang.Thread.run(Thread.java:745)[:1.8.0_65]
    …

As soon as I change the temperature in basicUI (using ‘setpoint’), I get the following log-message:

...
2016-12-14 22:13:39.571 [INFO ] [ome.core.thing.internal.ThingManager] - Not delegating update '22.5' for item 'Thermostat_UG_Wohnzimmer_SET' to handler for channel 'max:thermostat:KEQ1234567:KEQ1234567:set_temp', because handler is not initialized (thing must be in status UNKNOWN, ONLINE or OFFLINE).
...

Which I don’t understand the reason for, as the thermostat seems to be successfully going online before that timestamp:

...
2016-12-14 21:11:42.997 [ItemChannelLinkAddedEvent ] - Link 'Thermostat_UG_Wohnzimmer_SET-max:thermostat:KEQ1234567:KEQ1234567:set_temp' has been added.
...
2016-12-14 21:11:47.790 [ThingAddedEvent           ] - Thing 'max:thermostat:KEQ1234567:KEQ1234567' has been added.
...
2016-12-14 21:11:47.956 [hingStatusInfoChangedEvent] - 'max:thermostat:KEQ1234567:KEQ1234567' changed from UNINITIALIZED to UNINITIALIZED (HANDLER_MISSING_ERROR)
...
2016-12-14 21:11:49.760 [hingStatusInfoChangedEvent] - 'max:thermostat:KEQ1234567:KEQ1234567' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to INITIALIZING
...
2016-12-14 21:11:50.561 [ThingUpdatedEvent         ] - Thing 'max:thermostat:KEQ1234567:KEQ1234567' has been updated.
...
2016-12-14 21:12:21.473 [hingStatusInfoChangedEvent] - 'max:thermostat:KEQ1234567:KEQ1234567' changed from INITIALIZING to ONLINE
...

=> My focus is on getting my MAX! components running.
However I would greatly appreciate if someone could help me separating if multiple issues cause the logs seen above.
If information is missing, just let me know! I’m happy to add as necessary…

PS: I’ve seen that there was another thread related to one of the warnings above: ‘Frequent warnings in log if max things are configured via textual files’. Unfortunately this thread did not provide a solution other than configuring via UI instead of files.

Best regards
Karsten

2

I can’t help with the MAX stuff. But others have reporter the exec error and the REGEX error may be related to a problem where the regular expression transform isn’t loaded fast enough at startup so the first one or to calls to it fail. Do you see this warning repeatedly in the logs or just after a restart?

3

Thanks for your reply!

Indeed, doublechecking the log files few minutes ago, showed my that those messages (regarding exec and REGEX) occur only directly after startup. My system is running since yesterday evening and no newer events related to these two where logged.

=> First thing sorted out :slight_smile: . Seems to be an issue occuring only at startup… Seems acceptable for me… Thanks!

So, I hope someone can help me with the other stuff?

4

Btw. the log messages mentioned above regarding

“… Attempt to initialize a handler twice for thing …”

look very similiar to the ones discussed in another thread I found recently. The thread is about “Harmony Hub Binding unreliable”.

5

Hi

have seen part of the error before:

Error while applying configuration changes: 'IllegalStateException: Could not update thing max:bridge:MEQ1234567. Most likely because it is read-only.' - reverting configuration changes on thing 'max:bridge:MEQ1234567'.

Can it be that you defined your cube/thermostat things with text file configuration? If possible, can you avoid that, think that is the cause of that error message. Is there a specific reason you want it that way?

Now, that should indeed not prevent the handler from being initalised properly, but that sort of config is not very well tested.
What version are you using? (latest?)

6

Hi Marcel,

indeed, this error message was discussed in another threat already.

The threat was called ‘Frequent warnings in log if max things are configured via textual files’. Unfortunately the thread did not provide a solution other than configuring via UI instead of files.

Although I read that one of the objectives set for openhab2 is to encourage use of the UI to configure, I hesitate to do so for some reasons. As I want to be able to recover/reinstall easily I prefer to have as much as possible preconfigured in configuration files. Therefore, I did not configure anything on the UI at the moment. This way I can easily compare versions of my configuration (eg. with diff), move to another system or purge and reinstall openhab2, without the hassle of clicking through UIs afterwards…

Any idea how to solve these errors?
Might this be related to my issue not being able to set temperatures?

Best regards
Karsten

PS: I’m using the latest release that I can get via apt-get. Since today this is: openhab2-online 2.0.0~20161214201549

7

what you could do is have the discovery discover all of the things (thermostats) for you, but have the remaining part of the configuration (items/sitemaps etc) done in text files. Than you have best of both worlds in my opinion.
As the thermostats are always discovered with the same thing naming, the item/group/etc definitions remain usable

Anyway, now that the config is stored in a json file rather than in the mapdb the issue of being able to restore in another instance is very possible.

So wrt to the update issue… are your thermostats seen as ‘ONLINE’? The error would occur if the thing is not online.
The 2nd not too much tested piece is the 2 cubes in your setup. Now this normally should not cause issues but you do have to be very sharp that the right thermostat is linked to the right cube. (esp with the recent changes that changed the logic how the handlers are started only once the related bridge is started)

Anyway, would you mind to once run it with normal discovery and to eliminate the possible causes, (you can do that in a new/separate instance to avoid it disrupting your regular setup).
If it works with discovery, than would you mind pasting your max! related things & items file(s) to see if anything unusual can be seen

8

Hi Marcel,

I did a fresh install yesterday (apt-get purge and install) of openhab2-online.

Before starting I just copied my addons.cfg into the services folder.
After enabling openhab2 service I saw that it installed the components (ui, bindings, etc.) after a few minutes.

  • In the inbox I ticked just one of the cubes and all components attached to this cube showed up in the inbox immediately.

  • In the inbox I ticked one thermostat for testing.

  • Both things (cube and thermostat) showed up in ‘Configuration | Things’ incl. being online.

  • I created an items-file with just the one thermostat and the channel for set_temp.

Using the ‘Control’ in paperUI I was able to successfully change the temperature and I was also able to see the change being applied to the thermostat (temperature changed on its display)

  • I created a very basic sitemap with a setpoint and was also able to successfully change the temperature.

=> Conclusion was that it is working properly while using paperUI adding the things!

Getting into to more detail, I did another fresh install (apt-get purge and install) of openhab2-online.
I continued in an iterative manner, adding a single line to my configs and directly testing afterwards.

  • Immediately after adding one of the MAX!Cubes to the things file

Bridge max:bridge:MEQ123456 "MAX!Cube (OG/EG)" @ "Ortschaft" [ ipAddress="192.168.xxx.xx", serialNumber="MEQ1234567", exclusive=true ]

the errors came up again. During further testing I found that the error message “…Attempt to initialize a handler twice for thing…” seems not to be related to the max binding only:

2016-12-17 00:22:48.647 [WARN ] [ome.core.thing.internal.ThingManager] - Attempt to initialize a handler twice for thing 'systeminfo:computer:work' at the same time will be ignored.

Continuing today, I found that with the latest development release from tonight (openhab2-online 2.0.0~20161217141859), something changed!
=> With the new release, I did another fresh install and found that it’s working now :slight_smile: …
There are some new log messages I haven’t seen before, so I just wonder what was changed in this release to make it work?

Best regards
Karsten

9

https://hudson.eclipse.org/smarthome/job/SmartHomeDistribution-Stable/159/changes

10

It is probably Allow changing of unmanaged Things (#2629) as that was the main cause of the errors while trying to update the properties.

Hence I think now even with the text config this error won’t happen anymore:
Could not update element with key max:bridge:MEQ1234567 in ManagedThingProvider, because it does not exists.

11

For the moment I’m fine and able to continue to extend my setup.

Thanks for all your quick responses!

Good to know where to find the details about recent changes :slight_smile: …