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.
I’m attaching a small section of openhab.log in the hope that someone more knowledgeable can see the cause.
TIA
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]