iklein99 / homebridge-smartthings

This is a plugin to Homebridge to connect your Smartthings network into Apple Home Kit.
Apache License 2.0
150 stars 52 forks source link

Devices are not responding - ST firmware update probably suspect #173

Open JeffGoldner opened 1 year ago

JeffGoldner commented 1 year ago

Describe The Bug:

In the past few days, most of my ST devices have either stopped responding or are responding too slowly, resulting in "Updating..." in the Home app. To Reproduce:

I changed nothing in my running configuration. I have about 15 devices, mostly Jasco switches, one Zooz 72, one Inovelli Blue, 2 Schlage locks, 2 Ecolink motion sensors, two Samsung TVs (often offline, don't care).

I suspect a very recent (past 2-3 days) update as my ST3 hub is now running 0047.00011 - not even release notes are out for that.

Expected behavior:

I expected things to still work - switch status report correctly, motion sensors report motion (or not), lock status, etc.

Logs:

Show the Homebridge logs here, remove any sensitive information.

5/5/2023, 7:16:36 AM] [homebridge-smartthings-ik] This plugin slows down Homebridge. The read handler for the characteristic 'Status Low Battery' was slow to respond! See https://homebridge.io/w/JtMGR for more info. [5/5/2023, 7:16:36 AM] [homebridge-smartthings-ik] This plugin slows down Homebridge. The read handler for the characteristic 'Battery Level' was slow to respond! See https://homebridge.io/w/JtMGR for more info. [5/5/2023, 7:16:36 AM] [homebridge-smartthings-ik] This plugin slows down Homebridge. The read handler for the characteristic 'Lock Current State' was slow to respond! See https://homebridge.io/w/JtMGR for more info. [5/5/2023, 7:16:36 AM] [homebridge-smartthings-ik] This plugin slows down Homebridge. The read handler for the characteristic 'Lock Target State' was slow to respond! See https://homebridge.io/w/JtMGR for more info. [5/5/2023, 7:16:36 AM] [homebridge-smartthings-ik] This plugin slows down Homebridge. The read handler for the characteristic 'Status Low Battery' was slow to respond! See https://homebridge.io/w/JtMGR for more info. [5/5/2023, 7:16:36 AM] [homebridge-smartthings-ik] This plugin slows down Homebridge. The read handler for the characteristic 'Battery Level' was slow to respond! See https://homebridge.io/w/JtMGR for more info. [5/5/2023, 7:16:36 AM] [homebridge-smartthings-ik] This plugin slows down Homebridge. The read handler for the characteristic 'On' was slow to respond! See https://homebridge.io/w/JtMGR for more info. [5/5/2023, 7:16:36 AM] [homebridge-smartthings-ik] This plugin slows down Homebridge. The read handler for the characteristic 'Brightness' was slow to respond! See https://homebridge.io/w/JtMGR for more info. [5/5/2023, 7:16:36 AM] [homebridge-smartthings-ik] This plugin slows down Homebridge. The read handler for the characteristic 'On' was slow to respond! See https://homebridge.io/w/JtMGR for more info. [5/5/2023, 7:16:36 AM] [homebridge-smartthings-ik] This plugin slows down Homebridge. The read handler for the characteristic 'On' was slow to respond! See https://homebridge.io/w/JtMGR for more info. [5/5/2023, 7:16:36 AM] [homebridge-smartthings-ik] This plugin slows down Homebridge. The read handler for the characteristic 'On' was slow to respond! See https://homebridge.io/w/JtMGR for more info. [5/5/2023, 7:16:36 AM] [homebridge-smartthings-ik] This plugin slows down Homebridge. The read handler for the characteristic 'On' was slow to respond! See https://homebridge.io/w/JtMGR for more info. [5/5/2023, 7:16:36 AM] [homebridge-smartthings-ik] This plugin slows down Homebridge. The read handler for the characteristic 'Motion Detected' was slow to respond! See https://homebridge.io/w/JtMGR for more info. [5/5/2023, 7:16:36 AM] [homebridge-smartthings-ik] This plugin slows down Homebridge. The read handler for the characteristic 'Status Low Battery' was slow to respond! See https://homebridge.io/w/JtMGR for more info. [5/5/2023, 7:16:36 AM] [homebridge-smartthings-ik] This plugin slows down Homebridge. The read handler for the characteristic 'Battery Level' was slow to respond! See https://homebridge.io/w/JtMGR for more info. [5/5/2023, 7:16:36 AM] [homebridge-smartthings-ik] This plugin slows down Homebridge. The read handler for the characteristic 'On' was slow to respond! See https://homebridge.io/w/JtMGR for more info. [5/5/2023, 7:16:36 AM] [homebridge-smartthings-ik] This plugin slows down Homebridge. The read handler for the characteristic 'Brightness' was slow to respond! See https://homebridge.io/w/JtMGR for more info. [5/5/2023, 7:16:36 AM] [homebridge-smartthings-ik] This plugin slows down Homebridge. The read handler for the characteristic 'On' was slow to respond! See https://homebridge.io/w/JtMGR for more info. [5/5/2023, 7:16:36 AM] [homebridge-smartthings-ik] This plugin slows down Homebridge. The read handler for the characteristic 'On' was slow to respond! See https://homebridge.io/w/JtMGR for more info. [5/5/2023, 7:16:36 AM] [homebridge-smartthings-ik] This plugin slows down Homebridge. The read handler for the characteristic 'On' was slow to respond! See https://homebridge.io/w/JtMGR for more info. [5/5/2023, 7:16:36 AM] [homebridge-smartthings-ik] This plugin slows down Homebridge. The read handler for the characteristic 'Lock Current State' was slow to respond! See https://homebridge.io/w/JtMGR for more info. [5/5/2023, 7:16:36 AM] [homebridge-smartthings-ik] This plugin slows down Homebridge. The read handler for the characteristic 'Lock Target State' was slow to respond! See https://homebridge.io/w/JtMGR for more info. [5/5/2023, 7:16:36 AM] [homebridge-smartthings-ik] This plugin slows down Homebridge. The read handler for the characteristic 'Status Low Battery' was slow to respond! See https://homebridge.io/w/JtMGR for more info. [5/5/2023, 7:16:36 AM] [homebridge-smartthings-ik] This plugin slows down Homebridge. The read handler for the characteristic 'Battery Level' was slow to respond! See https://homebridge.io/w/JtMGR for more info. [5/5/2023, 7:16:36 AM] [homebridge-smartthings-ik] This plugin slows down Homebridge. The read handler for the characteristic 'On' was slow to respond! See https://homebridge.io/w/JtMGR for more info. [5/5/2023, 7:16:36 AM] [homebridge-smartthings-ik] This plugin slows down Homebridge. The read handler for the characteristic 'Brightness' was slow to respond! See https://homebridge.io/w/JtMGR for more info. [5/5/2023, 7:16:42 AM] [homebridge-smartthings-ik] This plugin slows down Homebridge. The read handler for the characteristic 'Motion Detected' didn't respond at all!. Please check that you properly call the callback! See https://homebridge.io/w/JtMGR for more info. [5/5/2023, 7:16:42 AM] [homebridge-smartthings-ik] This plugin slows down Homebridge. The read handler for the characteristic 'Status Low Battery' didn't respond at all!. Please check that you properly call the callback! See https://homebridge.io/w/JtMGR for more info. [5/5/2023, 7:16:42 AM] [homebridge-smartthings-ik] This plugin slows down Homebridge. The read handler for the characteristic 'Battery Level' didn't respond at all!. Please check that you properly call the callback! See https://homebridge.io/w/JtMGR for more info. [5/5/2023, 7:16:42 AM] [homebridge-smartthings-ik] This plugin slows down Homebridge. The read handler for the characteristic 'Lock Current State' didn't respond at all!. Please check that you properly call the callback! See https://homebridge.io/w/JtMGR for more info. [5/5/2023, 7:16:42 AM] [homebridge-smartthings-ik] This plugin slows down Homebridge. The read handler for the characteristic 'Lock Target State' didn't respond at all!. Please check that you properly call the callback! See https://homebridge.io/w/JtMGR for more info. [5/5/2023, 7:16:42 AM] [homebridge-smartthings-ik] This plugin slows down Homebridge. The read handler for the characteristic 'Status Low Battery' didn't respond at all!. Please check that you properly call the callback! See https://homebridge.io/w/JtMGR for more info. [5/5/2023, 7:16:42 AM] [homebridge-smartthings-ik] This plugin slows down Homebridge. The read handler for the characteristic 'Battery Level' didn't respond at all!. Please check that you properly call the callback! See https://homebridge.io/w/JtMGR for more info. [5/5/2023, 7:16:42 AM] [homebridge-smartthings-ik] This plugin slows down Homebridge. The read handler for the characteristic 'On' didn't respond at all!. Please check that you properly call the callback! See https://homebridge.io/w/JtMGR for more info. [5/5/2023, 7:16:42 AM] [homebridge-smartthings-ik] This plugin slows down Homebridge. The read handler for the characteristic 'Brightness' didn't respond at all!. Please check that you properly call the callback! See https://homebridge.io/w/JtMGR for more info. [5/5/2023, 7:16:42 AM] [homebridge-smartthings-ik] This plugin slows down Homebridge. The read handler for the characteristic 'On' didn't respond at all!. Please check that you properly call the callback! See https://homebridge.io/w/JtMGR for more info. [5/5/2023, 7:16:42 AM] [homebridge-smartthings-ik] This plugin slows down Homebridge. The read handler for the characteristic 'On' didn't respond at all!. Please check that you properly call the callback! See https://homebridge.io/w/JtMGR for more info. [5/5/2023, 7:16:42 AM] [homebridge-smartthings-ik] This plugin slows down Homebridge. The read handler for the characteristic 'On' didn't respond at all!. Please check that you properly call the callback! See https://homebridge.io/w/JtMGR for more info. [5/5/2023, 7:16:42 AM] [homebridge-smartthings-ik] This plugin slows down Homebridge. The read handler for the characteristic 'On' didn't respond at all!. Please check that you properly call the callback! See https://homebridge.io/w/JtMGR for more info. [5/5/2023, 7:16:42 AM] [homebridge-smartthings-ik] This plugin slows down Homebridge. The read handler for the characteristic 'Motion Detected' didn't respond at all!. Please check that you properly call the callback! See https://homebridge.io/w/JtMGR for more info. [5/5/2023, 7:16:42 AM] [homebridge-smartthings-ik] This plugin slows down Homebridge. The read handler for the characteristic 'Status Low Battery' didn't respond at all!. Please check that you properly call the callback! See https://homebridge.io/w/JtMGR for more info. [5/5/2023, 7:16:42 AM] [homebridge-smartthings-ik] This plugin slows down Homebridge. The read handler for the characteristic 'Battery Level' didn't respond at all!. Please check that you properly call the callback! See https://homebridge.io/w/JtMGR for more info. [5/5/2023, 7:16:42 AM] [homebridge-smartthings-ik] This plugin slows down Homebridge. The read handler for the characteristic 'On' didn't respond at all!. Please check that you properly call the callback! See https://homebridge.io/w/JtMGR for more info. [5/5/2023, 7:16:42 AM] [homebridge-smartthings-ik] This plugin slows down Homebridge. The read handler for the characteristic 'Brightness' didn't respond at all!. Please check that you properly call the callback! See https://homebridge.io/w/JtMGR for more info. [5/5/2023, 7:16:42 AM] [homebridge-smartthings-ik] This plugin slows down Homebridge. The read handler for the characteristic 'On' didn't respond at all!. Please check that you properly call the callback! See https://homebridge.io/w/JtMGR for more info. [5/5/2023, 7:16:42 AM] [homebridge-smartthings-ik] This plugin slows down Homebridge. The read handler for the characteristic 'On' didn't respond at all!. Please check that you properly call the callback! See https://homebridge.io/w/JtMGR for more info. [5/5/2023, 7:16:42 AM] [homebridge-smartthings-ik] This plugin slows down Homebridge. The read handler for the characteristic 'On' didn't respond at all!. Please check that you properly call the callback! See https://homebridge.io/w/JtMGR for more info. [5/5/2023, 7:16:42 AM] [homebridge-smartthings-ik] This plugin slows down Homebridge. The read handler for the characteristic 'Brightness' didn't respond at all!. Please check that you properly call the callback! See https://homebridge.io/w/JtMGR for more info. Plugin Config:

Show your Homebridge config.json here, remove any sensitive information.

{ "bridge": { "name": "Homebridge 8339", "username": "0E:A7:34:3B:83:39", "port": 51699, "pin": "440-16-364", "advertiser": "ciao", "bind": [ "eth0" ] }, "accessories": [], "platforms": [ { "name": "Config", "port": 8581, "auth": "form", "theme": "dark-mode", "tempUnits": "f", "lang": "auto", "platform": "config" }, { "country": "US", "language": "en-US", "auth_mode": "token", "refresh_token": "x", "username": "", "password": "xxx", "platform": "LGThinQ", "devices": [ { "id": "ead678c0-c54b-1d38-bb91-4cbce98841b6", "name": "Refrigerator", "type": "REFRIGERATOR", "ref_express_freezer": true } ], "thinq1": false, "refresh_interval": 60 }, { "bonds": [ { "ip_address": "192.168.1.xx", "token": "xxxx" } ], "include_dimmer": true, "include_toggle_state": false, "fan_speed_values": false, "_bridge": { "username": "xxxxxx", "port": 43005 }, "platform": "Bond", "debug": true }, { "name": "TuyaWebPlatform", "options": { "username": "mynumber", "password": "mypass", "countryCode": "1", "platform": "smart_life" }, "defaults": [ { "device_type": "form" } ], "scenes": true, "scenesWhitelist": [ "SL Path Lights Color" ], "_bridge": { "username": "xxx", "port": 41943 }, "platform": "TuyaWebPlatform" }, { "name": "Nest", "refreshToken": "x", "platform": "Nest" }, { "name": "Sonos", "excludeAirPlay": true, "service": "switch", "speakers": true, "platform": "ZP" }, { "units": "us", "interval": 5, "stations": [ { "nameNow": "Backyard", "service": "openweathermap", "key": "x", "locationCity": "my town, US", "language": "en", "compatibility": "home", "conditionCategory": "simple", "now": true, "extraHumidity": false, "hidden": [ "Cloud Cover", "Condition Category", "Dew Point", "Forecast Day", "Observation Station", "Observation Time", "Rain 1h", "Solar Radiation", "Sunrise Time", "Sunset Time", "Visibility" ], "tresholdAirPressure": 1100 } ], "platform": "WeatherPlus" }, { "platform": "LinkTapPlatform", "name": "LinkTapPlatform", "username": "myuser", "apiKey": "mykey'", "gatewayId": "1F0B8F1A004B1200", "taps": [ { "name": "Container Garden", "location": "Deck", "taplinkerId": "22198828004B1200", "duration": 1 }, { "name": "Front", "location": "Front of House", "taplinkerId": "FF6CAA19004B1200", "duration": 1 }, { "name": "Backyard", "location": "Back deck", "taplinkerId": "F553AA19004B1200", "duration": 1 }, { "name": "Pond", "location": "Backyard", "taplinkerId": "0B28E81D004B1200", "duration": 1 } ] }, { "email": "email", "password": "passwd", "platform": "myQ", "_bridge": { "username": "0E:34:19:52:AD:C2", "port": 57403 } }, { "devices": [ { "name": "LR SR6007", "host": "192.168.1.60", "port": 80, "zoneControl": 0, "getInputsFromDevice": false, "getFavoritesFromDevice": false, "getQuickSmartSelectFromDevice": false, "inputs": [ { "name": "Phono", "reference": "CBL/SAT", "mode": "SI" }, { "name": "Sonos", "reference": "MPLAY", "mode": "SI" }, { "name": "CD", "reference": "DVD", "mode": "SI" } ], "sensorPower": false, "sensorVolume": false, "sensorMute": false, "sensorInput": false, "enableDebugMode": false, "disableLogInfo": false, "disableLogDeviceInfo": false, "disableLogConnectError": true, "supportOldAvr": false, "masterPower": false, "masterVolume": false, "masterMute": false, "infoButtonCommand": "MNINF", "volumeControl": 1, "refreshInterval": 5, "enableMqtt": false, "mqttDebug": false, "mqttAuth": false } ], "platform": "DenonTv" }, { "name": "Smartthings Plug (IK)", "BaseURL": "https://api.smartthings.com/v1/", "AccessToken": "token", "GarageDoorMaxPoll": 40, "PollLocksSeconds": 10, "PollDoorsSeconds": 10, "PollSensorsSeconds": 5, "PollSwitchesAndLightsSeconds": 10, "platform": "HomeBridgeSmartThings", "_bridge": { "username": "0E:01:89:B7:3C:C7", "port": 46266 } }

]

}

Screenshots:

Environment:

JeffGoldner commented 1 year ago

Deleted the plugin from my previous install, removed the bridge from Homekit. Set up a new (latest) docker container (1.6.1) on my QNAP and only installed this plug-in as a child bridge. Same issues. Device discovery worked immediately on all 19 devices, and populated the HB cache, but most operations to get/set status fail. Not added to HK at this point.

This error did not look familiar:

[5/6/2023, 7:05:13 AM] [Smartthings Plug (IK)] Poll failure on Schlage Door Lock Error: HAP Status Error: -70402 at new HapStatusError (/homebridge/node_modules/homebridge/node_modules/hap-nodejs/src/lib/util/hapStatusError.ts:17:5) at /homebridge/node_modules/homebridge-smartthings-ik/src/services/lockService.ts:58:20

child bridge crashed at that point and restarted.

Magically, a few hours later, things seemed to be working. I added the bridge and its devices back to Homekit via the iOS Home app. I adjusted a few simple automations and they were working: turn on closet light (st) when motion detected (Aqara, native HK not via homebridge); turn outside lights off at sunrise this morning.

Around 7AM, went to hell again. Devices not responding, closet light automation not working even after restarting HB (with -D this time).

JeffGoldner commented 1 year ago

Added the Webhook yesterday. Logs show that sometimes requests succeed, other times they time out. Here's an example showing the last successful status requests, followed by a number of timeouts, every 85 seconds. Plug-in version 1.5.9, running as a child bridge, no other plug-ins aside from the UI. On rare occasions, a scheduled automation will run and control of a device might work, but those are exceptions, not the norm.

[5/7/2023, 11:30:26 AM] [Smartthings Plug (IK)] Updated status for Office Ceiling-main: {"button":{"button":{"value":"up","timestamp":"2022-12-10T20:45:07.461Z"},"numberOfButtons":{"value":1,"timestamp":"2022-12-10T20:45:07.460Z"},"supportedButtonValues":{"value":["down","down_hold","down_2x","down_3x","down_4x","down_5x","up","up_hold","up_2x","up_3x","up_4x","up_5x"],"timestamp":"2022-12-10T20:45:07.370Z"}},"platemusic11009.zoozLedColor":{"ledColor":{"value":"blue","timestamp":"2022-12-10T22:01:46.506Z"}},"platemusic11009.zoozLedBrightness":{"ledBrightness":{"value":"medium","timestamp":"2022-12-10T22:01:47.692Z"}},"platemusic11009.basicSetAssociationGroup":{"basicSetAssociationGroup":{"value":"None","timestamp":"2023-02-13T14:34:04.639Z"}},"platemusic11009.zoozLedMode":{"ledMode":{"value":"onWhenOff","timestamp":"2022-12-10T22:01:44.240Z"}},"platemusic11009.firmware":{"firmwareVersion":{"value":2,"timestamp":"2022-12-10T22:01:48.298Z"}},"switchLevel":{"level":{"value":1,"unit":"%","timestamp":"2023-05-06T03:59:48.964Z"}},"platemusic11009.multilevelAssociationGroup":{"multilevelAssociationGroup":{"value":"None","timestamp":"2023-02-13T14:34:04.733Z"}},"refresh":{},"platemusic11009.deviceNetworkId":{"deviceNetworkId":{"value":"[22]","timestamp":"2022-12-10T22:01:40.141Z"}},"switch":{"switch":{"value":"off","timestamp":"2023-05-06T03:59:50.206Z"}}} [5/7/2023, 11:30:26 AM] [Smartthings Plug (IK)] SwitchState value from Office Ceiling: off [5/7/2023, 11:30:32 AM] [Smartthings Plug (IK)] Received getLockState() event for Schlage Door Lock [5/7/2023, 11:30:32 AM] [Smartthings Plug (IK)] Refreshing status for Schlage Door Lock - current timestamp is 1683484158389 [5/7/2023, 11:30:32 AM] [Smartthings Plug (IK)] Calling Smartthings to get an update for Schlage Door Lock [5/7/2023, 11:30:32 AM] [Smartthings Plug (IK)] Received getLockState() event for Schlage Door Lock [5/7/2023, 11:30:32 AM] [Smartthings Plug (IK)] Refreshing status for Schlage Door Lock - current timestamp is 1683484158388 [5/7/2023, 11:30:32 AM] [Smartthings Plug (IK)] Calling Smartthings to get an update for Schlage Door Lock [5/7/2023, 11:30:33 AM] [Smartthings Plug (IK)] Updated status for Schlage Door Lock-main: {"lock":{"lock":{"value":"locked","data":{"method":"manual"},"timestamp":"2023-05-07T04:12:50.126Z"}},"refresh":{},"battery":{"battery":{"value":100,"unit":"%","timestamp":"2023-01-16T20:25:43.184Z"}},"lockCodes":{"codeLength":{"value":4,"timestamp":"2023-01-16T20:25:37.434Z"},"maxCodes":{"value":30,"timestamp":"2023-01-16T20:25:36.786Z"},"maxCodeLength":{"value":null},"codeChanged":{"value":"8 unset","data":{},"timestamp":"2023-01-16T20:25:46.244Z"},"lock":{"value":null},"minCodeLength":{"value":null},"scanCodes":{"value":"Complete","timestamp":"2023-01-16T20:25:46.340Z"},"codeReport":{"value":null},"lockCodes":{"value":"{\"1\":\"Code 1\",\"2\":\"Code 2\",\"3\":\"Code 3\",\"4\":\"Code 4\"}","timestamp":"2023-01-16T20:25:43.996Z"}}} [5/7/2023, 11:30:33 AM] [Smartthings Plug (IK)] LockState value from Schlage Door Lock: locked [5/7/2023, 11:30:33 AM] [Smartthings Plug (IK)] Updated status for Schlage Door Lock-main: {"lock":{"lock":{"value":"locked","data":{"method":"manual"},"timestamp":"2023-05-04T00:26:03.000Z"}},"refresh":{},"battery":{"battery":{"value":96,"unit":"%","timestamp":"2023-04-16T01:44:27.133Z"}},"lockCodes":{"codeLength":{"value":4,"timestamp":"2023-01-16T20:33:45.965Z"},"maxCodes":{"value":30,"timestamp":"2023-01-16T20:33:45.739Z"},"maxCodeLength":{"value":null},"codeChanged":{"value":"8 unset","data":{},"timestamp":"2023-01-16T20:35:40.393Z"},"lock":{"value":null},"minCodeLength":{"value":null},"scanCodes":{"value":"Complete","timestamp":"2023-01-16T20:35:40.587Z"},"codeReport":{"value":null},"lockCodes":{"value":"{\"1\":\"Code 1\",\"2\":\"Code 2\",\"3\":\"Code 3\",\"4\":\"Code 4\",\"5\":\"Code 5\"}","timestamp":"2023-01-16T20:35:34.398Z"}}} [5/7/2023, 11:30:33 AM] [Smartthings Plug (IK)] LockState value from Schlage Door Lock: locked [5/7/2023, 11:31:04 AM] [Smartthings Plug (IK)] Received response from webhook {"timeout":true,"events":[]} [5/7/2023, 11:31:04 AM] [Smartthings Plug (IK)] Posting request to web hook [5/7/2023, 11:32:29 AM] [Smartthings Plug (IK)] Received response from webhook {"timeout":true,"events":[]} [5/7/2023, 11:32:29 AM] [Smartthings Plug (IK)] Posting request to web hook [5/7/2023, 11:33:54 AM] [Smartthings Plug (IK)] Received response from webhook {"timeout":true,"events":[]} [5/7/2023, 11:33:54 AM] [Smartthings Plug (IK)] Posting request to web hook [5/7/2023, 11:35:21 AM] [Smartthings Plug (IK)] Received response from webhook {"timeout":true,"events":[]} [5/7/2023, 11:35:21 AM] [Smartthings Plug (IK)] Posting request to web hook [5/7/2023, 11:36:46 AM] [Smartthings Plug (IK)] Received response from webhook {"timeout":true,"events":[]} [5/7/2023, 11:36:46 AM] [Smartthings Plug (IK)] Posting request to web hook [5/7/2023, 11:38:11 AM] [Smartthings Plug (IK)] Received response from webhook {"timeout":true,"events":[]} [5/7/2023, 11:38:11 AM] [Smartthings Plug (IK)] Posting request to web hook [5/7/2023, 11:39:37 AM] [Smartthings Plug (IK)] Received response from webhook {"timeout":true,"events":[]} [5/7/2023, 11:39:37 AM] [Smartthings Plug (IK)] Posting request to web hook [5/7/2023, 11:41:02 AM] [Smartthings Plug (IK)] Received response from webhook {"timeout":true,"events":[]} [5/7/2023, 11:41:02 AM] [Smartthings Plug (IK)] Posting request to web hook [5/7/2023, 11:42:27 AM] [Smartthings Plug (IK)] Received response from webhook {"timeout":true,"events":[]} [5/7/2023, 11:42:27 AM] [Smartthings Plug (IK)] Posting request to web hook [5/7/2023, 11:43:53 AM] [Smartthings Plug (IK)] Received response from webhook {"timeout":true,"events":[]} [5/7/2023, 11:43:53 AM] [Smartthings Plug (IK)] Posting request to web hook [5/7/2023, 11:45:18 AM] [Smartthings Plug (IK)] Received response from webhook {"timeout":true,"events":[]} [5/7/2023, 11:45:18 AM] [Smartthings Plug (IK)] Posting request to web hook [5/7/2023, 11:46:43 AM] [Smartthings Plug (IK)] Received response from webhook {"timeout":true,"events":[]} [5/7/2023, 11:46:43 AM] [Smartthings Plug (IK)] Posting request to web hook [5/7/2023, 11:48:09 AM] [Smartthings Plug (IK)] Received response from webhook {"timeout":true,"events":[]} [5/7/2023, 11:48:09 AM] [Smartthings Plug (IK)] Posting request to web hook [5/7/2023, 11:49:34 AM] [Smartthings Plug (IK)] Received response from webhook {"timeout":true,"events":[]} [5/7/2023, 11:49:34 AM] [Smartthings Plug (IK)] Posting request to web hook [5/7/2023, 11:51:01 AM] [Smartthings Plug (IK)] Received response from webhook {"timeout":true,"events":[]} [5/7/2023, 11:51:01 AM] [Smartthings Plug (IK)] Posting request to web hook [5/7/2023, 11:52:26 AM] [Smartthings Plug (IK)] Received response from webhook {"timeout":true,"events":[]} [5/7/2023, 11:52:26 AM] [Smartthings Plug (IK)] Posting request to web hook [5/7/2023, 11:53:51 AM] [Smartthings Plug (IK)] Received response from webhook {"timeout":true,"events":[]} [5/7/2023, 11:53:51 AM] [Smartthings Plug (IK)] Posting request to web hook

JeffGoldner commented 1 year ago

Succeeds roughly at 1/2 hour intervals, but fails (timeout) in between.

iklein99 commented 1 year ago

Hi Jeff. These timeout messages are normal. The plugin opens a request every 85 seconds to wait for events from SmartThings. If no events arrive, that request times out and another is issued. This is ok.

Before you added the webhook, the plugin polls very often (like every 5 to 10 seconds for each device, depending upon your config). It looks to me like in this mode, SmartThings was responding very slowly, which causes a pile-up and timeouts. This could be due to either your internet connection or the smartthings hub you are using. With the webhook, this is no longer an issue as we don't poll the devices any longer. We just wait for events. Still, if you are having assue with your ST hub, then you will have problems. You may want to see about resetting the hub.

JeffGoldner commented 1 year ago

Yeah, I figured out that webhook timeout. To reduce the complexity, I am running a separate instance of homebridge on my QNAP NAS, updated node to v18.6.0, and only installed your plug-in (v1.5.9 right now). Configured as child bridge, webhook and api tokens configured. ST3 hub running 47.11 firmware, wired to my Orbi satellite.

I removed the bridge from Homekit altogether while I get a better understanding of the failure modes

Here's what I currently see:

The SmartThings app is able to control all devices instantly Discovery of all devices by the plugin works instantly - 17 physical devices, shows as 25 accessories (add batteries and buttons) Webhook gets data when something changes, as expected, usually quite quickly - or times out as expected and posts another request. Locks, motion detectors, lights.

The Homebridge UI takes a while to populate. I can usually control things but not always. For example, I turned on a light switch, it did go on but UI shows it goes off again. Refreshing the UI shows the correct state (on). But some devices don't respond all the time. Not too concerned about UI flakiness, I won't use that.

Now, added the child bridge to Home, all accessories found and added. Attempt to control accessory (dimmer) - No Response Attempt to control light switch - responded. On, then off Back to first dimmer, a few operations worked and then all ST things went to No Response in hub. Nothing in the HB log output. From ST app, turn off that dimmer. HB Log showed the state change and the Home app showed status for all things again.

So this is pretty consistent with the issues I have been seeing. Sometimes things work, other times the same things don't. Yesterday morning the outside lights turned off on schedule, then on in the evening. This morning they did not turn off.

I am not sure what will happen if I reset the hub - and by reset, what exactly do you mean? I would have to exclude and re-add all devices? But the ST app works 100%.

iklein99 commented 1 year ago

You may want to check what you are using for a home hub. I have an old iPad I’m using and sometimes I have to restart it. Has nothing to do with the plugin.

On May 8, 2023, at 3:41 PM, Jeff Goldner @.***> wrote:

Yeah, I figured out that webhook timeout. To reduce the complexity, I am running a separate instance of homebridge on my QNAP NAS, updated node to v18.6.0, and only installed your plug-in (v1.5.9 right now). Configured as child bridge, webhook and api tokens configured. ST3 hub running 47.11 firmware, wired to my Orbi satellite.

I removed the bridge from Homekit altogether while I get a better understanding of the failure modes

Here's what I currently see:

The SmartThings app is able to control all devices instantly Discovery of all devices by the plugin works instantly - 17 physical devices, shows as 25 accessories (add batteries and buttons) Webhook gets data when something changes, as expected, usually quite quickly - or times out as expected and posts another request. Locks, motion detectors, lights.

The Homebridge UI takes a while to populate. I can usually control things but not always. For example, I turned on a light switch, it did go on but UI shows it goes off again. Refreshing the UI shows the correct state (on). But some devices don't respond all the time. Not too concerned about UI flakiness, I won't use that.

Now, added the child bridge to Home, all accessories found and added. Attempt to control accessory (dimmer) - No Response Attempt to control light switch - responded. On, then off Back to first dimmer, a few operations worked and then all ST things went to No Response in hub. Nothing in the HB log output. From ST app, turn off that dimmer. HB Log showed the state change and the Home app showed status for all things again.

So this is pretty consistent with the issues I have been seeing. Sometimes things work, other times the same things don't. Yesterday morning the outside lights turned off on schedule, then on in the evening. This morning they did not turn off.

I am not sure what will happen if I reset the hub - and by reset, what exactly do you mean? I would have to exclude and re-add all devices? But the ST app works 100%.

— Reply to this email directly, view it on GitHub https://github.com/iklein99/homebridge-smartthings/issues/173#issuecomment-1538941220, or unsubscribe https://github.com/notifications/unsubscribe-auth/ABG55EWBB52MK66FV4M4MNTXFFD6RANCNFSM6AAAAAAXXU5YNE. You are receiving this because you commented.

JeffGoldner commented 1 year ago

2 atv 4ks. both restarted multiple times. 10 other plugins work.

iklein99 commented 1 year ago

All I can tell you is to reproduce the issue and send me the detailed logs. Follow the link for instructions. p.s. I wouldn't rely on the homebridge UI for device control - use the ios app.

Instructions for Producing a Detailed Log.pdf

JeffGoldner commented 1 year ago

I don't rely on that UX, just pointing out is was more reliable than the ios apps (home and controller for home) at this point. I truncated the log to remove earlier stuff. I then opened the Home app on my phone before the first webhook timeout below. At this point, all ST things in Home show No Response. The log simply shows

[5/10/2023, 9:45:46 AM] [Homebridge UI] Homebridge log truncated by xxxxxxx. [5/10/2023, 9:46:45 AM] [Smartthings Plug (IK)] Received response from webhook {"timeout":true,"events":[]} [5/10/2023, 9:46:45 AM] [Smartthings Plug (IK)] Posting request to web hook [5/10/2023, 9:48:10 AM] [Smartthings Plug (IK)] Received response from webhook {"timeout":true,"events":[]} [5/10/2023, 9:48:10 AM] [Smartthings Plug (IK)] Posting request to web hook

Now I will restart the entire container and get the log to you after fresh start of the Home app, and a few simple attempts at switch activities strictly in the Home app. Simple on/off/on/off of one light switch worked following container restart. A Change dimmer value of one switched worked a few times, tried another and the first few attempts showed success in Home, but didn't actually turn on or change the dimmer level of that light (O Lights), then No Response from either dimmer. Back to the original light switch (Closet Light), attempt to turn on, No Response. homebridge.log.txt

JeffGoldner commented 1 year ago

Then I used the ST app to control the Office Ceiling light and it worked as expected, immediately.

Corresponding HB log entries for the activities in the ST app:

[5/10/2023, 10:04:46 AM] [Smartthings Plug (IK)] Received response from webhook {"timeout":false,"events":[{"deviceId":"f527eaef-c088-4fa5-832a-f1576678339e","value":"on","componentId":"main","capability":"switch","attribute":"switch"}]} [5/10/2023, 10:04:46 AM] [Smartthings Plug (IK)] Received events for Office Ceiling [5/10/2023, 10:04:46 AM] [Smartthings Plug (IK)] Event for Office Ceiling:main - on [5/10/2023, 10:04:46 AM] [Smartthings Plug (IK)] Event updating switch capability for Office Ceiling to on [5/10/2023, 10:04:46 AM] [Smartthings Plug (IK)] Posting request to web hook [5/10/2023, 10:04:49 AM] [Smartthings Plug (IK)] Received response from webhook {"timeout":false,"events":[{"deviceId":"f527eaef-c088-4fa5-832a-f1576678339e","value":"off","componentId":"main","capability":"switch","attribute":"switch"}]} [5/10/2023, 10:04:49 AM] [Smartthings Plug (IK)] Received events for Office Ceiling

iklein99 commented 1 year ago

Everything looks normal and good from the logs, I traced Closet Light status and activity and I see requests to turn on, and successful results, then I see request to turn off with successful results. I also see status requests going and responses coming back and I see events coming in through the webhook as a result of your actions.

The plugin is functioning properly. There is another cause as to why you aren’t seeing thing right in the app. Not sure there is anything I can do for you.

On May 10, 2023, at 1:09 PM, Jeff Goldner @.***> wrote:

Then I used the ST app to control the Office Ceiling light and it worked as expected, immediately.

— Reply to this email directly, view it on GitHub https://github.com/iklein99/homebridge-smartthings/issues/173#issuecomment-1542542774, or unsubscribe https://github.com/notifications/unsubscribe-auth/ABG55EXYCKUTWBEAEEP2VJ3XFPDVFANCNFSM6AAAAAAXXU5YNE. You are receiving this because you commented.

coryabooth commented 1 year ago

Are you using Ubiquity Equipment or Pi-Hole? I had an issue with updating and pi-hole blocking some endpoints. Ubiquity recent had a problem with disconnecting WiFi devices on their most recent firmware

JeffGoldner commented 1 year ago

Orbi RBRE960 router and RBSE960 Satellites

JeffGoldner commented 1 year ago

Maybe premature, but...

I backed off Homebridge to 1.6.0 instead of the current release 1.6.1. Things might actually be working again. I had to redo a few automations for the Closet Light, but they ran as expected at least a few times over the past hour. I believe this was also impacting the tuyaweb plugin.

iklein99 commented 1 year ago

Let me know what you find out. I just updated to 1.6.1, but not seeing any issues.

JeffGoldner commented 1 year ago

I didn't think I had problems with 1.6.1 either. As of this AM, my ST related info still looks good, although the home app on MacOS didn't reflect some status like dimmer values correctly which I change in the early morning (iOS Home app was correct). I have one automation that's a bit funky but I suspect I messed it up trying to get fancy.

I have a lot of stuff in HomeKit (60-80 accessories). Maybe it's a scale issue? Or maybe the fact that I ordered a few native HK switches as replacements for Z-wave scared them into behaving, lol.

Tuya stuff still seems flaky, not your problem, just similar issues. Next week we can debug again when Apple releases 16.5 ...

iklein99 commented 1 year ago

I’d suspect the issue is with your home hub. But that is just s suspicion. But given what I saw in the logs, I think that may be where it is. I’ve had to restart mine a few times.

That is where all of your automations run as well.

On May 12, 2023, at 2:28 PM, Jeff Goldner @.***> wrote:

I didn't think I had problems with 1.6.1 either. As of this AM, my ST related info still looks good, although the home app on MacOS didn't reflect some status like dimmer values correctly which I change in the early morning (iOS Home app was correct). I have one automation that's a bit funky but I suspect I messed it up trying to get fancy.

I have a lot of stuff in HomeKit (60-80 accessories). Maybe it's a scale issue? Or maybe the fact that I ordered a few native HK switches as replacements for Z-wave scared them into behaving, lol.

Tuya stuff still seems flaky, not your problem, just similar issues. Next week we can debug again when Apple releases 16.5 ...

— Reply to this email directly, view it on GitHub https://github.com/iklein99/homebridge-smartthings/issues/173#issuecomment-1546123178, or unsubscribe https://github.com/notifications/unsubscribe-auth/ABG55EXKC6DNWKP74ZIPYL3XFZ6LBANCNFSM6AAAAAAXXU5YNE. You are receiving this because you commented.

JeffGoldner commented 1 year ago

I have restarted both of them many times. Maybe the last time stuck?

iklein99 commented 1 year ago

Any update? If not, I will close.

Sunflare98 commented 1 year ago

FWIW, I was getting these error messages this morning constantly. Hubs are Apple TVs (latest version, fully updated). It took 3 restarts of Homebridge before the plugin started performing normally. Not sure that's a permanent fix, but at least it's a fix for now.