openhab / openhab1-addons

Add-ons for openHAB 1.x
Eclipse Public License 2.0
3.43k stars 1.7k forks source link

[mqtt] Values not recovered from broker after configuration change #4414

Open rvfh opened 8 years ago

rvfh commented 8 years ago

Expected Behavior

watou commented 8 years ago

This is expected behavior; without using the retain flag when messages are published to the broker, MQTT brokers do not retain messages, and so there is nowhere from which to get the messages.

Here is a description:

Each client that subscribes to a topic pattern, which matches the topic of the retained message, will receive the message immediately after subscribing. For each topic only one retained message will be stored by the broker.

Does the same occur when the values are published to the broker with the MQTT retain flag set?

I will close this issue, but please reopen if you see the MQTT binding failing to respect official MQTT standard behavior.

rvfh commented 8 years ago

I am using the retain functionality of MQTT, but openHAB is not getting the data back after invalidating them.

rvfh commented 8 years ago

About re-opening: I can't. You have to re-open it as you closed it.

In the future, I recommend that an issue is not closed until the original poster has had a chance to respond to the comments!

watou commented 8 years ago

I didn't see reference to it in your report. So, to confirm, your messages are being published with the retain flag set, you are changing which configuration file(s) exactly, and the binding is not appearing to re-subscribe to those topic filters?

watou commented 8 years ago

About re-opening: I can't. You have to re-open it as you closed it.

Thanks for that; I had forgotten. The issue as opened, with no reference to the retain flag, looked like a common misunderstanding of MQTT, but with your added info that you use the retain flag, the issue is now different: the MQTT binding does not appear to re-subscribe to topics after a configuration change (which may or may not be desired behavior -- further study is required). Please add specifically what configuration is changed so the issue can be reproduced. Thanks!

rvfh commented 8 years ago

Hello Watou,

Sorry I really need to get you a log. Will try ASAP! I am updating the items/* and sitemaps/* files which triggers a reload (nice feature BTW!) of the configuration and a refresh of the UI with all values getting back to undefined. They are not subsequently reloaded from the MQTT broker, but I can get them using the mosquitto_sub command-line client, as they are retained in the broker.

rvfh commented 8 years ago

Here is a log with may annotations (starting in ### HF:) about what I am doing... openhab.log.zip

It is missing the 'I am getting value X' which I thought it would show. Feel free to suggest improvements to my logback_debug.xml :-)

watou commented 8 years ago

If all of the topics were published with the retain flag set, then the act of resubscribing to the topics ought to result in their retained messages being published again at that point. I grepped your log for just one topic:

$ grep ground_bedroomne_main_switch_enable openhab.log

### JC: startup...

10:03:15.434 DEBUG o.o.m.i.i.GenericItemProvider[:341]- Start processing binding configuration of Item 'ground_bedroomne_main_switch_enable (Type=SwitchItem, State=Uninitialized)' with 'MqttGenericBindingProvider' reader.
10:03:15.435 DEBUG o.o.b.m.i.MqttItemConfig[:72]- Loaded MQTT config for item 'ground_bedroomne_main_switch_enable' : 1 subscribers, 1 publishers
10:03:15.435 DEBUG o.o.i.t.m.i.MqttBrokerConnection[:476]- Starting message consumer for broker 'mosquitto' on topic 'ground_bedroomne_main_switch_enable_set'

### HF: I 'touch' configurations/items/default.items to trigger a reload...

10:03:58.201 DEBUG o.o.b.m.i.MqttGenericBindingProvider[:73]- Removing message consumers for item ground_bedroomne_main_switch_enable
10:03:58.201 DEBUG o.o.i.t.m.i.MqttBrokerConnection[:505]- Unsubscribing message consumer for topic 'ground_bedroomne_main_switch_enable_set' from broker 'mosquitto'
10:03:58.202 DEBUG o.o.b.m.i.MqttGenericBindingProvider[:106]- Removing message publishers for item ground_bedroomne_main_switch_enable
10:04:00.718 DEBUG o.o.b.m.i.MqttItemConfig[:72]- Loaded MQTT config for item 'ground_bedroomne_main_switch_enable' : 1 subscribers, 1 publishers
10:04:00.719 DEBUG o.o.i.t.m.i.MqttBrokerConnection[:476]- Starting message consumer for broker 'mosquitto' on topic 'ground_bedroomne_main_switch_enable_set'

### HF: values did not get reloaded, so I restart my MQTT server to force a disconnect/connect/load...

10:04:39.297 DEBUG o.o.i.t.m.i.MqttBrokerConnection[:476]- Starting message consumer for broker 'mosquitto' on topic 'ground_bedroomne_main_switch_enable_set'

### HF: all values reloaded and correct

So there seems to be something in either the binding or Eclipse Paho that is not fully reestablishing the subscription. What I'm confused about is how killing and restarting the broker immediately re-publishes the retained messages. So mosquitto must be persisting the retained messages to disk and reloading them when it's restarted?

If you run mosquitto_sub subscribing to that topic (having it go through the same test cycles as the binding does), does it immediately print the retained message when it's started? I suspect this "not re-sending retained messages when a config is reloaded" has always been the case in openHAB, but users have just learned to live with it. Would be nice if it were fixed, I admit!

rvfh commented 8 years ago

Hi Watou, sorry if my message was confusing: no the MQTT broker does not retain the values over a restart, but restarting it caused both my HNet server to send the values again and openHAB to get them. My bad for mixing things here!

The issue is not limited to MQTT in fact. I was using the TCP binding to get openHAB updates and the REST interface to send updates to openHAB before moving to MQTT over the week-end, and had the same issue, but I had not understood what was going on. Also, with the rest interface I had no other choice than re-sending for 10 seconds to make sure the values were definitely set. When I heard of MQTT and its retain feature, I thought I could get rid of the 'repeat for 10 seconds' loop, but I'll keep a bit longer :-P

To answer your last question, I indeed tested MQTT manually before implementing it, and this works: $ mosquitto_pub -t foo -m bar -r $ mosquitto_sub -t foo bar

I can also do: $ sudo service mosquitto restart $ sudo service hnet start $ sudo service hnet stop $ mosquitto_sub -t ground_bedroomne_main_switch_enable_set ON

FYI, HNet is my manager for my HA system. It sends to and receives from MQTT too, like so: | Hnet | <---> | MQTT | <---> | openHAB |

I use openHAB for its web/mobile interface and HNet to manage the "plumbing": switches, relays, GPIOs, etc...

rvfh commented 8 years ago

I took the output of the console in case it helps, as it seems to have more info... Again I put some comments starting in ###.

On 30 May 2016 at 19:49, John Cocula notifications@github.com wrote:

If all of the topics were published with the retain flag set, then the act of resubscribing to the topics ought to result in their retained messages being published again at that point. I grepped your log for just one topic:

$ grep ground_bedroomne_main_switch_enable openhab.log

JC: startup...

10:03:15.434 DEBUG o.o.m.i.i.GenericItemProvider[:341]- Start processing binding configuration of Item 'ground_bedroomne_main_switch_enable (Type=SwitchItem, State=Uninitialized)' with 'MqttGenericBindingProvider' reader. 10:03:15.435 DEBUG o.o.b.m.i.MqttItemConfig[:72]- Loaded MQTT config for item 'ground_bedroomne_main_switch_enable' : 1 subscribers, 1 publishers 10:03:15.435 DEBUG o.o.i.t.m.i.MqttBrokerConnection[:476]- Starting message consumer for broker 'mosquitto' on topic 'ground_bedroomne_main_switch_enable_set'

HF: I 'touch' configurations/items/default.items to trigger a reload...

10:03:58.201 DEBUG o.o.b.m.i.MqttGenericBindingProvider[:73]- Removing message consumers for item ground_bedroomne_main_switch_enable 10:03:58.201 DEBUG o.o.i.t.m.i.MqttBrokerConnection[:505]- Unsubscribing message consumer for topic 'ground_bedroomne_main_switch_enable_set' from broker 'mosquitto' 10:03:58.202 DEBUG o.o.b.m.i.MqttGenericBindingProvider[:106]- Removing message publishers for item ground_bedroomne_main_switch_enable 10:04:00.718 DEBUG o.o.b.m.i.MqttItemConfig[:72]- Loaded MQTT config for item 'ground_bedroomne_main_switch_enable' : 1 subscribers, 1 publishers 10:04:00.719 DEBUG o.o.i.t.m.i.MqttBrokerConnection[:476]- Starting message consumer for broker 'mosquitto' on topic 'ground_bedroomne_main_switch_enable_set'

HF: values did not get reloaded, so I restart my MQTT server to force a disconnect/connect/load...

10:04:39.297 DEBUG o.o.i.t.m.i.MqttBrokerConnection[:476]- Starting message consumer for broker 'mosquitto' on topic 'ground_bedroomne_main_switch_enable_set'

HF: all values reloaded and correct

So there seems to be something in either the binding or Eclipse Paho that is not fully reestablishing the subscription. What I'm confused about is how killing and restarting the broker immediately re-publishes the retained messages. So mosquitto must be persisting the retained messages to disk and reloading them when it's restarted?

If you run mosquitto_sub subscribing to that topic (having it go through the same test cycles as the binding does), does it immediately print the retained message when it's started? I suspect this "not re-sending retained messages when a config is reloaded" has always been the case in openHAB, but users have just learned to live with it. Would be nice if it were fixed, I admit!

— You are receiving this because you authored the thread. Reply to this email directly, view it on GitHub https://github.com/openhab/openhab/issues/4414#issuecomment-222533794, or mute the thread https://github.com/notifications/unsubscribe/ACYNkFqlO_y_Zd505OoEYsU-741PQS0pks5qGyMvgaJpZM4IpSw- .

rvfh commented 8 years ago

Struggled to attach the log... openhab_console.log.gz

stefanbode commented 8 years ago

As far as I can see with version 1.8.2 after a change in the .items file (only 2 mqtt items included) the system does not recover properly. Only thing that seems to work on the raspberry is to restart the server. Server does not crash, but hang with high cpu all time (until crasches...) The item reload works fine in my environment with homematic and other items (fritz).