ebaauw / homebridge-hue

Homebridge plugin for Philips Hue
Apache License 2.0
901 stars 91 forks source link

Crash after about 10min in #1062

Closed hoodie closed 2 years ago

hoodie commented 2 years ago

Issue

Hi there and happy Holidays,

I just set up a homebridge with homebridge-hue while at my parents but unfortunately it crashes after about 10min with this:

TypeError: Cannot read properties of undefined (reading 'id')
    at EventStreamClient.<anonymous> (/usr/local/lib/node_modules/homebridge-hue/lib/HueBridge.js:958:72)
    at EventStreamClient.emit (node:events:390:28)
    at IncomingMessage.<anonymous> (/usr/local/lib/node_modules/homebridge-hue/lib/EventStreamClient.js:167:36)
    at IncomingMessage.emit (node:events:390:28)
    at addChunk (node:internal/streams/readable:315:12)
    at readableAddChunk (node:internal/streams/readable:289:9)
    at IncomingMessage.Readable.push (node:internal/streams/readable:228:10)
    at HTTPParser.parserOnBody (node:_http_common:141:24)
    at TLSSocket.socketOnData (node:_http_client:487:22)
    at TLSSocket.emit (node:events:390:28)

Log Messages

after which the entire homebridge needs to restart and I need to push the pairing button on the hue again.

[23/12/2021, 14:58:55] Got SIGTERM, shutting down Homebridge...
[23/12/2021, 14:59:00] [Hue] goodbye
[23/12/2021, 14:59:00] [HB Supervisor] Homebridge Process Ended. Code: 143, Signal: null
[23/12/2021, 14:59:05] [HB Supervisor] Restarting Homebridge...
[23/12/2021, 14:59:05] [HB Supervisor] Starting Homebridge with extra flags: -I
[23/12/2021, 14:59:06] [HB Supervisor] Started Homebridge v1.3.8 with PID: 6882
[23/12/2021, 14:59:09] Loaded config.json with 0 accessories and 2 platforms.

Any ideas about this? It's the latest release 0.13.31

Thank you

ebaauw commented 2 years ago

The crash is caused by a bug in the error handler. Not sure what's causing the error, though. It looks like Homebridge Hue receives an event stream notification that it cannot parse. Could you please capture and attach a a debug log file and attach the debug dump file?

after which the entire homebridge needs to restart

Best run child bridges to contain errors to a single plugin.

I need to push the pairing button on the hue again

See the README and FAQ: you need to edit config.json, adding the obtained username (API key).

hoodie commented 2 years ago

thanks for the config.json tip!

here is my log from after a fresh restart

[23/12/2021, 21:51:24] [homebridge-hue] This plugin is taking long time to load and preventing Homebridge from starting. See https://git.io/JtMGR for more info.
[23/12/2021, 21:51:24] [Hue] Philips hue: request 2: POST / {"devicetype":"homebridge-hue#homebridge"}
[23/12/2021, 21:51:24] [Hue] Philips hue: request 2: api error 101: link button not pressed
[23/12/2021, 21:51:24] [Hue] Philips hue: press link button on the bridge to create a user - retrying in 15s
[23/12/2021, 21:51:25] [Homebridge UI] Changes to config.json saved.
[23/12/2021, 21:51:29] [Homebridge UI] Changes to config.json saved.
[23/12/2021, 21:51:31] [Homebridge UI] Homebridge restart request received
[23/12/2021, 21:51:31] [Homebridge UI] UI / Bridge settings have not changed; only restarting Homebridge process
[23/12/2021, 21:51:31] [Homebridge UI] Sending SIGTERM to Homebridge
[23/12/2021, 21:51:31] Got SIGTERM, shutting down Homebridge...
[23/12/2021, 21:51:36] [Hue] goodbye
[23/12/2021, 21:51:36] [Hue] goodbye

[23/12/2021, 21:51:36] [HB Supervisor] Homebridge Process Ended. Code: 143, Signal: null
[23/12/2021, 21:51:41] [HB Supervisor] Restarting Homebridge...
[23/12/2021, 21:51:41] [HB Supervisor] Starting Homebridge with extra flags: -I
[23/12/2021, 21:51:41] [HB Supervisor] Started Homebridge v1.3.8 with PID: 1289
[23/12/2021, 21:51:44] Loaded config.json with 0 accessories and 2 platforms.
[23/12/2021, 21:51:45] Loaded 0 cached accessories from cachedAccessories.
[23/12/2021, 21:51:45] ---
[23/12/2021, 21:51:49] Loaded plugin: homebridge-config-ui-x@4.41.5
[23/12/2021, 21:51:49] Registering platform 'homebridge-config-ui-x.config'
[23/12/2021, 21:51:49] ---
[23/12/2021, 21:51:57] Loaded plugin: homebridge-hue@0.13.31
[23/12/2021, 21:51:57] Registering platform 'homebridge-hue.Hue'
[23/12/2021, 21:51:57] ---
[23/12/2021, 21:51:57] Loading 2 platforms...
[23/12/2021, 21:51:57] [Config] Initializing config platform...
[23/12/2021, 21:51:57] [Config] Running in Service Mode
[23/12/2021, 21:51:57] [Hue] Initializing Hue platform...
[23/12/2021, 21:51:57] [Hue] homebridge-hue v0.13.31, node v16.13.1, homebridge v1.3.8
[23/12/2021, 21:51:57] [Hue] searching bridges and gateways
[23/12/2021, 21:52:02] [Hue] Philips hue: Signify Netherlands B.V. BSB002 bridge ***********, api v1.48.0
[23/12/2021, 21:52:03] [Hue] Philips hue: 5 accessories
[23/12/2021, 21:52:03] [Hue] masked debug info dumped to /var/lib/homebridge/homebridge-hue.json.gz
[23/12/2021, 21:52:03] Initializing platform accessory 'Philips hue'...
[23/12/2021, 21:52:03] [Hue] Philips hue: 2 services
[23/12/2021, 21:52:03] Initializing platform accessory '****'...
[23/12/2021, 21:52:03] Initializing platform accessory '************'...
[23/12/2021, 21:52:03] Initializing platform accessory '**************'...
[23/12/2021, 21:52:03] Initializing platform accessory '*************'...
Setup Payload:
X-HM://*************
Enter this code with your HomeKit app on your iOS device to pair with Homebridge:

    ┌────────────┐     
    │ ***-**-*** │     
    └────────────┘     

[23/12/2021, 21:52:03] Homebridge v1.3.8 (HAP v0.9.7) (Homebridge 7A3D) is running on port 51250.
[23/12/2021, 21:52:03] [Hue] Philips hue: event stream connected to https://**************/eventstream/clip/v2
[23/12/2021, 21:59:12] TypeError: Cannot read properties of undefined (reading 'id')
    at EventStreamClient.<anonymous> (/usr/local/lib/node_modules/homebridge-hue/lib/HueBridge.js:958:72)
    at EventStreamClient.emit (node:events:390:28)
    at IncomingMessage.<anonymous> (/usr/local/lib/node_modules/homebridge-hue/lib/EventStreamClient.js:167:36)
    at IncomingMessage.emit (node:events:390:28)
    at addChunk (node:internal/streams/readable:315:12)
    at readableAddChunk (node:internal/streams/readable:289:9)
    at IncomingMessage.Readable.push (node:internal/streams/readable:228:10)
    at HTTPParser.parserOnBody (node:_http_common:141:24)
    at TLSSocket.socketOnData (node:_http_client:487:22)
    at TLSSocket.emit (node:events:390:28)
[23/12/2021, 21:59:12] Got SIGTERM, shutting down Homebridge...
[23/12/2021, 21:59:18] [Hue] goodbye
[23/12/2021, 21:59:18] [HB Supervisor] Homebridge Process Ended. Code: 143, Signal: null
[23/12/2021, 21:59:23] [HB Supervisor] Restarting Homebridge...
[23/12/2021, 21:59:23] [HB Supervisor] Starting Homebridge with extra flags: -I
[23/12/2021, 21:59:23] [HB Supervisor] Started Homebridge v1.3.8 with PID: 1571
[23/12/2021, 21:59:26] Loaded config.json with 0 accessories and 2 platforms.
[23/12/2021, 21:59:26] Loaded 0 cached accessories from cachedAccessories.
[23/12/2021, 21:59:26] ---

and the dump

{
  "versions": {
    "node": "v16.13.1",
    "homebridge": "v1.3.8",
    "homebridge-hue": "v0.13.31"
  },
  "config": {
    "name": "Hue",
    "anyOn": true,
    "effects": true,
    "lights": true,
    "nativeHomeKitLights": true,
    "nativeHomeKitSensors": true,
    "resource": true,
    "platform": "Hue",
    "users": {

    }
  },
  "bridges": [
    {
      "lights": {
        "9": {
          "state": {
            "on": false,
            "alert": "select",
            "mode": "homeautomation",
            "reachable": true
          },
          "swupdate": {
            "state": "notupdatable",
            "lastinstall": "2021-01-26T20:11:19"
          },
          "type": "On/Off plug-in unit",
          "name": "Bett",
          "modelid": "Plug 01",
          "manufacturername": "OSRAM",
          "productname": "On/Off plug",
          "capabilities": {
            "certified": false,
            "control": {},
            "streaming": {
              "renderer": false,
              "proxy": false
            }
          },
          "config": {
            "archetype": "classicbulb",
            "function": "functional",
            "direction": "omnidirectional"
          },
          "uniqueid": "7c:b0:3e:aa:0a:09:08:9e-03",
          "swversion": "V1.05.09"
        },
        "11": {
          "state": {
            "on": true,
            "alert": "select",
            "mode": "homeautomation",
            "reachable": true
          },
          "swupdate": {
            "state": "notupdatable",
            "lastinstall": "2021-12-19T17:02:57"
          },
          "type": "On/Off plug-in unit",
          "name": "Schreibtisch",
          "modelid": "Plug 01",
          "manufacturername": "OSRAM",
          "productname": "On/Off plug",
          "capabilities": {
            "certified": false,
            "control": {},
            "streaming": {
              "renderer": false,
              "proxy": false
            }
          },
          "config": {
            "archetype": "classicbulb",
            "function": "functional",
            "direction": "omnidirectional"
          },
          "uniqueid": "7c:b0:3e:aa:0a:09:2a:42-03",
          "swversion": "V1.05.09"
        },
        "12": {
          "state": {
            "on": true,
            "alert": "select",
            "mode": "homeautomation",
            "reachable": true
          },
          "swupdate": {
            "state": "notupdatable",
            "lastinstall": "2021-12-21T18:51:17"
          },
          "type": "On/Off plug-in unit",
          "name": "Weihnachtsbaum",
          "modelid": "Plug 01",
          "manufacturername": "OSRAM",
          "productname": "On/Off plug",
          "capabilities": {
            "certified": false,
            "control": {},
            "streaming": {
              "renderer": false,
              "proxy": false
            }
          },
          "config": {
            "archetype": "christmastree",
            "function": "functional",
            "direction": "omnidirectional"
          },
          "uniqueid": "7c:b0:3e:aa:0a:0a:51:b9-03",
          "swversion": "V1.05.09"
        },
        "13": {
          "state": {
            "on": false,
            "alert": "select",
            "mode": "homeautomation",
            "reachable": false
          },
          "swupdate": {
            "state": "notupdatable",
            "lastinstall": "2021-12-21T19:00:51"
          },
          "type": "On/Off plug-in unit",
          "name": "On/Off plug 1",
          "modelid": "Plug 01",
          "manufacturername": "OSRAM",
          "productname": "On/Off plug",
          "capabilities": {
            "certified": false,
            "control": {},
            "streaming": {
              "renderer": false,
              "proxy": false
            }
          },
          "config": {
            "archetype": "classicbulb",
            "function": "functional",
            "direction": "omnidirectional"
          },
          "uniqueid": "7c:b0:3e:aa:0a:09:27:79-03",
          "swversion": "V1.05.09"
        }
      },
      "groups": {
        "0": {
          "name": "Group 0",
          "lights": [
            "9",
            "11",
            "12",
            "13"
          ],
          "sensors": [
            "1"
          ],
          "type": "LightGroup",
          "state": {
            "all_on": false,
            "any_on": true
          },
          "recycle": false,
          "action": {
            "on": false,
            "alert": "select"
          },
          "scenes": []
        },
        "1": {
          "name": "Lab",
          "lights": [
            "11",
            "13",
            "9"
          ],
          "sensors": [],
          "type": "Room",
          "state": {
            "all_on": false,
            "any_on": true
          },
          "recycle": false,
          "class": "Garage",
          "action": {
            "on": false,
            "alert": "select"
          },
          "scenes": []
        },
        "2": {
          "name": "Wohnzimmer",
          "lights": [
            "12"
          ],
          "sensors": [],
          "type": "Room",
          "state": {
            "all_on": true,
            "any_on": true
          },
          "recycle": false,
          "class": "Living room",
          "action": {
            "on": true,
            "alert": "select"
          },
          "scenes": []
        },
        "3": {
          "name": "Flur",
          "lights": [],
          "sensors": [],
          "type": "Room",
          "state": {
            "all_on": false,
            "any_on": false
          },
          "recycle": false,
          "class": "Other",
          "action": {
            "on": false,
            "alert": "none"
          },
          "scenes": []
        },
        "4": {
          "name": "Außen",
          "lights": [
            "13"
          ],
          "sensors": [],
          "type": "Zone",
          "state": {
            "all_on": false,
            "any_on": false
          },
          "recycle": false,
          "class": "Downstairs",
          "action": {
            "on": false,
            "alert": "select"
          },
          "scenes": []
        },
        "5": {
          "name": "Küche",
          "lights": [],
          "sensors": [],
          "type": "Room",
          "state": {
            "all_on": false,
            "any_on": false
          },
          "recycle": false,
          "class": "Kitchen",
          "action": {
            "on": false,
            "alert": "none"
          },
          "scenes": []
        }
      },
      "config": {
        "name": "Philips hue",
        "zigbeechannel": 25,
        "bridgeid": "ECB5FAFFFE182E85",
        "mac": "*****************",
        "dhcp": true,
        "ipaddress": "192.***.***.50",
        "netmask": "255.255.255.0",
        "gateway": "192.***.***.1",
        "proxyaddress": "none",
        "proxyport": 0,
        "UTC": "2021-12-23T20:59:44",
        "localtime": "2021-12-23T21:59:44",
        "timezone": "Europe/Berlin",
        "modelid": "BSB002",
        "datastoreversion": "113",
        "swversion": "1948086000",
        "apiversion": "1.48.0",
        "swupdate": {
          "updatestate": 0,
          "checkforupdate": false,
          "devicetypes": {
            "bridge": false,
            "lights": [],
            "sensors": []
          },
          "url": "",
          "text": "",
          "notify": true
        },
        "swupdate2": {
          "checkforupdate": false,
          "lastchange": "2021-12-21T19:00:51",
          "bridge": {
            "state": "noupdates",
            "lastinstall": "2021-11-09T13:57:33"
          },
          "state": "noupdates",
          "autoinstall": {
            "updatetime": "T14:00:00",
            "on": true
          }
        },
        "linkbutton": false,
        "portalservices": true,
        "portalconnection": "connected",
        "portalstate": {
          "signedon": true,
          "incoming": false,
          "outgoing": true,
          "communication": "disconnected"
        },
        "internetservices": {
          "internet": "connected",
          "remoteaccess": "connected",
          "time": "connected",
          "swupdate": "connected"
        },
        "factorynew": false,
        "replacesbridgeid": null,
        "backup": {
          "status": "idle",
          "errorcode": 0
        },
        "starterkitid": "",
        "whitelist": {
        }
      },
      "schedules": {},
      "scenes": {},
      "rules": {},
      "sensors": {
        "1": {
          "state": {
            "daylight": false,
            "lastupdated": "2021-12-23T14:32:00"
          },
          "config": {
            "on": true,
            "configured": true,
            "sunriseoffset": 30,
            "sunsetoffset": -30
          },
          "name": "Daylight",
          "type": "Daylight",
          "modelid": "PHDL00",
          "manufacturername": "Signify Netherlands B.V.",
          "swversion": "1.0"
        }
      },
      "resourcelinks": {}
    }
  ]
}
ebaauw commented 2 years ago

here is my log from after a fresh restart

Thanks. I'm afraid you didn't enable Homebridge debug mode? Now it doesn't log the notification. Next time, better attach the file, instead of copy/pasting large amounts of text.

and the dump

Only four OSRAM plugs? I wouldn't expect any "weird" notifications from them. Maybe the zone - I don't have any of those. Were you doing any configuration in the Hue app, when the crash occurred?

hoodie commented 2 years ago

merry xmas, I'm keeping an eye on it, but unfortunately it has not reoccurred since I turned on debug mode

ebaauw commented 2 years ago

Error handler fix in v0.13.32.