mqttitude/owntracks: I'm not receiving state from mosquitto

[ari...@nesys.it]

Hi All,

now I have up&running a private mosquitto server, owntracks on my iPhone and mqtt/mqttitude bindings configured on openHAB. But .... it doesn't work :(

Unfortunately I can't start openHAB in debug mode, due to installation from deb. But I've raised the log level in logback.xml to TRACE for both bindings.

Here my mosquitto conf file:

-----------------------------------------

pid_file /var/run/mosquitto.pid

user mosquitto

bind_address 192.168.xx.xx

port 8883

# max_connections

cafile /etc/mosquitto/ca_certificates/xxxxx.crt

certfile /etc/mosquitto/certs/xxxxx.pem

keyfile /etc/mosquitto/certs/xxxxx.key

persistence true

persistence_location /var/lib/mosquitto/

clientid_prefixes who-

allow_anonymous false

password_file /etc/mosquitto/passwd

log_dest file /var/log/mosquitto/mosquitto.log

log_type all

include_dir /etc/mosquitto/conf.d

--------------------------

the user/pwd in passwd file is the same configured in openHAB and owntracks.

mqtt binding conf file:

-----------------------------------

mqtt:mosquitto.url=ssl://my.mosquitto.server:8883

mqtt:mosquitto.clientId=who-openHAB

mqtt:mosquitto.user=user

mqtt:mosquitto.pwd=pwd

mqtt:mosquitto.qos=1

mqtt:mosquitto.retain=false

mqtt:mosquitto.async=true

mqtt-eventbus:broker=mosquitto 

mqtt-eventbus:commandPublishTopic=home/openHAB/out/${item}/command 

mqtt-eventbus:statePublishTopic=home/openHAB/state/${item}/state

------------------------------------

now what I can see in openhab.log:

2015-01-16 01:17:40.705 [INFO ] [.io.transport.mqtt.MqttService] - MQTT Service initialization completed.

2015-01-16 01:17:40.706 [INFO ] [o.i.t.m.i.MqttBrokerConnection] - Starting MQTT broker connection 'mosquitto'

2015-01-16 01:17:56.335 [DEBUG] [.m.internal.MqttitudeActivator] - Mqttitude binding has been started.

2015-01-16 01:17:56.355 [DEBUG] [.b.m.internal.MqttitudeBinding] - Registering Mqttitude consumer for /owntracks/nesys/andrea (on mosquitto)

2015-01-16 01:17:56.363 [DEBUG] [.b.m.internal.MqttitudeBinding] - Activating Mqttitude binding

2015-01-16 01:17:56.430 [DEBUG] [.b.mqtt.internal.MqttActivator] - MQTT binding has been started.

2015-01-16 01:17:56.472 [DEBUG] [m.internal.MqttEventBusBinding] - MQTT: Activating event bus binding.

2015-01-16 01:17:59.466 [DEBUG] [m.internal.MqttEventBusBinding] - Initializing MQTT Event Bus Binding

2015-01-16 01:17:59.469 [DEBUG] [m.internal.MqttEventBusBinding] - Setting up Event Bus State Publisher for topic home/openHAB/state/${item}/state

2015-01-16 01:17:59.511 [TRACE] [m.internal.MqttEventBusBinding] - No topic defined for Event Bus State Subsriber

2015-01-16 01:17:59.511 [DEBUG] [m.internal.MqttEventBusBinding] - Setting up Event Bus Command Publisher for topic home/openHAB/out/${item}/command

2015-01-16 01:17:59.511 [TRACE] [m.internal.MqttEventBusBinding] - No topic defined for Event Bus Command Subsriber

2015-01-16 01:17:59.512 [DEBUG] [m.internal.MqttEventBusBinding] - MQTT Event Bus Binding initialization completed

and in mosquitto.log:

1421367870: New connection from 192.168.17.6 on port 8883.

1421367870: New client connected from 192.168.17.6 as who-andrea (c1, k60, unesys).

1421367870: Sending CONNACK to who-andrea (0)

1421367870: Received SUBSCRIBE from who-andrea

1421367870: owntracks/+/+ (QoS 1)

1421367870: who-andrea 1 owntracks/+/+

1421367870: Sending SUBACK to who-andrea

1421367870: Sending PUBLISH to who-andrea (d0, q1, r1, m1, 'owntracks/nesys/andrea', ... (142 bytes))

1421367870: Received SUBSCRIBE from who-andrea

1421367870: owntracks/nesys/andrea/# (QoS 1)

1421367870: who-andrea 1 owntracks/nesys/andrea/#

1421367870: Sending SUBACK to who-andrea

1421367870: Sending PUBLISH to who-andrea (d0, q1, r1, m2, 'owntracks/nesys/andrea', ... (142 bytes))

1421367870: Received PUBACK from who-andrea (Mid: 1)

1421367870: Received PUBACK from who-andrea (Mid: 2)

1421367871: Received PUBLISH from who-andrea (d0, q1, r0, m26, 'owntracks/nesys/andrea', ... (143 bytes))

1421367871: Sending PUBACK to who-andrea (Mid: 26)

1421367871: Sending PUBLISH to who-andrea (d0, q1, r0, m3, 'owntracks/nesys/andrea', ... (143 bytes))

1421367872: Received PUBACK from nesys-andrea (Mid: 3)

1421367873: Received DISCONNECT from who-andrea

1421367874: Received PUBLISH from who-openHAB (d0, q1, r0, m318, 'home/openHAB/state/FioPreciProb/state', ... (4 bytes))

1421367874: Sending PUBACK to who-openHAB (Mid: 318)

1421367875: Received PUBLISH from who-openHAB (d0, q1, r0, m319, 'home/openHAB/state/FioCloudCover/state', ... (4 bytes))

1421367875: Sending PUBACK to who-openHAB (Mid: 319)

<... a lot of items from openHAB ...>

in this case, 192.168.17.6 is my iPhone.

owntracks configured as follow:

host my.mosquitto.server

port 8883

TLS ON

Auth ON

UserID user

Password pwd

ClientID who-andrea

Clear Session ON

Keep Alive 60

DeviceID andrea

Qos at least one

Retain OFF

(tried also with Topic "andrea")

My impression is: mosquitto server receives all info from iPhone and from openHAB, but is not forwarding anything to the clients.

item:

/*Presence items */

Switch  PresenceAndrea_PhoneMqttHome   "Andrea @ Home"   { mqttitude="mosquitto:/owntracks/nesys/andrea:home" }

I have a waypoint/region "home".

When I open the page in my site map, where I have a switch item linked to that item, I see this log:

2015-01-16 01:21:45.813 [WARN ] [.o.u.w.i.render.SwitchRenderer] - Cannot determine item type of 'null'

org.openhab.core.items.ItemNotFoundException: Item 'null' could not be found in the item registry

at org.openhab.core.internal.items.ItemRegistryImpl.getItem(ItemRegistryImpl.java:80) ~[na:na]

at org.openhab.ui.internal.items.ItemUIRegistryImpl.getItem(ItemUIRegistryImpl.java:527) ~[na:na]

at org.openhab.ui.webapp.internal.render.SwitchRenderer.renderWidget(SwitchRenderer.java:57) ~[org.openhab.ui.webapp_1.6.1.jar:na]

at org.openhab.ui.webapp.internal.render.PageRenderer.renderWidget(PageRenderer.java:158) [org.openhab.ui.webapp_1.6.1.jar:na]

at org.openhab.ui.webapp.internal.render.PageRenderer.processChildren(PageRenderer.java:121) [org.openhab.ui.webapp_1.6.1.jar:na]

at org.openhab.ui.webapp.internal.render.PageRenderer.processPage(PageRenderer.java:86) [org.openhab.ui.webapp_1.6.1.jar:na]

at org.openhab.ui.webapp.internal.servlet.WebAppServlet.service(WebAppServlet.java:142) [org.openhab.ui.webapp_1.6.1.jar:na]

at org.eclipse.equinox.http.servlet.internal.ServletRegistration.service(ServletRegistration.java:61) [org.eclipse.equinox.http.servlet_1.1.300.v20120522-1841.jar:na]

at org.eclipse.equinox.http.servlet.internal.ProxyServlet.processAlias(ProxyServlet.java:128) [org.eclipse.equinox.http.servlet_1.1.300.v20120522-1841.jar:na]

at org.eclipse.equinox.http.servlet.internal.ProxyServlet.service(ProxyServlet.java:60) [org.eclipse.equinox.http.servlet_1.1.300.v20120522-1841.jar:na]

at javax.servlet.http.HttpServlet.service(HttpServlet.java:848) [javax.servlet_3.0.0.v201112011016.jar:na]

at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:598) [org.eclipse.jetty.servlet_8.1.3.v20120522.jar:8.1.3.v20120522]

at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:486) [org.eclipse.jetty.servlet_8.1.3.v20120522.jar:8.1.3.v20120522]

at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:231) [org.eclipse.jetty.server_8.1.3.v20120522.jar:8.1.3.v20120522]

at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1065) [org.eclipse.jetty.server_8.1.3.v20120522.jar:8.1.3.v20120522]

at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:413) [org.eclipse.jetty.servlet_8.1.3.v20120522.jar:8.1.3.v20120522]

at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:192) [org.eclipse.jetty.server_8.1.3.v20120522.jar:8.1.3.v20120522]

at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:999) [org.eclipse.jetty.server_8.1.3.v20120522.jar:8.1.3.v20120522]

at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:117) [org.eclipse.jetty.server_8.1.3.v20120522.jar:8.1.3.v20120522]

at org.eclipse.jetty.server.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:250) [org.eclipse.jetty.server_8.1.3.v20120522.jar:8.1.3.v20120522]

at org.eclipse.jetty.server.handler.HandlerCollection.handle(HandlerCollection.java:149) [org.eclipse.jetty.server_8.1.3.v20120522.jar:8.1.3.v20120522]

at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:111) [org.eclipse.jetty.server_8.1.3.v20120522.jar:8.1.3.v20120522]

at org.eclipse.jetty.server.Server.handle(Server.java:350) [org.eclipse.jetty.server_8.1.3.v20120522.jar:8.1.3.v20120522]

at org.eclipse.jetty.server.AbstractHttpConnection.handleRequest(AbstractHttpConnection.java:454) [org.eclipse.jetty.server_8.1.3.v20120522.jar:8.1.3.v20120522]

at org.eclipse.jetty.server.AbstractHttpConnection.headerComplete(AbstractHttpConnection.java:890) [org.eclipse.jetty.server_8.1.3.v20120522.jar:8.1.3.v20120522]

at org.eclipse.jetty.server.AbstractHttpConnection$RequestHandler.headerComplete(AbstractHttpConnection.java:944) [org.eclipse.jetty.server_8.1.3.v20120522.jar:8.1.3.v20120522]

at org.eclipse.jetty.http.HttpParser.parseNext(HttpParser.java:630) [org.eclipse.jetty.http_8.1.3.v20120522.jar:8.1.3.v20120522]

at org.eclipse.jetty.http.HttpParser.parseAvailable(HttpParser.java:230) [org.eclipse.jetty.http_8.1.3.v20120522.jar:8.1.3.v20120522]

at org.eclipse.jetty.server.AsyncHttpConnection.handle(AsyncHttpConnection.java:77) [org.eclipse.jetty.server_8.1.3.v20120522.jar:8.1.3.v20120522]

at org.eclipse.jetty.io.nio.SslConnection.handle(SslConnection.java:191) [org.eclipse.jetty.io_8.1.3.v20120522.jar:8.1.3.v20120522]

at org.eclipse.jetty.io.nio.SelectChannelEndPoint.handle(SelectChannelEndPoint.java:606) [org.eclipse.jetty.io_8.1.3.v20120522.jar:8.1.3.v20120522]

at org.eclipse.jetty.io.nio.SelectChannelEndPoint$1.run(SelectChannelEndPoint.java:46) [org.eclipse.jetty.io_8.1.3.v20120522.jar:8.1.3.v20120522]

at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:603) [org.eclipse.jetty.util_8.1.3.v20120522.jar:8.1.3.v20120522]

at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:538) [org.eclipse.jetty.util_8.1.3.v20120522.jar:8.1.3.v20120522]

at java.lang.Thread.run(Thread.java:745) [na:1.8.0_25]

What I'm missing?

I appreciate your support on this

Thank you

Andrea

[ari...@nesys.it]

first step ahead.

From mqtt-eventbus point of view, Publish means "I will sent some data out", Subscribe means "I will receive some data from mqtt broker". So I've put this line in my openhab.cfg:

mqtt-eventbus:stateSubscribeTopic=owntracks/nesys/andrea

Now the log is much better:

2015-01-16 14:40:46.814 [DEBUG] [.m.internal.MqttitudeActivator] - Mqttitude binding has been started.

2015-01-16 14:40:46.853 [DEBUG] [.b.m.internal.MqttitudeBinding] - Registering Mqttitude consumer for owntracks/nesys/andrea (on mosquitto)

2015-01-16 14:40:46.869 [TRACE] [b.m.internal.MqttitudeConsumer] - Message received on topic owntracks/nesys/andrea: {"tst":"1421367424","vac":10,"acc":"200","alt":121,"lon":"9.13488","_type":"location","vel":0,"lat":"45.4668","cog":-1,"tid":"EA","batt":"95"}

2015-01-16 14:40:46.875 [DEBUG] [.b.m.internal.MqttitudeBinding] - Activating Mqttitude binding

2015-01-16 14:40:46.977 [DEBUG] [.b.mqtt.internal.MqttActivator] - MQTT binding has been started.

2015-01-16 14:40:47.022 [DEBUG] [m.internal.MqttEventBusBinding] - MQTT: Activating event bus binding.

So data now arrive on my openHAB event bus. But item doesn't work, and I see also this part of the log:

2015-01-16 14:40:47.473 [TRACE] [b.m.internal.MqttitudeConsumer] - Checking item PresenceAndrea_PhoneMqttHome...

2015-01-16 14:40:47.474 [TRACE] [b.m.internal.MqttitudeConsumer] - Not a location enter/leave event, ignoring

2015-01-16 14:40:49.771 [DEBUG] [m.internal.MqttEventBusBinding] - Initializing MQTT Event Bus Binding

2015-01-16 14:40:49.771 [TRACE] [m.internal.MqttEventBusBinding] - No topic defined for Event Bus State Publisher

2015-01-16 14:40:49.772 [DEBUG] [m.internal.MqttEventBusBinding] - Setting up Event Bus State Subscriber for topic owntracks/nesys/andrea

2015-01-16 14:40:49.806 [TRACE] [b.m.internal.MqttitudeConsumer] - Message received on topic owntracks/nesys/andrea: {"tst":"1421367424","vac":10,"acc":"200","alt":121,"lon":"9.13488","_type":"location","vel":0,"lat":"45.4668","cog":-1,"tid":"EA","batt":"95"}

2015-01-16 14:40:49.806 [TRACE] [m.internal.MqttEventBusBinding] - No topic defined for Event Bus Command Publisher

2015-01-16 14:40:49.806 [TRACE] [m.internal.MqttEventBusBinding] - No topic defined for Event Bus Command Subsriber

2015-01-16 14:40:49.807 [DEBUG] [m.internal.MqttEventBusBinding] - MQTT Event Bus Binding initialization completed.

2015-01-16 14:40:49.840 [TRACE] [b.m.internal.MqttitudeConsumer] - Checking item PresenceAndrea_PhoneMqttHome...

2015-01-16 14:40:49.841 [TRACE] [b.m.internal.MqttitudeConsumer] - Not a location enter/leave event, ignoring

Question is: the switch, if I'm at home, should be OFF or ON?

that:

2015-01-16 14:40:49.840 [TRACE] [b.m.internal.MqttitudeConsumer] - Checking item PresenceAndrea_PhoneMqttHome...

2015-01-16 14:40:49.841 [TRACE] [b.m.internal.MqttitudeConsumer] - Not a location enter/leave event, ignoring

sounds sinister ... ;) can you help me understanding this?

In the Owntracks I have a waypoint in owntracks/nesys/andrea, description "home", radius 50, share ON ...

Thanks

Andrea

[ari...@nesys.it]

Well,

it works finally ;-) but I would like to understand what is the tag for enter/leave that I should see in MQTT message:

2015-01-16 15:45:39.559 [ERROR] [o.i.t.m.i.MqttBrokerConnection] - MQTT connection to 'mosquitto' was lost: Connection lost : ReasonCode 32109 : Cause : null

2015-01-16 15:45:39.559 [INFO ] [o.i.t.m.i.MqttBrokerConnection] - Starting connection helper to periodically try restore connection to broker 'mosquitto'

2015-01-16 15:45:49.564 [INFO ] [o.i.t.m.i.MqttBrokerConnection] - Starting MQTT broker connection 'mosquitto'

2015-01-16 15:45:49.625 [TRACE] [b.m.internal.MqttitudeConsumer] - Message received on topic owntracks/nesys/andrea: {"tst":"1421367424","vac":10,"acc":"200","alt":121,"lon":"9.13488","_type":"location","vel":0,"lat":"45.4668","cog":-1,"tid":"EA","batt":"95"}

2015-01-16 15:45:49.630 [TRACE] [b.m.internal.MqttitudeConsumer] - Checking item PresenceAndrea_MQTT...

2015-01-16 15:45:49.631 [TRACE] [b.m.internal.MqttitudeConsumer] - Not a location enter/leave event, ignoring

2015-01-16 15:45:49.634 [TRACE] [b.m.internal.MqttitudeConsumer] - Message received on topic owntracks/nesys/andrea: {"tst":"1421367424","vac":10,"acc":"200","alt":121,"lon":"9.13488","_type":"location","vel":0,"lat":"45.4668","cog":-1,"tid":"EA","batt":"95"}

2015-01-16 15:45:49.638 [TRACE] [b.m.internal.MqttitudeConsumer] - Checking item PresenceAndrea_MQTT...

2015-01-16 15:45:49.638 [TRACE] [b.m.internal.MqttitudeConsumer] - Not a location enter/leave event, ignoring

2015-01-16 16:03:37.895 [TRACE] [b.m.internal.MqttitudeConsumer] - Message received on topic owntracks/nesys/andrea: {"cog":-1,"lon":"9.13492","acc":"65","vel":-1,"_type":"location","batt":"40","vac":10,"lat":"45.4669","t":"p","tst":"1421420472","alt":125,"tid":"EA"}

2015-01-16 16:03:37.903 [TRACE] [b.m.internal.MqttitudeConsumer] - Checking item PresenceAndrea_MQTT...

2015-01-16 16:03:37.903 [TRACE] [b.m.internal.MqttitudeConsumer] - Not a location enter/leave event, ignoring

someone can help me?

Thanks

Andrea

[Ben Jones]

Have you read the wiki page for the Mqttitude binding? That should explain the different modes of operation.

[Andrea Riela]

Hi Ben,

I’ve seen this link:

https://github.com/openhab/openhab/wiki/Mqttitude-Binding

but there are not info related how to understand the trace :) and I’m curious by nature eheh

thanks

Andrea

2015-01-17 1:10 GMT+01:00 Ben Jones <ben.j...@gmail.com>:

Have you read the wiki page for the Mqttitude binding? That should explain the different modes of operation.

--
You received this message because you are subscribed to a topic in the Google Groups "openhab" group.
To unsubscribe from this topic, visit https://groups.google.com/d/topic/openhab/gdAe0_OOP_o/unsubscribe.
To unsubscribe from this group and all its topics, send an email to openhab+u...@googlegroups.com.
To post to this group, send email to ope...@googlegroups.com.
Visit this group at http://groups.google.com/group/openhab.
To view this discussion on the web visit https://groups.google.com/d/msgid/openhab/e6b1825a-a0af-4bf1-b4bf-38dfd4f308f8%40googlegroups.com.

For more options, visit https://groups.google.com/d/optout.

[Andrea Riela]

Another question here.

Today I left my house (significant changes configured on Owntracks), when back I've seen my switch item ON. After a while, always at home, the switch became OFF.

Of course this is unattended.

Any idea?

Thank you very much for your support, i really appreciate.

Andrea

[Ben Jones]

So have you got a waypoint setup for home in Owntracks on your phone?

[Andrea Riela]

Yes of course. 200 meters for range in Owntracks

2015-01-17 3:35 GMT+01:00 Ben Jones <ben.j...@gmail.com>:

So have you got a waypoint setup for home in Owntracks on your phone?

--
You received this message because you are subscribed to a topic in the Google Groups "openhab" group.
To unsubscribe from this topic, visit https://groups.google.com/d/topic/openhab/gdAe0_OOP_o/unsubscribe.
To unsubscribe from this group and all its topics, send an email to openhab+u...@googlegroups.com.
To post to this group, send email to ope...@googlegroups.com.
Visit this group at http://groups.google.com/group/openhab.

To view this discussion on the web visit https://groups.google.com/d/msgid/openhab/62692b7c-a1e2-4054-bc69-263b056f046c%40googlegroups.com.

[Andrea Riela]

about trace. Everything is here: https://github.com/owntracks/owntracks/wiki/JSON

sorry, my mistake :)

can you help me understanding why now my item is OFF, even if I’m at home?

I will try another “tour” in few hours

;)

Andrea

[Andrea Riela]

First analysis of the trace.

I can see when I leaved the waypoint yesterday:

2015-01-16 17:37:47.587 [TRACE] [b.m.internal.MqttitudeConsumer] - Message received on topic owntracks/nesys/andrea: {"cog":-1,"lon":"9.13739","acc":"65","vel":-1,"_type":"location","event":"leave","vac":11,"lat":"45.4654","batt":"30","t":"c","tst":"1421426266","desc":"home","alt":122,"tid":"EA"}

2015-01-16 17:37:47.594 [TRACE] [b.m.internal.MqttitudeConsumer] - Checking item PresenceAndrea_MQTT...

2015-01-16 17:37:47.595 [DEBUG] [b.m.internal.MqttitudeConsumer] - PresenceAndrea_MQTT has left region home

and when I came back:

2015-01-16 18:04:21.556 [TRACE] [b.m.internal.MqttitudeConsumer] - Message received on topic owntracks/nesys/andrea: {"cog":-1,"lon":"9.13624","acc":"65","vel":-1,"_type":"location","event":"enter","vac":10,"lat":"45.4663","batt":"20","t":"c","tst":"1421427859","desc":"home","alt":121,"tid":"EA"}

2015-01-16 18:04:21.558 [TRACE] [b.m.internal.MqttitudeConsumer] - Checking item PresenceAndrea_MQTT...

2015-01-16 18:04:21.558 [DEBUG] [b.m.internal.MqttitudeConsumer] - PresenceAndrea_MQTT has entered region home

So, this sounds good :-)

then I can’t see any “leave” message, but I’ve restarted and changed some things (item name, …), so maybe now the item is empty. Let me check after next leaving, just in case ;) maybe this is correct for now ;)

Thanks again, I’m exploring for the first time MQTT, and I’m feeling like an explorer in a new world :)

Andrea

[Ben Jones]

Sounds like you have it working! Well done.

--
You received this message because you are subscribed to a topic in the Google Groups "openhab" group.
To unsubscribe from this topic, visit https://groups.google.com/d/topic/openhab/gdAe0_OOP_o/unsubscribe.
To unsubscribe from this group and all its topics, send an email to openhab+u...@googlegroups.com.
To post to this group, send email to ope...@googlegroups.com.
Visit this group at http://groups.google.com/group/openhab.

To view this discussion on the web visit https://groups.google.com/d/msgid/openhab/CANbOKYeYLy_2hRV_TuxSyuH-Qv_6S7MSw2O-3VESYgP4xuJUJA%40mail.gmail.com.

[Andrea Riela]

Thank you Ben,

just a question. I see when I restart openHAB the status of presence item is reset to OFF.

Maybe because I don’t implement persistence yet? Does make any sense?

Thanks

Andrea

[Ben Jones]

Yes, without persistence openHAB has no way of knowing what the previous state was after a restart.