[Yamaha binding] Strange lines in logs

Tags: #<Tag:0x00007fc20ffae028>

Hello,
I need help with Yamaha binding. I just upgraded openhab to newest tesing version from M5.
I have yamaha binding installed. I have refresh interval set to 2 sec. I have in logs situation:

2020-01-07 10:42:22.326 [me.event.ThingUpdatedEvent] - Thing 'yamahareceiver:zone:9ab0c000_f668_11de_9976_00a0dedd9906:Main_Zone' has been updated.
2020-01-07 10:42:22.328 [vent.ItemStateChangedEvent] - yamahareceiver_zone_9ab0c000_f668_11de_9976_00a0dedd9906_Main_Zone_zone_channels_surroundProgram changed from NULL to Straight
2020-01-07 10:42:22.336 [vent.ItemStateChangedEvent] - yamahareceiver_zone_9ab0c000_f668_11de_9976_00a0dedd9906_Main_Zone_zone_channels_mute changed from NULL to OFF
2020-01-07 10:42:22.337 [vent.ItemStateChangedEvent] - yamahareceiver_zone_9ab0c000_f668_11de_9976_00a0dedd9906_Main_Zone_playback_channels_playback changed from NULL to Play
2020-01-07 10:42:22.338 [vent.ItemStateChangedEvent] - yamahareceiver_zone_9ab0c000_f668_11de_9976_00a0dedd9906_Main_Zone_playback_channels_playback_station changed from NULL to RMF FM (Krakow/Polish)
2020-01-07 10:42:22.339 [vent.ItemStateChangedEvent] - yamahareceiver_zone_9ab0c000_f668_11de_9976_00a0dedd9906_Main_Zone_playback_channels_playback_song changed from NULL to RMF FM
2020-01-07 10:42:22.340 [vent.ItemStateChangedEvent] - yamahareceiver_zone_9ab0c000_f668_11de_9976_00a0dedd9906_Main_Zone_playback_channels_playback_song_image_url changed from NULL to http:/x.x.x.x/YamahaRemoteControl/AlbumART/AlbumART3696.png
2020-01-07 10:42:22.341 [vent.ItemStateChangedEvent] - yamahareceiver_zone_9ab0c000_f668_11de_9976_00a0dedd9906_Main_Zone_playback_channels_tuner_band changed from NULL to
2020-01-07 10:42:22.342 [vent.ItemStateChangedEvent] - yamahareceiver_zone_9ab0c000_f668_11de_9976_00a0dedd9906_Main_Zone_navigation_channels_navigation_menu changed from NULL to Radio
2020-01-07 10:42:22.343 [vent.ItemStateChangedEvent] - yamahareceiver_zone_9ab0c000_f668_11de_9976_00a0dedd9906_Main_Zone_navigation_channels_navigation_current_item changed from NULL to 1
2020-01-07 10:42:22.344 [vent.ItemStateChangedEvent] - yamahareceiver_zone_9ab0c000_f668_11de_9976_00a0dedd9906_Main_Zone_navigation_channels_navigation_total_items changed from NULL to 2
2020-01-07 10:42:22.345 [vent.ItemStateChangedEvent] - yamahareceiver_zone_9ab0c000_f668_11de_9976_00a0dedd9906_Main_Zone_navigation_channels_navigation_level changed from NULL to 0
2020-01-07 10:42:22.353 [vent.ItemStateChangedEvent] - yamahareceiver_zone_9ab0c000_f668_11de_9976_00a0dedd9906_Main_Zone_zone_channels_input changed from NULL to NET RADIO
2020-01-07 10:42:22.353 [vent.ItemStateChangedEvent] - yamahareceiver_zone_9ab0c000_f668_11de_9976_00a0dedd9906_Main_Zone_zone_channels_power changed from NULL to ON
2020-01-07 10:42:22.354 [vent.ItemStateChangedEvent] - yamahareceiver_zone_9ab0c000_f668_11de_9976_00a0dedd9906_Main_Zone_playback_channels_preset changed from NULL to -1
2020-01-07 10:42:22.354 [vent.ItemStateChangedEvent] - yamahareceiver_zone_9ab0c000_f668_11de_9976_00a0dedd9906_Main_Zone_navigation_channels_navigation_menu changed from Radio to NET RADIO
2020-01-07 10:42:24.317 [me.event.ThingUpdatedEvent] - Thing 'yamahareceiver:zone:9ab0c000_f668_11de_9976_00a0dedd9906:Main_Zone' has been updated.
2020-01-07 10:42:24.324 [vent.ItemStateChangedEvent] - yamahareceiver_zone_9ab0c000_f668_11de_9976_00a0dedd9906_Main_Zone_zone_channels_mute changed from NULL to OFF
2020-01-07 10:42:24.325 [vent.ItemStateChangedEvent] - yamahareceiver_zone_9ab0c000_f668_11de_9976_00a0dedd9906_Main_Zone_zone_channels_power changed from NULL to ON
2020-01-07 10:42:24.342 [me.event.ThingUpdatedEvent] - Thing 'yamahareceiver:zone:9ab0c000_f668_11de_9976_00a0dedd9906:Main_Zone' has been updated.
2020-01-07 10:42:24.351 [vent.ItemStateChangedEvent] - yamahareceiver_zone_9ab0c000_f668_11de_9976_00a0dedd9906_Main_Zone_navigation_channels_navigation_menu changed from NULL to NET RADIO
2020-01-07 10:42:24.352 [vent.ItemStateChangedEvent] - yamahareceiver_zone_9ab0c000_f668_11de_9976_00a0dedd9906_Main_Zone_playback_channels_preset changed from NULL to -1
2020-01-07 10:42:24.352 [vent.ItemStateChangedEvent] - yamahareceiver_zone_9ab0c000_f668_11de_9976_00a0dedd9906_Main_Zone_zone_channels_mute changed from NULL to OFF
2020-01-07 10:42:24.352 [vent.ItemStateChangedEvent] - yamahareceiver_zone_9ab0c000_f668_11de_9976_00a0dedd9906_Main_Zone_zone_channels_dialogueLevel changed from NULL to 3
2020-01-07 10:42:24.353 [vent.ItemStateChangedEvent] - yamahareceiver_zone_9ab0c000_f668_11de_9976_00a0dedd9906_Main_Zone_playback_channels_playback changed from NULL to Play
2020-01-07 10:42:24.353 [vent.ItemStateChangedEvent] - yamahareceiver_zone_9ab0c000_f668_11de_9976_00a0dedd9906_Main_Zone_playback_channels_playback_station changed from NULL to RMF FM (Krakow/Polish)
2020-01-07 10:42:24.354 [vent.ItemStateChangedEvent] - yamahareceiver_zone_9ab0c000_f668_11de_9976_00a0dedd9906_Main_Zone_playback_channels_playback_artist changed from NULL to N/A
2020-01-07 10:42:24.354 [vent.ItemStateChangedEvent] - yamahareceiver_zone_9ab0c000_f668_11de_9976_00a0dedd9906_Main_Zone_playback_channels_playback_album changed from NULL to
2020-01-07 10:42:24.354 [vent.ItemStateChangedEvent] - yamahareceiver_zone_9ab0c000_f668_11de_9976_00a0dedd9906_Main_Zone_playback_channels_playback_song changed from NULL to RMF FM
2020-01-07 10:42:24.355 [vent.ItemStateChangedEvent] - yamahareceiver_zone_9ab0c000_f668_11de_9976_00a0dedd9906_Main_Zone_playback_channels_playback_song_image_url changed from NULL to http://x.x.x.x:80/YamahaRemoteControl/AlbumART/AlbumART3696.png
2020-01-07 10:42:24.355 [vent.ItemStateChangedEvent] - yamahareceiver_zone_9ab0c000_f668_11de_9976_00a0dedd9906_Main_Zone_playback_channels_tuner_band changed from NULL to
2020-01-07 10:42:24.355 [vent.ItemStateChangedEvent] - yamahareceiver_zone_9ab0c000_f668_11de_9976_00a0dedd9906_Main_Zone_navigation_channels_navigation_menu changed from NET RADIO to Radio
2020-01-07 10:42:24.356 [vent.ItemStateChangedEvent] - yamahareceiver_zone_9ab0c000_f668_11de_9976_00a0dedd9906_Main_Zone_navigation_channels_navigation_current_item changed from NULL to 1
2020-01-07 10:42:24.356 [vent.ItemStateChangedEvent] - yamahareceiver_zone_9ab0c000_f668_11de_9976_00a0dedd9906_Main_Zone_navigation_channels_navigation_total_items changed from NULL to 2
2020-01-07 10:42:24.357 [vent.ItemStateChangedEvent] - yamahareceiver_zone_9ab0c000_f668_11de_9976_00a0dedd9906_Main_Zone_navigation_channels_navigation_level changed from NULL to 0
2020-01-07 10:42:24.357 [vent.ItemStateChangedEvent] - yamahareceiver_zone_9ab0c000_f668_11de_9976_00a0dedd9906_Main_Zone_zone_channels_input changed from NULL to NET RADIO
2020-01-07 10:42:24.357 [vent.ItemStateChangedEvent] - yamahareceiver_zone_9ab0c000_f668_11de_9976_00a0dedd9906_Main_Zone_zone_channels_volume changed from NULL to 33
2020-01-07 10:42:24.358 [vent.ItemStateChangedEvent] - yamahareceiver_zone_9ab0c000_f668_11de_9976_00a0dedd9906_Main_Zone_zone_channels_surroundProgram changed from NULL to Straight

It looks like it is logging changes even if nothing changes at receiver.
Every refresh it is changing items state from Null to real value.
I think there should not be change if there was no real chage in receiver.

It is making big mess in log.
As i remember there was no such situation in m5 version

First: Please use code fences for your log to make the post more readable.

The Thing has been updated log lines on every refresh is normal as far as I know. You can filter it in the log config if you want.

The other log entries for all items changing from NULL to some value shouldn’t be there. But without any further information I have no idea where to look. Maybe the Binding is restarting. I think this is a common problem with 2.5 release version.

I do not think that is normal. This is about some property of the thing changing e.g. address or type. Not about data.
Associated Items getting silently set to NULL is probably a consequence of the unwanted Thing reset.

Similar problems have been seen in other bindings e.g.


but I don’t think anyone’s really got to the bottom of it.
Feels like something to do with discovery to me.

This one looks really relevant

Hello,
Thanks rossko57 for hint.
I changed thing from discovery to manual configuration and lines with ( *changed from NULL to NET RADIO) dissapeared.
So it looks like there is problem with thing discovery in newest test version. I had also problems with other bindings, like MQTT, MIIO (things were disappearing after restart).
So i am moving to manual thing configuration.
but
errror:

2020-01-07 10:42:24.342 [me.event.ThingUpdatedEvent] - Thing 'yamahareceiver:zone:9ab0c000_f668_11de_9976_00a0dedd9906:Main_Zone' has been updated.

still is in logs (every 2 seconds). Even nothing is changing (yamaha receiver is off).
Looks like this is connected to info from Tomasz:

Hello Sebastian,
Is there a way to filter out those lines about yamaha thing update from logs, (that they will be not written to log?

Yes, that I my understanding too.

Can you please create a github issue for that, so that it’s not lost?
Once I have some free time I will look into that.

I suggest to test the my latest build from here and see if things are improved.

Issue created

1 Like

Hello Tomasz,
I already tested your build. Same “thing has been updated” log entry.

1 Like

Please check progress here