search

NorthernMan54 / homebridge-alexa

Expose your homebridge controlled devices to Amazon Alexa.
https://www.homebridge.ca
458 stars 68 forks source link

Homebridge crash #349

Closed recom273 closed 4 years ago

recom273 commented 4 years ago

I'm running the homebridge beta 1.2.-Beta 3

I noticed this red error appearing once every half hour as I was working on another screen. There doesn't seem to be any pattern, and the instance restarts without any issue and runs fine for a while and repeats.

[7/22/2020, 09:28:57] [Hue] Entrance Motion Sensor: set homekit motion from 0 to 1 [7/22/2020, 09:28:57] TypeError: Cannot read property 'event' of undefined at /usr/local/lib/node_modules/homebridge-alexa/lib/alexaActions.js:706:17 at Array.forEach (:null:null) at alexaHome.alexaEvent (/usr/local/lib/node_modules/homebridge-alexa/lib/alexaActions.js:689:10) at EventEmitter.emit (events.js:315:20) at HAPNodeJSClient. (/usr/local/lib/node_modules/homebridge-alexa/lib/alexaActions.js:48:22) at HAPNodeJSClient.emit (events.js:315:20) at HAPNodeJSClient. (/usr/local/lib/node_modules/homebridge-alexa/node_modules/hap-node-client/HAPNodeJSClient.js:97:10) at EventEmitter.emit (events.js:315:20) at _sendHapEvent (/usr/local/lib/node_modules/homebridge-alexa/node_modules/hap-node-client/lib/eventedHttpClient.js:118:24) at Socket. (/usr/local/lib/node_modules/homebridge-alexa/node_modules/hap-node-client/lib/eventedHttpClient.js:69:11) at Socket.emit (events.js:315:20) at addChunk (_stream_readable.js:295:12) at readableAddChunk (_stream_readable.js:271:9) at Socket.Readable.push (_stream_readable.js:212:10) at TCP.onStreamRead (internal/stream_base_commons.js:186:23)

[7/22/2020, 09:28:57] Got SIGTERM, shutting down Homebridge... [7/22/2020, 09:29:02] [Hue] goodbye [7/22/2020, 09:29:02] [HB Supervisor] Homebridge Process Ended. Code: 143, Signal: null [7/22/2020, 09:29:07] [HB Supervisor] Restarting Homebridge... [7/22/2020, 09:29:07] [HB Supervisor] Starting Homebridge with extra flags: -I

NorthernMan54 commented 4 years ago

To debug this further can you enable the debug flag and share a log around the event, details are here for enabling the debug flag.

https://github.com/NorthernMan54/homebridge-alexa/blob/master/README.md#debug

With the debug log enabled, can you share the messages around the crash. It should look like something like this. This is from my machine when I trigger my motion sensor.

hapNodeJSClient Events [{"host":"192.168.1.11","port":51826,"aid":21,"iid":16,"value":true,"status":true}] +3m
alexaActions Events [{"host":"192.168.1.11","port":51826,"aid":21,"iid":16,"value":true,"status":true}] +3m
alexaLocal Sending message {"context":{},"event":{"header":{"messageId":"76cbd7e0-f002-48ff-9444-dc545fdeeb7a","namespace":"Alexa","name":"ChangeReport","payloadVersion":"3"},"endpoint":{"endpointId":"QkM6MjI6M0Q6RTM6Q0Y6MzItaG9tZWJyaWRnZS1XU1NFTlNPUi1Qb3JjaCBNb3Rpb24tMDAwMDAwODUtMDAwMC0xMDAwLTgwMDAtMDAyNkJCNzY1Mjkx"},"payload":{"change":{"cause":{"type":"PHYSICAL_INTERACTION"},"properties":[{"namespace":"Alexa.MotionSensor","name":"detectionState","value":"DETECTED","timeOfSample":"2020-07-23T01:38:10.100Z","uncertaintyInMilliseconds":500}]}}}} +4m
recom273 commented 4 years ago

[7/23/2020, 10:49:47] [Hue] Office Motion Sensor: set homekit motion from 0 to 1 2020-07-23T03:49:47.625Z hapNodeJSClient Events [{"host":"127.0.0.1","port":51068,"aid":77,"iid":10,"value":true,"status":true}] 2020-07-23T03:49:47.625Z alexaActions Events [{"host":"127.0.0.1","port":51068,"aid":77,"iid":10,"value":true,"status":true}] 2020-07-23T03:49:47.665Z alexaLocal Sending message {"context":{},"event":{"header":{"messageId":"55d13e43-6b08-4018-aa9c-bddc08941a5c","namespace":"Alexa","name":"ChangeReport","payloadVersion":"3"},"endpoint":{"endpointId":"MEU6MDM6NkI6QkE6NTk6MTYtaG9tZWJyaWRnZS1MVU1JLU9mZmljZSBNb3Rpb24gU2Vuc29yLTAwMDAwMDg1LTAwMDAtMTAwMC04MDAwLTAwMjZCQjc2NTI5MQ=="},"payload":{"change":{"cause":{"type":"PHYSICAL_INTERACTION"},"properties":[{"namespace":"Alexa.MotionSensor","name":"detectionState","value":"DETECTED","timeOfSample":"2020-07-23T03:49:47.629Z","uncertaintyInMilliseconds":500}]}}}}

I turned off the 'routines' checkbox in the settings and it seemed to be ok yesterday.

recom273 commented 4 years ago

I also saw this in the log when I restarted

[7/23/2020, 10:45:43] [Alexa] alexaDiscovery - returned 130 devices 2020-07-23T03:45:43.331Z alexaActions registerEvents [ '{"host":"127.0.0.1","port":51068,"aid":48,"iid":10}': { '0': 'NOT_DETECTED', '1': 'DETECTED', endpointID: 'MEU6MDM6NkI6QkE6NTk6MTYtaG9tZWJyaWRnZS1FbGdhdG8tUnVzc2VsbCBBd2F5IE1vZGUtMDAwMDAwODAtMDAwMC0xMDAwLTgwMDAtMDAyNkJCNzY1Mjkx', template: 'ContactSensor' }, '{"host":"127.0.0.1","port":51068,"aid":49,"iid":10}': { '0': 'NOT_DETECTED', '1': 'DETECTED', endpointID: 'MEU6MDM6NkI6QkE6NTk6MTYtaG9tZWJyaWRnZS1FbGdhdG8tTml0IEF3YXkgTW9kZS0wMDAwMDA4MC0wMDAwLTEwMDAtODAwMC0wMDI2QkI3NjUyOTE=', template: 'ContactSensor' }, '{"host":"127.0.0.1","port":51068,"aid":35,"iid":10}': { '0': 'DETECTED', '1': 'NOT_DETECTED', endpointID: 'MEU6MDM6NkI6QkE6NTk6MTYtaG9tZWJyaWRnZS1Ccm9hZGxpbmstR2FyYWdlIERvb3ItMDAwMDAwNDEtMDAwMC0xMDAwLTgwMDAtMDAyNkJCNzY1Mjkx', template: 'ContactSensor' }, '{"host":"127.0.0.1","port":51068,"aid":37,"iid":10}': { '0': 'NOT_DETECTED', '1': 'DETECTED', endpointID: 'MEU6MDM6NkI6QkE6NTk6MTYtaG9tZWJyaWRnZS1ob21lYnJpZGdlLWFsZXhhLUFsZXhhLTAwMDAwMDgwLTAwMDAtMTAwMC04MDAwLTAwMjZCQjc2NTI5MQ==', template: 'ContactSensor' } .............

recom273 commented 4 years ago

Heres a debug after the crash happens

[7/23/2020, 12:27:47] [Hue] Bedroom Motion Sensor: set homekit motion from 0 to 1 2020-07-23T05:27:47.460Z hapNodeJSClient Events [{"host":"127.0.0.1","port":51068,"aid":85,"iid":10,"value":true,"status":true}] 2020-07-23T05:27:47.461Z alexaActions Events [{"host":"127.0.0.1","port":51068,"aid":85,"iid":10,"value":true,"status":true}] [7/23/2020, 12:27:47] TypeError: Cannot read property 'event' of undefined at /usr/local/lib/node_modules/homebridge-alexa/lib/alexaActions.js:706:17 at Array.forEach (:null:null) at alexaHome.alexaEvent (/usr/local/lib/node_modules/homebridge-alexa/lib/alexaActions.js:689:10) at EventEmitter.emit (events.js:315:20) at HAPNodeJSClient. (/usr/local/lib/node_modules/homebridge-alexa/lib/alexaActions.js:48:22) at HAPNodeJSClient.emit (events.js:315:20) at HAPNodeJSClient. (/usr/local/lib/node_modules/homebridge-alexa/node_modules/hap-node-client/HAPNodeJSClient.js:97:10) at EventEmitter.emit (events.js:315:20) at _sendHapEvent (/usr/local/lib/node_modules/homebridge-alexa/node_modules/hap-node-client/lib/eventedHttpClient.js:118:24) at Socket. (/usr/local/lib/node_modules/homebridge-alexa/node_modules/hap-node-client/lib/eventedHttpClient.js:69:11) at Socket.emit (events.js:315:20) at addChunk (_stream_readable.js:295:12) at readableAddChunk (_stream_readable.js:271:9) at Socket.Readable.push (_stream_readable.js:212:10) at TCP.onStreamRead (internal/stream_base_commons.js:186:23)

2020-07-23T05:27:47.477Z hapNodeJSClient Events [{"host":"192.168.68.110","port":51068,"aid":85,"iid":10,"value":true,"status":true}] 2020-07-23T05:27:47.477Z alexaActions Events [{"host":"192.168.68.110","port":51068,"aid":85,"iid":10,"value":true,"status":true}] [7/23/2020, 12:27:47] Got SIGTERM, shutting down Homebridge... 2020-07-23T05:27:47.539Z hapHttpClient Disconnected from server 127.0.0.1:51068 undefined 2020-07-23T05:27:47.539Z hapNodeJSClient HAPevent events Reregister { server: '127.0.0.1:51068', deviceID: undefined } 2020-07-23T05:27:47.540Z hapHttpClient Disconnected from server 192.168.68.110:51068 undefined 2020-07-23T05:27:47.540Z hapNodeJSClient HAPevent events Reregister { server: '192.168.68.110:51068', deviceID: undefined } 2020-07-23T05:27:47.542Z alexaLocal Sending message {"context":{},"event":{"header":{"messageId":"012ad573-cf16-48cd-a3d2-59d83cbe19f9","namespace":"Alexa","name":"ChangeReport","payloadVersion":"3"},"endpoint":{"endpointId":"MEU6MDM6NkI6QkE6NTk6MTYtaG9tZWJyaWRnZS1MVU1JLUJlZHJvb20gTW90aW9uIFNlbnNvci0wMDAwMDA4NS0wMDAwLTEwMDAtODAwMC0wMDI2QkI3NjUyOTE="},"payload":{"change":{"cause":{"type":"PHYSICAL_INTERACTION"},"properties":[{"namespace":"Alexa.MotionSensor","name":"detectionState","value":"DETECTED","timeOfSample":"2020-07-23T05:27:47.480Z","uncertaintyInMilliseconds":500}]}}}} [7/23/2020, 12:27:52] [Hue] goodbye [7/23/2020, 12:27:52] [HB Supervisor] Homebridge Process Ended. Code: 143, Signal: null [7/23/2020, 12:27:57] [HB Supervisor] Restarting Homebridge... [7/23/

NorthernMan54 commented 4 years ago

Are you using routines in Alexa triggered by homebridge devices? If not you can set routines to false.

recom273 commented 4 years ago

Yes, I was using it, as I think it’s an excellent feature, but I can live without it.

I was more reporting an issue. I don’t think I had this issue with beta 1.0 or stable versions.

mreassassin commented 4 years ago

I'm getting the same thing now. never used to get crashes til now. I did unplug one of my smart plugs. could it be looking for that? I'll try plugging that in and see if it helps...

I'm also using routines, but could live without them if it will stop the crashes.

NorthernMan54 commented 4 years ago

Likely, try removing it from the Alexa app

mreassassin commented 4 years ago

that didn't help. it seems to crash, sometimes, when I open homekit on my phone. I've tried turning things on and off with alexa and that seems to work fine. turning things on and off in homekit seems to work fine. it's just sometimes when I close homekit and launch it again later, it will crash homebridge.

it may also have something to do with my ring doorbell?

here's my log:

[8/10/2020, 18:19:30] [Ring] Front Door Detected Motion. Loading snapshot before sending event to HomeKit [8/10/2020, 18:19:35] [XboxTv] Device: 192.168.1.218 BedroomXbox, get current Power state successful, state: OFF [8/10/2020, 18:19:35] [XboxTv] Device: 192.168.1.218 BedroomXbox, get current App successful:
[8/10/2020, 18:19:35] [XboxTv] Device: 192.168.1.35 GarageXbox, get current App successful:
[8/10/2020, 18:19:35] [XboxTv] Device: 192.168.1.35 GarageXbox, get current Power state successful, state: OFF [8/10/2020, 18:19:35] [XboxTv] Device: 192.168.1.118 XBOX, get current App successful: Roblox roblox_6nk717fhb5z8t!RobloxClient0 [8/10/2020, 18:19:35] [XboxTv] Device: 192.168.1.118 XBOX, get current Power state successful, state: ON [8/10/2020, 18:19:36] [CMD Switch] Garage XBOX-ON is off. [8/10/2020, 18:19:36] [CMD Switch] PS4 is off. [8/10/2020, 18:19:36] [Living Room Volume] Get receiver volume 37 [8/10/2020, 18:19:36] [Living Room Volume] Receiver MainZone Volume power state is 1 2020-08-11T01:19:37.022Z hapNodeJSClient Events [{"host":"127.0.0.1","port":51826,"aid":70,"iid":32,"value":true,"status":true}] 2020-08-11T01:19:37.023Z alexaActions Events [{"host":"127.0.0.1","port":51826,"aid":70,"iid":32,"value":true,"status":true}] [8/10/2020, 18:19:37] TypeError: Cannot read property 'event' of undefined at /usr/lib/node_modules/homebridge-alexa/lib/alexaActions.js:706:17 at Array.forEach () at alexaHome.alexaEvent (/usr/lib/node_modules/homebridge-alexa/lib/alexaActions.js:689:10) at EventEmitter.emit (events.js:315:20) at HAPNodeJSClient. (/usr/lib/node_modules/homebridge-alexa/lib/alexaActions.js:48:22) at HAPNodeJSClient.emit (events.js:315:20) at HAPNodeJSClient. (/usr/lib/node_modules/homebridge-alexa/node_modules/hap-node-client/HAPNodeJSClient.js:97:10) at EventEmitter.emit (events.js:315:20) at _sendHapEvent (/usr/lib/node_modules/homebridge-alexa/node_modules/hap-node-client/lib/eventedHttpClient.js:118:24) at Socket. (/usr/lib/node_modules/homebridge-alexa/node_modules/hap-node-client/lib/eventedHttpClient.js:69:11) 2020-08-11T01:19:37.064Z hapNodeJSClient Events [{"host":"192.168.1.22","port":51826,"aid":70,"iid":32,"value":true,"status":true}] 2020-08-11T01:19:37.064Z alexaActions Events [{"host":"192.168.1.22","port":51826,"aid":70,"iid":32,"value":true,"status":true}] [8/10/2020, 18:19:37] Got SIGTERM, shutting down Homebridge... 2020-08-11T01:19:37.360Z alexaLocal Sending message {"context":{},"event":{"header":{"messageId":"bd5d4d24-a955-4250-b7d8-689fb68b61e5","namespace":"Alexa","name":"ChangeReport","payloadVersion":"3"},"endpoint":{"endpointId":"MEU6ODQ6NkM6NzYtaG9tZWJyaWDAtMDAyNkJCNzY1Mjkx"},"payload":{"change":{"cause":{"type":"PHYSICAL_INTERACTION"},"properties":[{"namespace":"Alexa.MotionSensor","name":"detectionState","value":"DETECTED","timeOfSample":"2020-08-11T01:19:37.066Z","uncertaintyInMilliseconds":500}]}}}} 2020-08-11T01:19:37.367Z hapHttpClient Disconnected from server 127.0.0.1:51826 undefined 2020-08-11T01:19:37.368Z hapNodeJSClient HAPevent events Reregister { server: '127.0.0.1:51826', deviceID: undefined } 2020-08-11T01:19:37.370Z hapHttpClient Disconnected from server 192.168.1.22:51826 undefined 2020-08-11T01:19:37.370Z hapNodeJSClient HAPevent events Reregister { server: '192.168.1.22:51826', deviceID: undefined } [8/10/2020, 18:19:42] [HB Supervisor] Homebridge Process Ended. Code: 143, Signal: null [8/10/2020, 18:19:47] [HB Supervisor] Restarting Homebridge...

NorthernMan54 commented 4 years ago

@mreassassin Please update to the latest and try it again. I have added some defensive code to prevent the crash

mreassassin commented 4 years ago

@NorthernMan54 that seems to have done it! no crashes since! thank u!!