WebThingsIO / thing-url-adapter

Proxy adapter for Web Thing API endpoints
Mozilla Public License 2.0
22 stars 18 forks source link

thing-url-adapter will sometimes continuously reopen websockets #45

Closed dhylands closed 4 years ago

dhylands commented 6 years ago

I was using this hash of the thing-url-adapter eb18917e637a6c38c6061257a5e7f074e45d0cdd and d0d44dc3dcf4c4f8f53fe4ea735007121b3e0eb2 of the gateway running under ubuntu 18.04.

I was using my SparkFun ESP32 Thing, which I had left running overnight. Sometime during the night it crashed. I disabled and re-enabled the thing-url-adpter (the ESP32 Thing wasn't running). I had previously put some prints in the thing-url-adapter and when it started up, it started doing this:

2018-05-23 08:50:30.054 Unloading ThingURLAdapter
2018-05-23 08:50:30.059 thing-url: closeWebSocket ws://192.168.1.86:80/0
2018-05-23 08:50:30.061 thing-url: closeWebSocket ws://192.168.1.86:80/1
2018-05-23 08:50:30.061 thing-url: Adapter: ThingURLAdapter unloaded
2018-05-23 08:50:30.947 thing-url: cleanupAndReopen ws://192.168.1.86:80/1
2018-05-23 08:50:30.947 thing-url: createWebSocket ws://192.168.1.86:80/1
2018-05-23 08:50:33.064 debug: Got: thingRemoved notification for Blue LED
2018-05-23 08:50:33.064 debug: Got: thingRemoved notification for Button 0
2018-05-23 08:50:34.019 thing-url: cleanupAndReopen ws://192.168.1.86:80/1
2018-05-23 08:50:34.019 thing-url: createWebSocket ws://192.168.1.86:80/1
2018-05-23 08:50:37.091 thing-url: cleanupAndReopen ws://192.168.1.86:80/1
2018-05-23 08:50:37.091 thing-url: createWebSocket ws://192.168.1.86:80/1
2018-05-23 08:50:40.040 Not checking SHA256SUMS file for thing-url-adapter since a .git directory was detected
2018-05-23 08:50:40.163 thing-url: cleanupAndReopen ws://192.168.1.86:80/1
2018-05-23 08:50:40.163 thing-url: createWebSocket ws://192.168.1.86:80/1
2018-05-23 08:50:40.308 Loading add-on: thing-url-adapter
2018-05-23 08:50:40.495 thing-url: Opening database: /home/dhylands/Dropbox/moziot/.mozilla-iot/config/db.sqlite3
2018-05-23 08:50:40.507 thing-url: Loading add-on for thing-url-adapter from /home/dhylands/Dropbox/moziot/.mozilla-iot/addons/thing-url-adapter
2018-05-23 08:50:40.725 debug: Got: adapterAdded notification for thing-url-adapter ThingURLAdapter
2018-05-23 08:50:43.235 thing-url: cleanupAndReopen ws://192.168.1.86:80/1
2018-05-23 08:50:43.235 thing-url: createWebSocket ws://192.168.1.86:80/1
2018-05-23 08:50:46.307 thing-url: cleanupAndReopen ws://192.168.1.86:80/1
2018-05-23 08:50:46.307 thing-url: createWebSocket ws://192.168.1.86:80/1

I counted about 100 create/cleanupAndReopens per second once it got going.

Eventually. the ESP32 Thing was rebooted and came back online.

2018-05-23 08:51:22.692 thing-url: createWebSocket ws://192.168.1.86:80/1
2018-05-23 08:51:22.699 thing-url: cleanupAndReopen ws://192.168.1.86:80/1
2018-05-23 08:51:22.699 thing-url: createWebSocket ws://192.168.1.86:80/1
2018-05-23 08:51:31.741 thing-url: Creating websocket with ws://192.168.1.86:80/0
2018-05-23 08:51:31.742 thing-url: createWebSocket ws://192.168.1.86:80/0
2018-05-23 08:51:35.024 thing-url: Creating websocket with ws://192.168.1.86:80/1
2018-05-23 08:51:35.024 thing-url: createWebSocket ws://192.168.1.86:80/1
2018-05-23 08:51:35.025 debug: Got: thingAdded notification for Blue LED
2018-05-23 08:51:35.242 debug: Got: thingAdded notification for Button 0
2018-05-23 08:55:25.539 getValue for property on for: Blue LED returning false
2018-05-23 08:55:25.549 getValue for property level for: Blue LED returning 50
2018-05-23 08:55:25.557 getValue for property on for: Button 0 returning false

On the ESP32 side of things, I saw an open request for a webSocket for the thing at /1, then another for /0 and another for /1

The last 2 (for /0 and /1) were exepected. However, the first one for /1 wasn't closed (this would correspond to the thing-url-adapter open that happened at 2018-05-23 08:51:22.699) so there may be 2 problems here: 1 - the thing-url-adapter continuously trying to open a websocket for a device that doesn't exist on the network. 2 - Not properly shutting down (or perhaps it should be reusing) the webSocket that was successfully opened (on /1)

mrstegeman commented 4 years ago

Fixed by #78