Closed martink2 closed 5 years ago
Short update, I might have been chasing a red herring with the tty errors on startup.
I updated to the latest marketplace version and now the binding is started later in the startup process and i do not see any errors in the log regarding tty problems.
Unfortunately I still have the same problem with the dimmers:
ThingID: 00877367
EnoceanID: 00877367
SenderID: 5
EEP:Send Gateway Dimming A5_38_08
EEP:Receive Message with dimming Value A5_38_08
Button Pressed
2018-12-20 21:34:29.859 [TRACE] [ernal.transceiver.EnOceanTransceiver] - Received Sync Byte
2018-12-20 21:34:29.864 [TRACE] [ernal.transceiver.EnOceanTransceiver] - >> Received header, data length 7 optional length 7 packet type 1
2018-12-20 21:34:29.880 [DEBUG] [ernal.transceiver.EnOceanTransceiver] - RADIO_ERP1 with RORG RPS for FEFF3B48 payload F650FEFF3B483002FFFFFFFF5900 received
Button Released
2018-12-20 21:34:30.706 [TRACE] [ernal.transceiver.EnOceanTransceiver] - Received Sync Byte
2018-12-20 21:34:30.710 [TRACE] [ernal.transceiver.EnOceanTransceiver] - >> Received header, data length 7 optional length 7 packet type 1
2018-12-20 21:34:30.717 [DEBUG] [ernal.transceiver.EnOceanTransceiver] - RADIO_ERP1 with RORG RPS for FEFF3B48 payload F600FEFF3B482001FFFFFFFF5B00 received
State Telegram from Actor
2018-12-20 21:34:32.480 [TRACE] [ernal.transceiver.EnOceanTransceiver] - Received Sync Byte
2018-12-20 21:34:32.484 [TRACE] [ernal.transceiver.EnOceanTransceiver] - >> Received header, data length 10 optional length 7 packet type 1
2018-12-20 21:34:32.492 [DEBUG] [ernal.transceiver.EnOceanTransceiver] - RADIO_ERP1 with RORG _4BS for 00877367 payload A5024F0009008773670001FFFFFFFF5500 received
2018-12-20 21:34:32.496 [DEBUG] [rnal.handler.EnOceanBaseThingHandler] - ESP Packet payload A5024F00090087736700 for 00877367 received
But at this point the expected state change is not happening.
Hi @fruggy83,
i did some further debugging and i can narrow it down a little further:
I have a dimmer thing (wzDiBoden), which is not updating.
I remove the thing and re-create it with the exact same settings -> it starts working
2018-12-24 22:34:57.370 [DEBUG] [org.openhab.binding.openocean ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.config.core.status.ConfigStatusProvider}={service.id=430, service.bundleid=254, service.scope=singleton} - org.openhab.binding.openocean
2018-12-24 22:34:57.422 [DEBUG] [rnal.handler.EnOceanBaseThingHandler] - Initializing enocean base thing handler.
2018-12-24 22:34:57.432 [DEBUG] [rnal.handler.EnOceanBaseThingHandler] - initializeThing thing enocean:centralCommand:050A7B7D bridge status ONLINE
2018-12-24 22:34:57.617 [DEBUG] [ernal.transceiver.EnOceanTransceiver] - Listener added: 84573053
2018-12-24 22:35:42.451 [TRACE] [ernal.transceiver.EnOceanTransceiver] - Received Sync Byte
2018-12-24 22:35:42.455 [TRACE] [ernal.transceiver.EnOceanTransceiver] - >> Received header, data length 10 optional length 7 packet type 1
2018-12-24 22:35:42.462 [DEBUG] [ernal.transceiver.EnOceanTransceiver] - RADIO_ERP1 with RORG _4BS for 050A7B7D payload A502380009050A7B7D0001FFFFFFFF5300 received
2018-12-24 22:35:42.466 [DEBUG] [rnal.handler.EnOceanBaseThingHandler] - ESP Packet payload A502380009050A7B7D00 for 050A7B7D received
2018-12-24 22:35:42.487 [vent.ItemStateChangedEvent] - wzBoden changed from 41 to 56
Now without restarting or any other changes i go in and change something on the thing (ex. the name):
018-12-24 22:36:37.387 [DEBUG] [rnal.handler.EnOceanBaseThingHandler] - Initializing enocean base thing handler.
2018-12-24 22:36:37.392 [DEBUG] [rnal.handler.EnOceanBaseThingHandler] - initializeThing thing enocean:centralCommand:050A7B7D bridge status ONLINE
2018-12-24 22:36:37.424 [DEBUG] [ernal.transceiver.EnOceanTransceiver] - Listener added: 84573053
2018-12-24 22:36:37.480 [me.event.ThingUpdatedEvent] - Thing 'enocean:centralCommand:050A7B7D' has been updated.
2018-12-24 22:36:56.416 [TRACE] [ernal.transceiver.EnOceanTransceiver] - Received Sync Byte
2018-12-24 22:36:56.421 [TRACE] [ernal.transceiver.EnOceanTransceiver] - >> Received header, data length 10 optional length 7 packet type 1
2018-12-24 22:36:56.430 [DEBUG] [ernal.transceiver.EnOceanTransceiver] - RADIO_ERP1 with RORG _4BS for 050A7B7D payload A5023C0009050A7B7D0001FFFFFFFF5300 received
2018-12-24 22:36:56.434 [DEBUG] [rnal.handler.EnOceanBaseThingHandler] - ESP Packet payload A5023C0009050A7B7D00 for 050A7B7D received
At which point the dimmer value is no longer updated.
As far as i can see the resulting thing in the jsonDB is exactly the same.
Is there anything else you would suggest to do to further dig into the issue ?
Thanks
Martin
Hi @martink2,
thanks for your analysis. Found the bug and fixed it. Could you please test it? You find the fix in the issue branch. Thanks a lot.
Hi @fruggy83 ,
thanks again for the quick support. Yes i can confirm with the build from the issue branch the problem i resolved for me.
Hi @fruggy83
as mentioned in the community the is something problematic going on in the serial transceiver on openhab startup:
I recently switched to the 2.4 release and found the issue to be present release as well as at least m8, m7, m6 and the issue-10 version i am currently running.
On a clean openhabian installation i can create the bridge , dimmer thing and dimmer item and everything works fine whenever the dimmer sends a status message the value is reflected immediately. This is working until i restart the openhab process after which the dimmer is still working in a sense that i can dimm it but if the dimmer is sending an updated telegramm after manual dimming the new value is not updated in the item/thing.
I can solve the issue by removing the bridge and dimmer thing and adding it again afterward, which makes it work until restart.
In the broken state i can still see the packet recieved for the thing in question but nothing is published afterwards. As far as i can tell this behaviour is specific for the dimmer / command.
The other devices i have (classicDevices) are still reflecting the state via telegramms from associated enocean id's. I have this behaviour consistently.
Below is a full startup log but i found the folowing:
after a few minutes the bridge is reinitilized, which is working without a porblem:
After which all things go into online state but at least dimmers are not updated.
I am a bit lost on how to debug this problem further, I assume there is some problem in teh startup sequence or the sequence of loading things. The above error does not appear when adding the bridge after startup.
As always very much gratefull for any advise how to debug further?
Thanks
Martin