Closed brettdaman closed 8 years ago
A little more debugging
The syslogd error seems unrelated, got the message while everything worked fine yesterday.
What i read in the docker logs
agile-core-BLE:
08:47:11.369 [Thread-8] INFO i.agile.protocol.ble.BLEProtocolImp - Protocol Notification:..�9
08:47:12.381 [Thread-8] INFO i.agile.protocol.ble.BLEProtocolImp - Protocol Notification:..�9
08:47:13.327 [Thread-8] INFO i.agile.protocol.ble.BLEProtocolImp - Protocol Notification:..�9
08:47:14.339 [Thread-8] INFO i.agile.protocol.ble.BLEProtocolImp - Protocol Notification:..�9
08:47:15.351 [Thread-8] INFO i.agile.protocol.ble.BLEProtocolImp - Protocol Notification:..�9
08:47:16.364 [Thread-8] INFO i.agile.protocol.ble.BLEProtocolImp - Protocol Notification:..�9
08:47:17.377 [Thread-8] INFO i.agile.protocol.ble.BLEProtocolImp - Protocol Notification:..�9
08:47:18.321 [Thread-8] INFO i.agile.protocol.ble.BLEProtocolImp - Protocol Notification:..�9
08:47:19.334 [Thread-8] INFO i.agile.protocol.ble.BLEProtocolImp - Protocol Notification:..B9
agile-core-DeviceManager:
08:47:20.352 [Thread-1] INFO i.a.devicemanager.device.DeviceImp - Device notification component Optical value 152.96
08:47:21.364 [Thread-1] INFO i.a.devicemanager.device.DeviceImp - Device notification component Optical value 155.56
08:47:22.377 [Thread-1] INFO i.a.devicemanager.device.DeviceImp - Device notification component Optical value 152.96
08:47:23.389 [Thread-1] INFO i.a.devicemanager.device.DeviceImp - Device notification component Optical value 152.32
08:47:24.334 [Thread-1] INFO i.a.devicemanager.device.DeviceImp - Device notification component Optical value 151.36
08:47:25.347 [Thread-1] INFO i.a.devicemanager.device.DeviceImp - Device notification component Optical value 150.36
08:47:26.360 [Thread-1] INFO i.a.devicemanager.device.DeviceImp - Device notification component Optical value 148.76
08:47:27.398 [Thread-1] INFO i.a.devicemanager.device.DeviceImp - Device notification component Optical value 148.12
agile-core-http, agile-core-ProtocolManager (have no usefull logs conserning this issue)
So the values are still read from the sensor, but they are not send over the websocket. Is it possible to close and reopen the socket and still see the subscribed stream? At the moment if I close the socket I cant get the data back and need to restart the dockers and reinit.
got since the latest update also usefull errorlog from agile-core-http:
http: New value iot.agile.object.RecordObject<B0:B4:48:BE:7D:83, Optical, 90.76, Light intensity (W/sr), , 1474295522575>
http: New value iot.agile.object.RecordObject<B0:B4:48:BE:7D:83, Optical, 90.76, Light intensity (W/sr), , 1474295522575>
[WARNING]
org.eclipse.jetty.websocket.api.WebSocketException: RemoteEndpoint unavailable, current state [CLOSED], expecting [OPEN or CONNECTED]
at org.eclipse.jetty.websocket.common.WebSocketSession.getRemote(WebSocketSession.java:308)
at iot.agile.http.ws.AgileWebSocketAdapter$1.handle(AgileWebSocketAdapter.java:55)
at iot.agile.http.ws.AgileWebSocketAdapter$1.handle(AgileWebSocketAdapter.java:49)
at org.freedesktop.dbus.AbstractConnection$2.run(Unknown Source)
at org.freedesktop.dbus.AbstractConnection$_workerthread.run(Unknown Source)
http: New value iot.agile.object.RecordObject<B0:B4:48:BE:7D:83, Optical, 79.2, Light intensity (W/sr), , 1474295523581>
http: New value iot.agile.object.RecordObject<B0:B4:48:BE:7D:83, Optical, 79.2, Light intensity (W/sr), , 1474295523581>
[WARNING]
org.eclipse.jetty.websocket.api.WebSocketException: RemoteEndpoint unavailable, current state [CLOSED], expecting [OPEN or CONNECTED]
at org.eclipse.jetty.websocket.common.WebSocketSession.getRemote(WebSocketSession.java:308)
at iot.agile.http.ws.AgileWebSocketAdapter$1.handle(AgileWebSocketAdapter.java:55)
at iot.agile.http.ws.AgileWebSocketAdapter$1.handle(AgileWebSocketAdapter.java:49)
at org.freedesktop.dbus.AbstractConnection$2.run(Unknown Source)
at org.freedesktop.dbus.AbstractConnection$_workerthread.run(Unknown Source)
http: New value iot.agile.object.RecordObject<B0:B4:48:BE:7D:83, Optical, 89.16, Light intensity (W/sr), , 1474295524594>
http: New value iot.agile.object.RecordObject<B0:B4:48:BE:7D:83, Optical, 89.16, Light intensity (W/sr), , 1474295524594>
[WARNING]
org.eclipse.jetty.websocket.api.WebSocketException: RemoteEndpoint unavailable, current state [CLOSED], expecting [OPEN or CONNECTED]
at org.eclipse.jetty.websocket.common.WebSocketSession.getRemote(WebSocketSession.java:308)
at iot.agile.http.ws.AgileWebSocketAdapter$1.handle(AgileWebSocketAdapter.java:55)
at iot.agile.http.ws.AgileWebSocketAdapter$1.handle(AgileWebSocketAdapter.java:49)
at org.freedesktop.dbus.AbstractConnection$2.run(Unknown Source)
at org.freedesktop.dbus.AbstractConnection$_workerthread.run(Unknown Source)
http: New value iot.agile.object.RecordObject<B0:B4:48:BE:7D:83, Optical, 87.72, Light intensity (W/sr), , 1474295525606>
[WARNING]
org.eclipse.jetty.websocket.api.WebSocketException: RemoteEndpoint unavailable, current state [CLOSED], expecting [OPEN or CONNECTED]
at org.eclipse.jetty.websocket.common.WebSocketSession.getRemote(WebSocketSession.java:308)
at iot.agile.http.ws.AgileWebSocketAdapter$1.handle(AgileWebSocketAdapter.java:55)
at iot.agile.http.ws.AgileWebSocketAdapter$1.handle(AgileWebSocketAdapter.java:49)
at org.freedesktop.dbus.AbstractConnection$2.run(Unknown Source)
at org.freedesktop.dbus.AbstractConnection$_workerthread.run(Unknown Source)
I see no reason why the WS would be closed from server side, except if the TCP connection fails. I have now added explicit handling and logging for WS close. Soon we also push updates to the D-Bus part, to handle multiple and repeated subscriptions.
Restarting websockets should work now after https://github.com/Agile-IoT/agile-core/commit/14c47c306835504af1334aae51c317ca2a330397
I found out that I need to be first connected with the socket and then subscribe, if I do it that way i get updates from my sensor, but after a while it stops. If I check my pi I see a syslogd message. I can only get it working again by restarting the containers.
Message from syslogd@agile-pi at Sep 16 14:09:53 ... kernel:[ 2360.366538] unregister_netdevice: waiting for lo to become free. Usage count = 1