chrisjshull / homebridge-nest

Nest plugin for HomeBridge
700 stars 112 forks source link

Nest API call to subscribe to device settings updates returned an error: 400 / 502 #261

Closed raulfunkie closed 4 years ago

raulfunkie commented 4 years ago

Describe the bug Getting a bunch of errors on homebridge and rendering all devices useless. (No Response)

[6/5/2020, 12:31:25 AM] [Nest] Nest API call to subscribe to device settings updates returned an error: 400
[6/5/2020, 12:31:35 AM] [Nest] Nest API call to subscribe to device settings updates returned an error: 400
[6/5/2020, 12:31:46 AM] [Nest] Nest API call to subscribe to device settings updates returned an error: 400
[6/5/2020, 12:31:57 AM] [Nest] Nest API call to subscribe to device settings updates returned an error: 400
[6/5/2020, 12:32:08 AM] [Nest] Nest API call to subscribe to device settings updates returned an error: 400
[6/5/2020, 12:32:19 AM] [Nest] Nest API call to subscribe to device settings updates returned an error: 400
[6/5/2020, 12:32:30 AM] [Nest] Nest API call to subscribe to device settings updates returned an error: 400
[6/5/2020, 12:32:41 AM] [Nest] Nest API call to subscribe to device settings updates returned an error: 400
[6/5/2020, 12:32:52 AM] [Nest] Nest API call to subscribe to device settings updates returned an error: 400
[6/5/2020, 12:33:03 AM] [Nest] Nest API call to subscribe to device settings updates returned an error: 400
[6/5/2020, 12:33:14 AM] [Nest] Nest API call to subscribe to device settings updates returned an error: 400
[6/5/2020, 12:33:26 AM] [Nest] Nest API call to subscribe to device settings updates returned an error: 400
[6/5/2020, 12:33:37 AM] [Nest] Nest API call to subscribe to device settings updates returned an error: 400
[6/5/2020, 12:33:48 AM] [Nest] Nest API call to subscribe to device settings updates returned an error: 400
[6/5/2020, 12:33:58 AM] [Nest] Nest API call to subscribe to device settings updates returned an error: 400
[6/5/2020, 12:34:09 AM] [Nest] Nest API call to subscribe to device settings updates returned an error: 400
[6/5/2020, 12:34:20 AM] [Nest] Nest API call to subscribe to device settings updates returned an error: 400
[6/5/2020, 12:34:31 AM] [Nest] Nest API call to subscribe to device settings updates returned an error: 400
[6/5/2020, 12:34:42 AM] [Nest] Nest API call to subscribe to device settings updates returned an error: 400
[6/5/2020, 12:34:53 AM] [Nest] Nest API call to subscribe to device settings updates returned an error: 400
[6/5/2020, 12:35:04 AM] [Nest] Nest API call to subscribe to device settings updates returned an error: 400
[6/5/2020, 12:35:15 AM] [Nest] Nest API call to subscribe to device settings updates returned an error: 400
[6/5/2020, 12:35:26 AM] [Nest] Nest API call to subscribe to device settings updates returned an error: 400
[6/5/2020, 12:35:37 AM] [Nest] Nest API call to subscribe to device settings updates returned an error: 400
[6/5/2020, 12:35:47 AM] [Nest] Nest API call to subscribe to device settings updates returned an error: 400
[6/5/2020, 12:35:58 AM] [Nest] Nest API call to subscribe to device settings updates returned an error: 400
[6/5/2020, 12:36:09 AM] [Nest] Nest API call to subscribe to device settings updates returned an error: 400
[6/5/2020, 12:36:20 AM] [Nest] Nest API call to subscribe to device settings updates returned an error: 400
[6/5/2020, 12:36:31 AM] [Nest] Nest API call to subscribe to device settings updates returned an error: 502
[6/5/2020, 12:36:41 AM] [Nest] Nest API call to subscribe to device settings updates returned an error: 502
{}
[6/5/2020, 2:35:31 PM] [Nest] Nest API call to subscribe to device settings updates returned an error: EAI_AGAIN
{}
{}
{}

To Reproduce Steps to reproduce the behavior:

  1. Run homebridge normally (I'm using pm2)
  2. After a while it dies and I have to restart it from terminal.

Expected behavior It should work forever and ever and ever and ever.

Include with your bug report this version info:

node --version
homebridge --version

Make sure you have the latest LTS from https://nodejs.org and the latest packages: npm upgrade -g homebridge homebridge-nest

Also include debug log output from startup through seeing the issue: DEBUG=* homebridge -D

[6/5/2020, 6:24:25 PM] Loaded config.json with 1 accessories and 3 platforms.
[6/5/2020, 6:24:25 PM] ---
[6/5/2020, 6:24:25 PM] Loaded plugin: homebridge-eufy-robovac@1.2.2
[6/5/2020, 6:24:25 PM] Registering accessory 'homebridge-eufy-robovac.Eufy RoboVac'
[6/5/2020, 6:24:25 PM] ---
[6/5/2020, 6:24:27 PM] Loaded plugin: homebridge-hue@0.11.69
[6/5/2020, 6:24:27 PM] Registering platform 'homebridge-hue.Hue'
[6/5/2020, 6:24:27 PM] ---
[6/5/2020, 6:24:27 PM] Loaded plugin: homebridge-nest@4.4.6
[6/5/2020, 6:24:27 PM] Registering platform 'homebridge-nest.Nest'
[6/5/2020, 6:24:27 PM] ---
[6/5/2020, 6:24:27 PM] Loaded plugin: homebridge-webos-tv@1.8.7
[6/5/2020, 6:24:27 PM] Registering accessory 'homebridge-webos-tv.webostv'
[6/5/2020, 6:24:27 PM] Registering platform 'homebridge-webos-tv.webostv'
[6/5/2020, 6:24:27 PM] ---
[6/5/2020, 6:24:27 PM] Loading 3 platforms...
[6/5/2020, 6:24:27 PM] [Nest] Initializing Nest platform...
[6/5/2020, 6:24:27 PM] [Nest] Fetching Nest devices.
[6/5/2020, 6:24:27 PM] [Hue] Initializing Hue platform...
[6/5/2020, 6:24:27 PM] [Hue] homebridge-hue v0.11.69, node v12.17.0, homebridge v1.1.0
[6/5/2020, 6:24:27 PM] [webostv] Initializing webostv platform...
[6/5/2020, 6:24:27 PM] Loading 1 accessories...
[6/5/2020, 6:24:27 PM] [Robotina] Initializing Eufy RoboVac accessory...
Looking for device...
[6/5/2020, 6:24:27 PM] [webostv] Init - initializing devices
[6/5/2020, 6:24:27 PM] [webostv] Init - initializing device with name: TV
[6/5/2020, 6:24:27 PM] TV is running on port 45383.
[6/5/2020, 6:24:27 PM] Please add [TV] manually in Home app. Setup Code: 014-09-012
[6/5/2020, 6:24:28 PM] [Hue] zigbee: dresden elektronik deCONZ gateway v2.5.77, api v1.16.0
[6/5/2020, 6:24:28 PM] [Hue] zigbee: 5 accessories
[6/5/2020, 6:24:28 PM] [Hue] masked debug info dumped to /home/pi/.homebridge/homebridge-hue.json.gz
[6/5/2020, 6:24:28 PM] Initializing platform accessory 'zigbee'...
[6/5/2020, 6:24:28 PM] [Hue] zigbee: 2 services
[6/5/2020, 6:24:28 PM] Initializing platform accessory 'Master Bedroom'...
[6/5/2020, 6:24:28 PM] Initializing platform accessory 'Guest Room'...
[6/5/2020, 6:24:28 PM] Initializing platform accessory 'Main Door'...
[6/5/2020, 6:24:28 PM] Initializing platform accessory 'Mini Fridge'...
Found device xxx at 192.168.7.248
Connecting...
Connected!
Status Updated!
Status Updated!
[6/5/2020, 6:24:31 PM] [Nest] initing thermostat "AC Thermostat": deviceId: XXX structureId: XXX
[6/5/2020, 6:24:31 PM] Initializing platform accessory 'AC Thermostat'...
Setup Payload:
X-HM://XXX
Scan this code with your HomeKit app on your iOS device to pair with Homebridge:
- QR code thingy goes here-
Or enter this code with your HomeKit app on your iOS device to pair with Homebridge:
- Homebridge code goes here-

[6/5/2020, 6:24:31 PM] Homebridge is running on port 51826.
[6/5/2020, 6:25:19 PM] [Hue] Mini Fridge: set homekit motion from 0 to 1
[6/5/2020, 6:26:24 PM] [Hue] Mini Fridge: set homekit motion from 1 to 0
adriancable commented 4 years ago

Hi, @raulfunkie. What happens when you restart Homebridge? Does it then work again?

raulfunkie commented 4 years ago

Yes. It starts to work normally again. And this happens after a while (again).

adriancable commented 4 years ago

@raulfunkie - in that case, what we really need is a log showing what happens around the time this problem starts happening.

Please can you add "Debug.Verbose" to the "options" array in your config.json, and run: homebridge -D

Then see if you can catch the problem starting, and email me the complete log (it will be quite large) to me at adrian.cable@gmail.com. Also let me know whether you are using a Nest account or a Google account. Thanks!

raulfunkie commented 4 years ago

Can I add that value to the config.json file and then run homebridge using pm2? It's keeping an error log and output log too.

Just confirm and I'll do it right away and wait for it to happen.

adriancable commented 4 years ago

Yes - just to be clear - in config.json, under

“platform”: “Nest”,

add

“options”: [ “Debug.Verbose” ],

You’ll also need to make sure homebridge runs with the -D command line parameter. (This is not the same as setting the DEBUG environment variable, which I don’t need.)

On Jun 5, 2020, at 17:29, Raul Rincon notifications@github.com wrote:

 Can I add that value to the config.json file and then run homebridge using pm2? It's keeping an error log and output log too.

Just confirm and I'll do it right away and wait for it to happen.

— You are receiving this because you commented. Reply to this email directly, view it on GitHub, or unsubscribe.

raulfunkie commented 4 years ago

Screen Shot 2020-06-06 at 1 41 59 PM

Like that?

adriancable commented 4 years ago

Raul - exactly - and run Homebridge with the -D command line parameter.

On Jun 6, 2020, at 10:42, Raul Rincon notifications@github.com wrote:



Like that?

— You are receiving this because you commented. Reply to this email directly, view it on GitHub, or unsubscribe.

raulfunkie commented 4 years ago

Alright just did that, but I'm not sure where I can find the log for this particular run of homebridge.

adriancable commented 4 years ago

Raul - you use pm2, right? I believe that stores logs on your behalf.

Or just stop pm2 and run Homebridge manually, and the logs will appear on the console.

On Jun 6, 2020, at 10:56, Raul Rincon notifications@github.com wrote:

 Alright just did that, but I'm not sure where I can find the log for this particular run of homebridge.

— You are receiving this because you commented. Reply to this email directly, view it on GitHub, or unsubscribe.

raulfunkie commented 4 years ago

hb-verbose.log

There you go.

adriancable commented 4 years ago

Raul - great - the log is set up correctly. But we will need to wait till you get the error, and then send me the log straight after.

In this log, I see you connecting to the Nest service fine, and then the log stops before there are any errors.

On Jun 6, 2020, at 11:04, Raul Rincon notifications@github.com wrote:

 hb-verbose.log

There you go.

— You are receiving this because you commented. Reply to this email directly, view it on GitHub, or unsubscribe.

raulfunkie commented 4 years ago

Oh that makes sense. I’ll run it again and leave it be so it registers what happens when it fails. Sorry about that!

adriancable commented 4 years ago

Raul - perfect! Thanks for your help.

On Jun 6, 2020, at 11:18, Raul Rincon notifications@github.com wrote:

 Oh that makes sense. I’ll run it again and leave it be so it registers what happens when it fails. Sorry about that!

— You are receiving this because you commented. Reply to this email directly, view it on GitHub, or unsubscribe.

raulfunkie commented 4 years ago

I just ran the command again adding: tee /home/pi/hb.log so it logs the console output. I'll keep an eye out when it crashes so I can attach the log right away here.

Thanks for your help and time!

raulfunkie commented 4 years ago

Not sure what happened but the console (terminal window) stopped updating events at around 3:41pm, and I checked the .log file and it stopped updating around 3:57pm (I can't see an error on the console tho.)

I stopped the process (ctrl+c) and this showed:

[6/6/2020, 3:40:56 PM] [Hue] zigbee: gateway request 967: get /sensors
[6/6/2020, 3:40:56 PM] [Hue] zigbee: gateway request 967: ok
[6/6/2020, 3:41:01 PM] [Hue] zigbee: gateway request 968: get /sensors
[6/6/2020, 3:41:01 PM] [Hue] zigbee: gateway request 968: ok
[6/6/2020, 3:41:06 PM] [Hue] zigbee: gateway request 969: get /sensors
[6/6/2020, 3:41:06 PM] [Hue] zigbee: gateway request 969: ok
[6/6/2020, 3:41:11 PM] [Hue] zigbee: gateway request 970: get /sensors
[6/6/2020, 3:41:11 PM] [Hue] zigbee: gateway request 970: ok
client_loop: send disconnect: Broken pipe

Here's the file for reference: hb-verbose2.log

raulfunkie commented 4 years ago

So, I'm running homebridge again using this command to run it from pm2: pm2 start homebridge -- -D.

It will pass the -D argument to homebridge, and will also keep the logs of the console and any errors homebridge might throw. Let's see how this one works.

raulfunkie commented 4 years ago

Died on me again. Here are the logs. Not even sure if it's related to Nest or what, since it keeps on logging things (but home app shows devices from Homebridge as No Response). homebridge-out.log homebridge-error.log

adriancable commented 4 years ago

@raulfunkie - the logs look fine. We don't see any evidence of the 400/502 errors you saw before. Is it all your Homebridge devices going to 'No Response' or just the Nest devices? If the former, it probably isn't to do with the Nest plug-in. (although I do still want to troubleshoot the 400/502 errors you're getting, if you can reproduce that.)

raulfunkie commented 4 years ago

Yeah seems like it’s something else causing the issue. All devices go No Response

github-actions[bot] commented 4 years ago

This issue has been automatically marked as stale because it has not had recent activity. It will be closed if no further activity occurs. Thank you for your contributions.