Sensor data not visible in BasicUI (openhabian/RasPi)

After a new reinstall of Openhabian latest version and MQTT on RasPi, I have data coming through to MQTT (seen on MQTTspy) and also showing in the Openhab event log. BUT no values are appearing in the BasicUI nor the ClassicUI.

I must be missing something. Advice please on how to diagnose the problem.
TIA
Andrew

Step 1 is, as always: check your log files.
Step 2 is recheck your log files in DEBUG mode.

Hi @namraccr, and thanks for your reply.
I had already checked the log file (using frontail - a brilliant recent addition!) - no errors found.
So I need to to Step 2 next. How do I get DEBUG mode?

Have you tried editing/saving your sitemap file and checked openhab.log for any syntax errors?

Hello, @lfs_alp5,
Thanks for your suggestion. Just tried opening the sitemap file and writing it back (no actual changes made) and in openhab.log I just see a “refreshing sitemap” message, no errors or warnings.

In the meantime, I’ve found how to get into Karaf console. I’m trying ot set DEBUG level, but I can’t find any info about what goes after “log:set DEBUG”. All I’ve managed to find is referring to bindings, but I think I need something more general to cover the basic data handling in openhab and sending it to the UI’s. How do I specify that?

EDIT: just tried simply “log:set DEBUG” with nothing after it, and it seems to have worked! (wish this was documented somewhere easy to find!!)
I’m now getting lots and lots of extra messages in Frontail - need to study them and work out what they are telling me.

At least I’m making progress.
Thanks to you and @namraccr for your help.

You can specify a specific binding for debug like this:

log:set DEBUG org.openhab.binding.zwave

(There’s some references to this here)

Well, I got absolutely LOTS of messages in openhab.log after using the Karaf command “log:set DEBUG”. Trouble is, I don’t know what I should see, and whether any of the messages are indicating the cause of my problem. :frowning:

I’m attaching a small section of openhab.log in the hope that someone more knowledgeable can see the cause.
TIA :grinning:

2017-08-14 14:22:20.688 [DEBUG] [client.mqttv3.internal.CommsCallback] - openhabian: new msg avail, notify workAvailable
2017-08-14 14:22:20.690 [DEBUG] [client.mqttv3.internal.CommsCallback] - openhabian: call messageArrived key=0 topic=ESPeasy6_DHW/DS18B5/Temp5
2017-08-14 14:22:20.691 [DEBUG] [client.mqttv3.internal.CommsReceiver] - openhabian: network read message
2017-08-14 14:22:20.692 [DEBUG] [client.mqttv3.internal.CommsCallback] - openhabian: notify spaceAvailable
2017-08-14 14:22:20.694 [DEBUG] [client.mqttv3.internal.CommsCallback] - openhabian: wait for workAvailable
2017-08-14 14:22:20.701 [DEBUG] [.eclipse.jetty.server.HttpConnection] - org.eclipse.jetty.server.HttpConnection$SendCallback@1578b03[PROCESSING][i=null,cb=Blocker@123c677{null}] generate: FLUSH (null,[p=0,l=156,c=32768,r=156],false)@COMMITTED
2017-08-14 14:22:20.703 [DEBUG] [org.eclipse.jetty.io.WriteFlusher   ] - write: WriteFlusher@f5ba64{IDLE} [HeapByteBuffer@1658445[p=0,l=156,c=32768,r=156]={<<<event: message\nda...mStateEvent"}\n\n>>>\n\n\\"oldValue\\":\\"...\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00}]
2017-08-14 14:22:20.705 [DEBUG] [org.eclipse.jetty.io.WriteFlusher   ] - update WriteFlusher@f5ba64{WRITING}:IDLE-->WRITING
2017-08-14 14:22:20.711 [DEBUG] [org.eclipse.jetty.io.ChannelEndPoint] - flushed 156 SelectChannelEndPoint@1962f74{/127.0.0.1:45780<->8080,Open,in,out,-,W,1033/30000,HttpConnection}{io=0,kio=0,kro=1}
2017-08-14 14:22:20.712 [DEBUG] [org.eclipse.jetty.io.WriteFlusher   ] - update WriteFlusher@f5ba64{IDLE}:WRITING-->IDLE
2017-08-14 14:22:20.714 [DEBUG] [.eclipse.jetty.server.HttpConnection] - org.eclipse.jetty.server.HttpConnection$SendCallback@1578b03[PROCESSING][i=null,cb=Blocker@123c677{null}] generate: DONE (null,[p=156,l=156,c=32768,r=0],false)@COMMITTED
2017-08-14 14:22:20.718 [DEBUG] [.eclipse.jetty.server.HttpConnection] - org.eclipse.jetty.server.HttpConnection$SendCallback@1592d3a[PROCESSING][i=null,cb=Blocker@466fb8{null}] generate: FLUSH (null,[p=0,l=156,c=32768,r=156],false)@COMMITTED
2017-08-14 14:22:20.720 [DEBUG] [org.eclipse.jetty.io.WriteFlusher   ] - write: WriteFlusher@331097{IDLE} [HeapByteBuffer@b3dbe4[p=0,l=156,c=32768,r=156]={<<<event: message\nda...mStateEvent"}\n\n>>>\n\n\\"oldValue\\":\\"...\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00}]
2017-08-14 14:22:20.722 [DEBUG] [org.eclipse.jetty.io.WriteFlusher   ] - update WriteFlusher@331097{WRITING}:IDLE-->WRITING
2017-08-14 14:22:20.724 [DEBUG] [org.eclipse.jetty.io.ChannelEndPoint] - flushed 156 SelectChannelEndPoint@11b1b{/127.0.0.1:45782<->8080,Open,in,out,-,W,1039/30000,HttpConnection}{io=0,kio=0,kro=1}
2017-08-14 14:22:20.726 [DEBUG] [org.eclipse.jetty.io.WriteFlusher   ] - update WriteFlusher@331097{IDLE}:WRITING-->IDLE
2017-08-14 14:22:20.728 [DEBUG] [.eclipse.jetty.server.HttpConnection] - org.eclipse.jetty.server.HttpConnection$SendCallback@1592d3a[PROCESSING][i=null,cb=Blocker@466fb8{null}] generate: DONE (null,[p=156,l=156,c=32768,r=0],false)@COMMITTED
2017-08-14 14:22:20.731 [DEBUG] [.eclipse.jetty.server.HttpConnection] - org.eclipse.jetty.server.HttpConnection$SendCallback@1578b03[PROCESSING][i=null,cb=Blocker@123c677{null}] generate: FLUSH (null,[p=0,l=216,c=32768,r=216],false)@COMMITTED
2017-08-14 14:22:20.732 [DEBUG] [org.eclipse.jetty.io.WriteFlusher   ] - write: WriteFlusher@f5ba64{IDLE} [HeapByteBuffer@1658445[p=0,l=216,c=32768,r=216]={<<<event: message\nda...hangedEvent"}\n\n>>>\n93 1.39-.93h9.16...\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00}]
2017-08-14 14:22:20.733 [DEBUG] [org.eclipse.jetty.io.WriteFlusher   ] - update WriteFlusher@f5ba64{WRITING}:IDLE-->WRITING
2017-08-14 14:22:20.734 [DEBUG] [org.eclipse.jetty.io.ChannelEndPoint] - flushed 216 SelectChannelEndPoint@1962f74{/127.0.0.1:45780<->8080,Open,in,out,-,W,22/30000,HttpConnection}{io=0,kio=0,kro=1}
2017-08-14 14:22:20.736 [DEBUG] [org.eclipse.jetty.io.WriteFlusher   ] - update WriteFlusher@f5ba64{IDLE}:WRITING-->IDLE
2017-08-14 14:22:20.737 [DEBUG] [.eclipse.jetty.server.HttpConnection] - org.eclipse.jetty.server.HttpConnection$SendCallback@1578b03[PROCESSING][i=null,cb=Blocker@123c677{null}] generate: DONE (null,[p=216,l=216,c=32768,r=0],false)@COMMITTED
2017-08-14 14:22:20.740 [DEBUG] [.eclipse.jetty.server.HttpConnection] - org.eclipse.jetty.server.HttpConnection$SendCallback@1592d3a[PROCESSING][i=null,cb=Blocker@466fb8{null}] generate: FLUSH (null,[p=0,l=216,c=32768,r=216],false)@COMMITTED
2017-08-14 14:22:20.741 [DEBUG] [org.eclipse.jetty.io.WriteFlusher   ] - write: WriteFlusher@331097{IDLE} [HeapByteBuffer@b3dbe4[p=0,l=216,c=32768,r=216]={<<<event: message\nda...hangedEvent"}\n\n>>>\nup","name":"gGF"...\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00}]
2017-08-14 14:22:20.742 [DEBUG] [org.eclipse.jetty.io.WriteFlusher   ] - update WriteFlusher@331097{WRITING}:IDLE-->WRITING
2017-08-14 14:22:20.744 [DEBUG] [org.eclipse.jetty.io.ChannelEndPoint] - flushed 216 SelectChannelEndPoint@11b1b{/127.0.0.1:45782<->8080,Open,in,out,-,W,17/30000,HttpConnection}{io=0,kio=0,kro=1}
2017-08-14 14:22:20.745 [DEBUG] [org.eclipse.jetty.io.WriteFlusher   ] - update WriteFlusher@331097{IDLE}:WRITING-->IDLE
2017-08-14 14:22:20.746 [DEBUG] [.eclipse.jetty.server.HttpConnection] - org.eclipse.jetty.server.HttpConnection$SendCallback@1592d3a[PROCESSING][i=null,cb=Blocker@466fb8{null}] generate: DONE (null,[p=216,l=216,c=32768,r=0],false)@COMMITTED
2017-08-14 14:22:20.917 [DEBUG] [.conn.PoolingClientConnectionManager] - Connection request: [route: {}->http://192.168.1.5:49153][total kept alive: 2; route allocated: 0 of 100; total allocated: 2 of 1024]
2017-08-14 14:22:20.921 [DEBUG] [.conn.PoolingClientConnectionManager] - Connection leased: [id: 39][route: {}->http://192.168.1.5:49153][total kept alive: 2; route allocated: 1 of 100; total allocated: 3 of 1024]
2017-08-14 14:22:20.923 [DEBUG] [conn.DefaultClientConnectionOperator] - Connecting to 192.168.1.5:49153
2017-08-14 14:22:20.953 [DEBUG] [tp.client.protocol.RequestAddCookies] - CookieSpec selected: best-match
2017-08-14 14:22:20.954 [DEBUG] [ttp.client.protocol.RequestAuthCache] - Auth cache not set in the context
2017-08-14 14:22:20.955 [DEBUG] [protocol.RequestTargetAuthentication] - Target auth state: UNCHALLENGED
2017-08-14 14:22:20.955 [DEBUG] [.protocol.RequestProxyAuthentication] - Proxy auth state: UNCHALLENGED
2017-08-14 14:22:20.956 [DEBUG] [e.http.impl.client.DefaultHttpClient] - Attempt 1 to execute request
2017-08-14 14:22:20.956 [DEBUG] [tp.impl.conn.DefaultClientConnection] - Sending request: GET /description3.xml HTTP/1.1
2017-08-14 14:22:20.957 [DEBUG] [org.apache.http.wire                ] - >> "GET /description3.xml HTTP/1.1[\r][\n]"
2017-08-14 14:22:20.957 [DEBUG] [org.apache.http.wire                ] - >> "Host: 192.168.1.5:49153[\r][\n]"
2017-08-14 14:22:20.958 [DEBUG] [org.apache.http.wire                ] - >> "Connection: Keep-Alive[\r][\n]"
2017-08-14 14:22:20.958 [DEBUG] [org.apache.http.wire                ] - >> "User-Agent: Linux/4.9.35-v7 UPnP/1.0 jUPnP/2.0[\r][\n]"
2017-08-14 14:22:20.959 [DEBUG] [org.apache.http.wire                ] - >> "[\r][\n]"
2017-08-14 14:22:20.960 [DEBUG] [org.apache.http.headers             ] - >> GET /description3.xml HTTP/1.1
2017-08-14 14:22:20.960 [DEBUG] [org.apache.http.headers             ] - >> Host: 192.168.1.5:49153
2017-08-14 14:22:20.960 [DEBUG] [org.apache.http.headers             ] - >> Connection: Keep-Alive
2017-08-14 14:22:20.961 [DEBUG] [org.apache.http.headers             ] - >> User-Agent: Linux/4.9.35-v7 UPnP/1.0 jUPnP/2.0
2017-08-14 14:22:21.038 [DEBUG] [org.apache.http.wire                ] - << "HTTP/1.1 401 Unauthorized[\r][\n]"
2017-08-14 14:22:21.038 [DEBUG] [org.apache.http.wire                ] - << "SERVER: Linux/2.6.18.8 UPnP/1.0 SKY DLNADOC/1.50[\r][\n]"
2017-08-14 14:22:21.039 [DEBUG] [org.apache.http.wire                ] - << "CONNECTION: close[\r][\n]"
2017-08-14 14:22:21.040 [DEBUG] [org.apache.http.wire                ] - << "[\r][\n]"
2017-08-14 14:22:21.040 [DEBUG] [tp.impl.conn.DefaultClientConnection] - Receiving response: HTTP/1.1 401 Unauthorized
2017-08-14 14:22:21.041 [DEBUG] [org.apache.http.headers             ] - << HTTP/1.1 401 Unauthorized
2017-08-14 14:22:21.041 [DEBUG] [org.apache.http.headers             ] - << SERVER: Linux/2.6.18.8 UPnP/1.0 SKY DLNADOC/1.50
2017-08-14 14:22:21.042 [DEBUG] [org.apache.http.headers             ] - << CONNECTION: close
2017-08-14 14:22:21.043 [DEBUG] [e.http.impl.client.DefaultHttpClient] - Authentication required
2017-08-14 14:22:21.043 [DEBUG] [e.http.impl.client.DefaultHttpClient] - 192.168.1.5:49153 requested authentication
2017-08-14 14:22:21.044 [DEBUG] [e.http.impl.client.DefaultHttpClient] - Response contains no authentication challenges
2017-08-14 14:22:21.075 [DEBUG] [tp.impl.conn.DefaultClientConnection] - Connection 0.0.0.0:59264<->192.168.1.5:49153 closed
2017-08-14 14:22:21.076 [DEBUG] [.conn.PoolingClientConnectionManager] - Connection released: [id: 39][route: {}->http://192.168.1.5:49153][total kept alive: 2; route allocated: 0 of 100; total allocated: 2 of 1024]
2017-08-14 14:22:22.097 [DEBUG] [o.client.mqttv3.internal.ClientState] - openhabian: received bytes count=1
2017-08-14 14:22:22.098 [DEBUG] [o.client.mqttv3.internal.ClientState] - openhabian: received bytes count=29
2017-08-14 14:22:22.099 [DEBUG] [mqttv3.internal.wire.MqttInputStream] - null: Automatic Reconnect Successful: PUBLISH qos:0 retained:false dup:false topic:"ESPeasy3/deltaT/deltatFR" payload:[hex:352e39 utf8:"5.9" length:3]
2017-08-14 14:22:22.100 [DEBUG] [o.client.mqttv3.internal.ClientState] - openhabian: received key=0 message=PUBLISH qos:0 retained:false dup:false topic:"ESPeasy3/deltaT/deltatFR" payload:[hex:352e39 utf8:"5.9" length:3]

Likely next steps:
Turn off debugging for everything EXCEPT mqtt.
Recheck the log after sending/receiving some mqtt messages.
Check your items/sitemap.