OH1 OwnTracks... not getting anywhere

Thanks for getting back to me.
Short answer: No.

I have a simple (default) mqtt set-up that works…
Nothing but default settings in OH and mosquitto; no password, etc.
Exception from default: I do have a second listener defined on port 8883; though TLS)

OH and mqtt is working; e.g.

2017-01-17 16:23:58 - Network_Router_LAN state updated to ON
2017-01-17 16:23:58 - Network_ATA state updated to ON
2017-01-17 16:24:00 - Hub_BorePump_Demand state updated to ON
2017-01-17 16:24:00 - Bore_Pump_Status state updated to ON
2017-01-17 16:24:01 - mobMaxG state updated to present
2017-01-17 16:24:14 - Weather_Humidity state updated to 45
2017-01-17 16:24:14 - Weather_Temperature state updated to 32
2017-01-17 16:24:14 - Weather_LastUpdate state updated to 2017-01-17T16:24:14
2017-01-17 16:24:15 - Hub_BorePump_Demand state updated to ON
2017-01-17 16:24:15 - Bore_Pump_Status state updated to ON
2017-01-17 16:24:16 - Tank_Irrigation_Demand state updated to ON
2017-01-17 16:24:17 - Tank_Irrigation_Level state updated to 2

E.g. Tank, Bore, Hub are all MQTT message based.

The iPhone at present connects via local WiFi.
However, I publish the originally received messages for enter and leave to test mqttitude in OH.
Subscribing to the same topic (via terminal) will show the very same message.

Yes, I am not sure why I have owntracks/owntracks in the topic; as the examples I see do not.
But this does not matter ATM, nor does not seem to be the problem.
As you said: it seems to register / subscribe to this msg.

Yep so checking the source code (which I wrote many years ago ;)) there is definitely trace logging configured to help debug these sorts of issues. Any message received by the binding subscription is logged via;

logger.trace("Message received on topic {}: {}", topic, decoded);

The fact you are not seeing these either means your logging is not configured correctly, or for some reason the messages are not getting thru to the binding. The fact the Registering Mqttitude consumer for xxx is being logged seems to mean your item config is correct.

I would focus on the logging side of things I think.

Thanks… will do…
though I do not know what to look for, this is my entry:

<logger name="org.openhab.binding.mqttitude" level="TRACE" />

since these entries do work (enabled disabled weather and exec):

        <!-- 170171 MaxG log levels are: OFF, ERROR, WARN, INFO, DEBUG, TRACE -->

        <!-- 160626 MaxG enabled logging for weather binding -->
        <!-- logger name="org.openhab.binding.weather" level="DEBUG" /-->

        <!-- 160730 MaxG added to log test msgs to info -->
        <!-- logger name="org.openhab.model.script.test" level="DEBUG" /-->

        <!-- 160918 MaxG added to log exec binding -->
        <!-- logger name="org.openhab.binding.exec" level="DEBUG" /-->

Can someone please confirm, whether I named the log entry for mqttitude correctly?

That logging config looks fine. I just checked again and the only place that there is trace logging is inside the MQTT consumer, meaning if you don’t receive any messages you won’t see anything extra in the logging.

So it perhaps means that for some reason openHAB isn’t receiving those pubs to that topic.

Can you do a mosquitto_sub using the same user/pwd as openHAB uses and then do your test pub to that topic and make sure it is appearing?

I think I did not specify a user / pw for OH to connect to.
my openhab.conf mqtt section is:

mqtt:mymosquitto.url=tcp://localhost:1883
mqtt:mymosquitto.clientId=openhab
mqtt:mymosquitto.qos=0
mqtt:mymosquitto.retain=true
mqtt:mymosquitto.async=true

there is also no longer a mqttitude config (removed earlier on your advice)

I quickly created a String item…

String mqttitudeTest "mqttitudeTest [%s]" {mqtt="<[mymosquitto:owntracks/owntracks/maxg-iphone/event:state:default]"}

.sitemap

        Text item=mqttitudeTest

and it logs:

2017-01-17 19:33:11 - mqttitudeTest state updated to {"desc":"Home","t":"c","tst":1484616290,"acc":50,"lon":152.3871252314675,"_type":"transition","wtst":1484570767,"lat":-27.32542779299181,"event":"leave","tid":"MG"}

so OH can subscribe / work this particular publish command.

Also, re-installed the binding with apt-get, same log msgs and behaviour. My initial install was simply dropping the binding into ‘addons’.

Are we on the same page? OH 1.8.3
Just saw another post having the same issue in 1.9.0. (OH2).
Maybe this is related?

When I add a debug item that subscribes to messages on the same topic I get messages so that would, in my case, rule out a configuration error in mqtt.conf.

I haven’t moved the phone out of the geofence or spoofed any MQTT-messages so I in order to confirm that the MQTT configuration works I subscribed directly to the device topic and not to the /event topic.

13:32:02.523 [INFO ] [marthome.event.ItemStateChangedEvent] - mqttitudeTest changed from {"_type":"location","tid":"ik","acc":9,"batt":67,"conn":"w","doze":false,"lat":XX.XXXXXXX,"lon":YY.YYYYYYY,"tst":1484655994} to {"_type":"location","tid":"ik","acc":30,"batt":67,"conn":"w","doze":false,lat":XX.XXXXXXX,"lon":YY.YYYYYYY,"tst":1484656321}

Debug Item:

String mqttitudeTest "mqttitudeTest [%s]" {mqtt="<[mqttloc:owntracks/<user>/<device>:state:default]"}

I personally am running 1.8.3. Sounds like Fredrik has got his issue sorted. Since you have proven that your MQTT broker is receiving those messages I think the only thing left is your item config (but I am not sure what).

Can you post your full items config currently? I would suggest paring it right back to a single Switch item to remove any confusion and see if we can make any progress with that.

… was only asking… :slight_smile:

.sitemap

        Switch item=GeoLoc_MaxHome	icon="present"

.items

Switch   GeoLoc_MaxHome		"Max @ Home [%s]"		{mqttitude="mosquitto:owntracks/owntracks/maxg-iphone/event:Home"}

logback.xml

<logger name="org.openhab.binding.mqttitude" level="TRACE" />

no entry related to mqttitude in openhab.conf
mosquitto (has been and) is running nicely
mqttitude does not seem to process the messages.

After reducing the items config to one switch, I rebooted the rPi (just to be sure)

On a side note: if you have 1.8.3 running, why not check the log level by adding TRACE to the logger, and see, what the outcome of openhab.log is. Even if I set it to TRACE it says DEBUG in the log. (The same with the EXEC and Yahoo weather binding); so I doubt that the openhab.log will show TRACE as a word; whether this affects its inner working; e.g. whether it does actually do TRACE I cannot tell.

In any case, thank you for your continued help with this issue.

@westermarck: As you can see in a previous post, I have done exactly the same. In my case (as I suspect in yours) mosquitto is working. But the mqttitude binding, despite subscribing to the OwnTracks topic does not seem to process any of it.

And you are still seeing the mqttitude debug message that it is subscribing to the appropriate topic?

yes…

2017-01-18 07:54:27.398 [INFO ] [penhab.io.rest.RESTApplication] - Stopped REST API
2017-01-18 07:55:03.650 [INFO ] [.o.core.internal.CoreActivator] - openHAB runtime has been started (v1.8.3).
2017-01-18 07:55:08.763 [INFO ] [o.o.i.s.i.DiscoveryServiceImpl] - mDNS service has been started
2017-01-18 07:55:09.003 [INFO ] [o.o.i.s.i.DiscoveryServiceImpl] - Service Discovery initialization completed.
2017-01-18 07:55:09.025 [INFO ] [.io.transport.mqtt.MqttService] - MQTT Service initialization completed.
2017-01-18 07:55:09.030 [INFO ] [o.i.t.m.i.MqttBrokerConnection] - Starting MQTT broker connection 'mymosquitto'
2017-01-18 07:55:18.396 [INFO ] [penhab.io.rest.RESTApplication] - Started REST API at /rest
2017-01-18 07:55:23.961 [INFO ] [.o.u.w.i.servlet.WebAppServlet] - Started Classic UI at /classicui/openhab.app
2017-01-18 07:55:26.686 [INFO ] [c.internal.ModelRepositoryImpl] - Loading model 'max01.items'
2017-01-18 07:55:27.326 [INFO ] [c.internal.ModelRepositoryImpl] - Loading model 'lights.items'
2017-01-18 07:55:27.522 [INFO ] [c.internal.ModelRepositoryImpl] - Loading model 'groups.items'
2017-01-18 07:55:27.666 [INFO ] [c.internal.ModelRepositoryImpl] - Loading model 'openings.items'
2017-01-18 07:55:29.441 [DEBUG] [.m.internal.MqttitudeActivator] - Mqttitude binding has been started.
2017-01-18 07:55:29.504 [DEBUG] [.b.m.internal.MqttitudeBinding] - Registering Mqttitude consumer for owntracks/owntracks/maxg-iphone/event (on mosquitto)
2017-01-18 07:55:29.507 [DEBUG] [.b.m.internal.MqttitudeBinding] - Activating Mqttitude binding
2017-01-18 07:55:29.728 [INFO ] [.b.a.internal.bus.AstroBinding] - AstroConfig[latitude=-27.3164855,longitude=152.3701568,interval=60,systemTimezone=Austral$
2017-01-18 07:55:29.742 [INFO ] [.p.rrd4j.internal.RRD4jService] - Removing invalid defintion component = null heartbeat = 0 min/max = 0.0/0.0 step = 0 0 ar$
2017-01-18 07:55:29.905 [INFO ] [c.internal.ModelRepositoryImpl] - Loading model 'logging.persist'
2017-01-18 07:55:30.024 [INFO ] [c.internal.ModelRepositoryImpl] - Loading model 'mapdb.persist'
2017-01-18 07:55:30.064 [INFO ] [c.internal.ModelRepositoryImpl] - Loading model 'db4o.persist'
2017-01-18 07:55:30.105 [INFO ] [c.internal.ModelRepositoryImpl] - Loading model 'rrd4j.persist'
2017-01-18 07:55:30.659 [INFO ] [c.internal.ModelRepositoryImpl] - Loading model 'exec.persist'
2017-01-18 07:55:30.808 [WARN ] [o.p.m.i.MqttPersistenceService] - mqtt-persistence:broker
2017-01-18 07:55:30.812 [WARN ] [o.p.m.i.MqttPersistenceService] - mqtt-persistence:topic
2017-01-18 07:55:30.815 [WARN ] [o.p.m.i.MqttPersistenceService] - mqtt-persistence:message
2017-01-18 07:55:31.285 [INFO ] [o.o.b.w.i.common.WeatherConfig] - LocationConfig[providerName=YAHOO,language=en,updateInterval=10,latitude=<null>,longitude$
2017-01-18 07:55:32.750 [INFO ] [.b.a.internal.job.JobScheduler] - Scheduled a daily job at midnight for astro calculation
2017-01-18 07:55:32.765 [INFO ] [.b.a.internal.job.JobScheduler] - Scheduled astro job with interval of 60 seconds

I am at a loss then sorry :frowning:

That’s OK… appreciate your help…

Will move to plan B – calculating the distance, etc via captured mosquitto strings and rules :slight_smile:

Maybe you (or someone else) can clarify one thing:
If logging is set to TRACE (n logbakc.xml), does it show as TRACE or DEBUG in the openhab.log?

I am close to 100% certain it will be shown as TRACE.

It is a shame, as this binding has been working flawlessly for me for years. Can’t understand why you are having such troubles!

Have you tried to do what I did in the mqttitude.conf in order for it to pick up the configuration changes?

I removed the values (commenting them out is not the same). I ended up with a mqttitude.conf that only contains the following:

home.lat=
home.lon=
geofence=

Be aware you are on OH 2 and I am on OH1 = different binding versions.
I did the mosquitto item and it works…
… and have no entries related to mqttitude in the openhab.conf
But why not; will try the empty entries :slight_smile:

@ben_jones12: don’t stress about it; I feel you’ve done the best you could…
sometimes there things beyond what we see…

OK, added the mqttitude section in openhab.conf with uncommented parameters and leaving them ‘empty’… result:

after restart with mqttitude empty values
2017-01-18 10:32:47.913 [INFO ] [.io.transport.mqtt.MqttService] - MQTT Service initialization completed.
2017-01-18 10:32:47.918 [INFO ] [o.i.t.m.i.MqttBrokerConnection] - Starting MQTT broker connection 'mymosquitto'
2017-01-18 10:33:07.715 [DEBUG] [.m.internal.MqttitudeActivator] - Mqttitude binding has been started.
2017-01-18 10:33:07.777 [DEBUG] [.b.m.internal.MqttitudeBinding] - Registering Mqttitude consumer for owntracks/owntracks/maxg-iphone/event (on mosquitto)
2017-01-18 10:33:07.780 [DEBUG] [.b.m.internal.MqttitudeBinding] - Activating Mqttitude binding
2017-01-18 10:33:07.785 [DEBUG] [.b.m.internal.MqttitudeBinding] - Mqttitude binding configuration updated, no 'home' location specified. All item bindings must be configured with a <region>.
2017-01-18 10:33:07.792 [DEBUG] [.b.m.internal.MqttitudeBinding] - Unregistering Mqttitude consumer for owntracks/owntracks/maxg-iphone/event (on mosquitto)
2017-01-18 10:33:07.802 [DEBUG] [.b.m.internal.MqttitudeBinding] - Registering Mqttitude consumer for owntracks/owntracks/maxg-iphone/event (on mosquitto)
2017-01-18 10:33:08.974 [WARN ] [o.p.m.i.MqttPersistenceService] - mqtt-persistence:broker
2017-01-18 10:33:08.975 [WARN ] [o.p.m.i.MqttPersistenceService] - mqtt-persistence:topic
2017-01-18 10:33:08.977 [WARN ] [o.p.m.i.MqttPersistenceService] - mqtt-persistence:message

msoquitto log:

1484699546: Socket error on client openhab, disconnecting.
1484699568: New connection from 127.0.0.1 on port 1883.
1484699568: New client connected from 127.0.0.1 as openhab (c1, k60).
1484699760: New connection from ::1 on port 1883.
1484699760: New client connected from ::1 as mosqpub/14933-rpiautoma (c1, k60).
1484699760: Client mosqpub/14933-rpiautoma disconnected.
1484699793: New connection from ::1 on port 1883.

… in essence no change, and no TRACE messages or further DEBUG messages when publishing the owntracks messages…

I say: let’s give it a rest… and I do Plan B :slight_smile:

Hang on - your item binding is using mosquitto as the broker name, but it looks like the MQTT binding is named mymosquitto in your log above?

1 Like

I do not understand the inner workings of OH or mqtt… but the mosquitto.log shows and entry at epoch 1484699760 (18 January 2017 10:36:00 GMT+10:00) connecting and disconnecting a mosqoub on rpiAutomation… could this a problem.
I did not define this name; so it must be auto assigned??
Is this relevant?

Can you try…

Switch   GeoLoc_MaxHome		"Max @ Home [%s]"		{mqttitude="mymosquitto:owntracks/owntracks/maxg-iphone/event:Home"}