Log Viewer error after migration to OH4 blocky/MQTT

Hi,
I just migrated from OH3 to 4 and got a strange error coming from one of my rules.
I ‘smartened’ my garage doors using an esp8266 giving an impulse to the motor triggering an action. Since it’s not yet smart enough knowing what’s triggered, there is just one command to the esp. Since OH doesn’t allow sending the same command again and again, I was using a rule to reset the command state back to ‘idle’.
It still does that, but seems like OH is shortly freezing and I get this log:

2023-08-18 13:12:26.277 [ERROR] [nal.common.AbstractInvocationHandler] - An error occurred while calling method 'ThingHandler.handleCommand()' on 'org.openhab.binding.mqtt.generic.internal.handler.GenericMQTTThingHandler@ef3f8e': Value idle not within range
java.lang.IllegalArgumentException: Value idle not within range
	at org.openhab.binding.mqtt.generic.values.TextValue.parseCommand(TextValue.java:67) ~[?:?]
	at org.openhab.binding.mqtt.generic.values.TextValue.parseCommand(TextValue.java:1) ~[?:?]
	at org.openhab.binding.mqtt.generic.ChannelState.publishValue(ChannelState.java:363) ~[?:?]
	at org.openhab.binding.mqtt.generic.AbstractMQTTThingHandler.handleCommand(AbstractMQTTThingHandler.java:152) ~[?:?]
	at jdk.internal.reflect.GeneratedMethodAccessor55.invoke(Unknown Source) ~[?:?]
	at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?]
	at java.lang.reflect.Method.invoke(Method.java:568) ~[?:?]
	at org.openhab.core.internal.common.AbstractInvocationHandler.invokeDirect(AbstractInvocationHandler.java:147) ~[?:?]
	at org.openhab.core.internal.common.InvocationHandlerSync.invoke(InvocationHandlerSync.java:59) ~[?:?]
	at jdk.proxy25828.$Proxy25944.handleCommand(Unknown Source) ~[?:?]
	at org.openhab.core.thing.internal.profiles.ProfileCallbackImpl.handleCommand(ProfileCallbackImpl.java:85) ~[?:?]
	at org.openhab.core.thing.internal.profiles.SystemDefaultProfile.onCommandFromItem(SystemDefaultProfile.java:48) ~[?:?]
	at jdk.internal.reflect.GeneratedMethodAccessor288.invoke(Unknown Source) ~[?:?]
	at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?]
	at java.lang.reflect.Method.invoke(Method.java:568) ~[?:?]
	at org.openhab.core.internal.common.AbstractInvocationHandler.invokeDirect(AbstractInvocationHandler.java:147) ~[?:?]
	at org.openhab.core.internal.common.Invocation.call(Invocation.java:52) ~[?:?]
	at java.util.concurrent.FutureTask.run(FutureTask.java:264) ~[?:?]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) ~[?:?]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) ~[?:?]
	at java.lang.Thread.run(Thread.java:833) ~[?:?]
2023-08-18 13:12:26.291 [ERROR] [nal.common.AbstractInvocationHandler] - An error occurred while calling method 'ThingHandler.handleCommand()' on 'org.openhab.binding.mqtt.generic.internal.handler.GenericMQTTThingHandler@ef3f8e': Value idle not within range
java.lang.IllegalArgumentException: Value idle not within range
	at org.openhab.binding.mqtt.generic.values.TextValue.parseCommand(TextValue.java:67) ~[?:?]
	at org.openhab.binding.mqtt.generic.values.TextValue.parseCommand(TextValue.java:1) ~[?:?]
	at org.openhab.binding.mqtt.generic.ChannelState.publishValue(ChannelState.java:363) ~[?:?]
	at org.openhab.binding.mqtt.generic.AbstractMQTTThingHandler.handleCommand(AbstractMQTTThingHandler.java:152) ~[?:?]
	at jdk.internal.reflect.GeneratedMethodAccessor55.invoke(Unknown Source) ~[?:?]
	at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?]
	at java.lang.reflect.Method.invoke(Method.java:568) ~[?:?]
	at org.openhab.core.internal.common.AbstractInvocationHandler.invokeDirect(AbstractInvocationHandler.java:147) ~[?:?]
	at org.openhab.core.internal.common.InvocationHandlerSync.invoke(InvocationHandlerSync.java:59) ~[?:?]
	at jdk.proxy25829.$Proxy25945.handleCommand(Unknown Source) ~[?:?]
	at org.openhab.core.thing.internal.profiles.ProfileCallbackImpl.handleCommand(ProfileCallbackImpl.java:85) ~[?:?]
	at org.openhab.core.thing.internal.profiles.SystemDefaultProfile.onCommandFromItem(SystemDefaultProfile.java:48) ~[?:?]
	at jdk.internal.reflect.GeneratedMethodAccessor288.invoke(Unknown Source) ~[?:?]
	at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?]
	at java.lang.reflect.Method.invoke(Method.java:568) ~[?:?]
	at org.openhab.core.internal.common.AbstractInvocationHandler.invokeDirect(AbstractInvocationHandler.java:147) ~[?:?]
	at org.openhab.core.internal.common.Invocation.call(Invocation.java:52) ~[?:?]
	at java.util.concurrent.FutureTask.run(FutureTask.java:264) ~[?:?]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) ~[?:?]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) ~[?:?]
	at java.lang.Thread.run(Thread.java:833) ~[?:?]
==> /var/log/openhab/events.log <==
2023-08-18 13:12:26.267 [INFO ] [openhab.event.ItemCommandEvent      ] - Item 'Garage_ldoor' received command idle
2023-08-18 13:12:26.270 [INFO ] [penhab.event.ItemStatePredictedEvent] - Item 'Garage_ldoor' predicted to become idle
2023-08-18 13:12:26.271 [INFO ] [openhab.event.ItemCommandEvent      ] - Item 'Garage_rdoor' received command idle
2023-08-18 13:12:26.272 [INFO ] [openhab.event.ItemStateUpdatedEvent ] - Item 'Garage_ldoor' updated to idle

I recreated the rule just in case there was a problem in the migration, but that didn’t change anything:

configuration: {}
triggers:
  - id: "1"
    configuration:
      itemName: Garage_ldoor
      state: ldoor
    type: core.ItemStateChangeTrigger
  - id: "2"
    configuration:
      itemName: Garage_rdoor
      state: rdoor
    type: core.ItemStateChangeTrigger
conditions: []
actions:
  - inputs: {}
    id: "3"
    configuration:
      blockSource: <xml xmlns="https://developers.google.com/blockly/xml"><block
        type="oh_sleep" id="gx6VrY1z.+NXxs?ulp,*" x="208" y="122"><field
        name="milliseconds">1000</field><next><block type="oh_event"
        id=":{4.[-6,4F5THEVKTt}k"><field
        name="eventType">sendCommand</field><value name="value"><shadow
        type="text" id="YBr$L:?fu0`8I}Y7|`yj"><field
        name="TEXT">value</field></shadow><block type="text"
        id="YBr$L:?fu0`8I}Y7|`yj"><field
        name="TEXT">idle</field></block></value><value name="itemName"><shadow
        type="oh_item" id="buOS-uc/|M(Lu6ta*=Ut"><mutation itemName="MyItem"
        itemLabel="MyItem"></mutation><field
        name="itemName">MyItem</field></shadow><block type="oh_item"
        id="buOS-uc/|M(Lu6ta*=Ut"><mutation itemName="Garage_ldoor"
        itemLabel="ldoor"></mutation><field
        name="itemName">Garage_ldoor</field></block></value><next><block
        type="oh_event" id="K.~:g1lF8Xdb;A#.[g;F"><field
        name="eventType">sendCommand</field><value name="value"><shadow
        type="text" id="Bp{R*/I1]o;j{/c5,LN+"><field
        name="TEXT">value</field></shadow><block type="text"
        id="Bp{R*/I1]o;j{/c5,LN+"><field
        name="TEXT">idle</field></block></value><value name="itemName"><shadow
        type="oh_item" id="sg|M2:6D,oQb]MfD}y.S"><mutation itemName="MyItem"
        itemLabel="MyItem"></mutation><field
        name="itemName">MyItem</field></shadow><block type="oh_item"
        id="sg|M2:6D,oQb]MfD}y.S"><mutation itemName="Garage_rdoor"
        itemLabel="rdoor"></mutation><field
        name="itemName">Garage_rdoor</field></block></value></block></next></block></next></block></xml>
      type: application/javascript
      script: |
        var thread = Java.type('java.lang.Thread')


        thread.sleep(1000);
        items.getItem('Garage_ldoor').sendCommand('idle');
        items.getItem('Garage_rdoor').sendCommand('idle');
    type: script.ScriptAction

Anyone got an idea what else I could try to avoid this?

The error is coming from the binding, not the rule. How is that configured?

Why the sleep before the two commands. I’d expect it to be between the two commands.

Oh f… me :person_facepalming:

Thanks for your reply Rish. I had for some reason an “allowed state” in the item itself.

About your question: The idea is to reset the value after it’s been sent to the ESP, as open/close/stop is currently one single command. ‘ldoor’ for the left, and ‘rdoor’ for the right gate, which uses both the same channel on the MQTT item. The sleep before sort of to make sure the command is sent before the channel is reset to ‘idle’ and to avoid fingertrouble is clicked twice accidentally. I will change that once I find some time to give the ESP sensors to actually know whether the gates are open or closed…

One alternative approach would be to set Expire on the Item. You can have the Item update to “Idle” after 1 second automatically. No rule required.

Thanks again, that works! :sweat_smile: