michaelwoods/onstar2mqtt

504 Gateway Timeout

BennyDaBee opened this issue · 19 comments

Now I am not sure if this is really solvable, but I have been getting a huge amount of 504 Gateway timeout errors recently.

Actually going to do some TS on my network before I open this again.

@BennyDaBee, in seems that OnStar has been throttling API access a lot more as of late, so I've been seeing the same thing as well.

Its really been causing a pain as my stuff is getting outdated data as well as commands dont reliably work anymore.

Correct me if Im wrong @BigThunderSR, but shouldnt we be seeing the same problems on the app? As OnStarJS mimics how the app requests data no?

Correct me if Im wrong @BigThunderSR, but shouldnt we be seeing the same problems on the app? As OnStarJS mimics how the app requests data no?

Since there's no way to force refresh the app on command, it's hard to make a 1:1 comparison unfortunately. I know this isn't directly related, but mentioning for comparison. I mentioned in another issue thread that even the app becomes unable to send commands to the car after it goes into the deep sleep state, so even the app isn't immune to some things like that.

BTW, I only seem to hit the 504s when trying to get diagnostics via API. None of my remote commands seem to hit the 504s via API.

Yea trying again, it does appear that actual commands do work, but most of my Diagnostic requests are getting that 504. The one command I kept on trying has a typo, hence why it wasnt working lol.

If the server is timing out there's not much we can do. Maybe they are implementing rate limiting this way, or the library polling isn't waiting long enough for the service (there should be a config for this).

Correct me if Im wrong @BigThunderSR, but shouldnt we be seeing the same problems on the app? As OnStarJS mimics how the app requests data no?

Since there's no way to force refresh the app on command, it's hard to make a 1:1 comparison unfortunately. I know this isn't directly related, but mentioning for comparison. I mentioned in another issue thread that even the app becomes unable to send commands to the car after it goes into the deep sleep state, so even the app isn't immune to some things like that.

BTW, I only seem to hit the 504s when trying to get diagnostics via API. None of my remote commands seem to hit the 504s via API.

First let me say thank you to @michaelwoods and @BigThunderSR for always staying on top on this integration. I typically pull @BigThunderSR image lately lol

I have been using this for 3+ years now and the gateway timeouts have always been an issue, and like @BigThunderSR stated their own app isnt immune to this.

I have a gas vehicle so I know i dont have a use case, but curious to what information you are wanting in diagnostics that would change with the vehicle sitting there.

Do the batteries drain that quick on the EV thats its something that needs constant monitoring or something, @BennyDaBee ?

Just curious :D

I do have a gas vehicle as well. I know the timeout would normally start after about 3 diagnostic requests from when the truck was shut off. However, as of late, if I go for a drive, it sometimes will not update until the next day, and checking the console its still making the requests every half hour with it timing out.

I just updated my fork where the polling status is now published to a MQTT topic (which you specify) along with command response status where the topic is determined by the command name (README updated with schema). Please try the "latest" docker image and let me know what you think. I will publish the changes in a versioned release after I get some feedback. Thanks.

@BigThunderSR Trying your fork, but I am not able to get the Command Response to show anywhere. I did make sure I specified the MQTT_ONSTAR_POLLING_STATUS_TOPIC

Spoke too soon. Ended up using NodeRed to create MQTT IN node that is subscripted to the specified topic.

I will be running it for a bit, but when testing the topics, got this error.

error: Command error {"command":"cancelStartVehicle","err":{"request":{"authRequired":true,"body":"{}","checkRequestStatus":true,"contentType":"application/json; charset=UTF-8","headers":{},"method":0,"upgradeRequired":false,"url":"https://api.gm.com:443/api/v1/account/vehicles/EDITEDOU/requests/cancelStart1349688941703384630752"},"response":{"config":{"adapter":["xhr","http"],"env":{},"headers":{"Accept":"application/json","Accept-Encoding":"br, gzip, deflate","Accept-Language":"en-US","Authorization":"Bearer EDITED OUT","Connection":"keep-alive","Content-Type":"application/json; charset=UTF-8","Host":"api.gm.com","User-Agent":"myChevrolet/118 CFNetwork/1408.0.4 Darwin/22.5.0"},"maxBodyLength":-1,"maxContentLength":-1,"method":"get","timeout":0,"transformRequest":[null],"transformResponse":[null],"transitional":{"clarifyTimeoutError":false,"forcedJSONParsing":true,"silentJSONParsing":true},"url":"https://api.gm.com:443/api/v1/account/vehicles/EDITEDOUT/requests/cancelStart1349688941703384630752","xsrfCookieName":"XSRF-TOKEN","xsrfHeaderName":"X-XSRF-TOKEN"},"data":{"commandResponse":{"body":{"error":{"code":"ONS-220","description":"Failed to execute vehicle request.","subCode":null,"subCodeDescription":null}},"completionTime":"2023-12-24T02:23:51.323Z","requestTime":"2023-12-24T02:23:50.752Z","status":"failure","type":"cancelStart","url":"https://api.gm.com:443/api/v1/account/vehicles/EDITEDOU/requests/cancelStart1349688941703384630752"}},"headers":{"cache-control":"public; max-age=5","connection":"keep-alive","content-type":"application/json","date":"Sun, 24 Dec 2023 02:23:57 GMT","request-context":"appId=cid-v1:a7e19842-5b19-4b47-a9cf-85cc6e87a746","strict-transport-security":"max-age=31536000 ; includeSubDomains","transfer-encoding":"chunked","vary":"Origin,Access-Control-Request-Method,Access-Control-Request-Headers","x-content-type-options":"nosniff","x-frame-options":"DENY","x-vcap-request-id":"67b42812-d138-4513-49e1-4e2e87a596fe","x-xss-protection":"1; mode=block"},"request":{"_closed":true,"_contentLength":0,"_defaultKeepAlive":true,"_ended":true,"_events":{},"_eventsCount":7,"_hasBody":true,"_header":"GET /api/v1/account/vehicles/EDITEDOU/requests/cancelStart1349688941703384630752 HTTP/1.1\r\nAccept: application/json\r\nContent-Type: application/json; charset=UTF-8\r\nAccept-Language: en-US\r\nHost: api.gm.com\r\nConnection: keep-alive\r\nAccept-Encoding: br, gzip, deflate\r\nUser-Agent: myChevrolet/118 CFNetwork/1408.0.4 Darwin/22.5.0\r\nAuthorization: Bearer EDITEDOU","_headerSent":true,"_keepAliveTimeout":0,"_last":true,"_redirectable":{"_currentRequest":"[Circular]","_currentUrl":"https://api.gm.com/api/v1/account/vehicles/EDITEDOU/requests/cancelStart1349688941703384630752","_ended":true,"_ending":true,"_events":{},"_eventsCount":3,"_options":{"agents":{},"beforeRedirects":{},"headers":{"Accept":"application/json","Accept-Encoding":"br, gzip, deflate","Accept-Language":"en-US","Authorization":"Bearer EDITEDOU","Connection":"keep-alive","Content-Type":"application/json; charset=UTF-8","Host":"api.gm.com","User-Agent":"myChevrolet/118 CFNetwork/1408.0.4 Darwin/22.5.0"},"hostname":"api.gm.com","maxBodyLength":null,"maxRedirects":21,"method":"GET","nativeProtocols":{"http:":{"METHODS":["ACL","BIND","CHECKOUT","CONNECT","COPY","DELETE","GET","HEAD","LINK","LOCK","M-SEARCH","MERGE","MKACTIVITY","MKCALENDAR","MKCOL","MOVE","NOTIFY","OPTIONS","PATCH","POST","PROPFIND","PROPPATCH","PURGE","PUT","REBIND","REPORT","SEARCH","SOURCE","SUBSCRIBE","TRACE","UNBIND","UNLINK","UNLOCK","UNSUBSCRIBE"],"STATUS_CODES":{"100":"Continue","101":"Switching Protocols","102":"Processing","103":"Early Hints","200":"OK","201":"Created","202":"Accepted","203":"Non-Authoritative Information","204":"No Content","205":"Reset Content","206":"Partial Content","207":"Multi-Status","208":"Already Reported","226":"IM Used","300":"Multiple Choices","301":"Moved Permanently","302":"Found","303":"See Other","304":"Not Modified","305":"Use Proxy","307":"Temporary Redirect","308":"Permanent Redirect","400":"Bad Request","401":"Unauthorized","402":"Payment Required","403":"Forbidden","404":"Not Found","405":"Method Not Allowed","406":"Not Acceptable","407":"Proxy Authentication Required","408":"Request Timeout","409":"Conflict","410":"Gone","411":"Length Required","412":"Precondition Failed","413":"Payload Too Large","414":"URI Too Long","415":"Unsupported Media Type","416":"Range Not Satisfiable","417":"Expectation Failed","418":"I'm a Teapot","421":"Misdirected Request","422":"Unprocessable Entity","423":"Locked","424":"Failed Dependency","425":"Too Early","426":"Upgrade Required","428":"Precondition Required","429":"Too Many Requests","431":"Request Header Fields Too Large","451":"Unavailable For Legal Reasons","500":"Internal Server Error","501":"Not Implemented","502":"Bad Gateway","503":"Service Unavailable","504":"Gateway Timeout","505":"HTTP Version Not Supported","506":"Variant Also Negotiates","507":"Insufficient Storage","508":"Loop Detected","509":"Bandwidth Limit Exceeded","510":"Not Extended","511":"Network Authentication Required"},"globalAgent":{"_events":{},"_eventsCount":2,"defaultPort":80,"freeSockets":{},"keepAlive":false,"keepAliveMsecs":1000,"maxFreeSockets":256,"maxSockets":null,"maxTotalSockets":null,"options":{"noDelay":true,"path":null},"protocol":"http:","requests":{},"scheduling":"lifo","sockets":{},"totalSocketCount":0},"maxHeaderSize":16384},"https:":{"globalAgent":{"_events":{},"_eventsCount":2,"_sessionCache":{"list":["api.gm.com:443:::::::::::::::::::::"],"map":{"api.gm.com:443:::::::::::::::::::::":{"data":EDITEDOU,"type":"Buffer"}}},"defaultPort":443,"freeSockets":{},"keepAlive":false,"keepAliveMsecs":1000,"maxCachedSessions":100,"maxFreeSockets":256,"maxSockets":null,"maxTotalSockets":null,"options":{"noDelay":true,"path":null},"protocol":"https:","requests":{},"scheduling":"lifo","sockets":{"api.gm.com:443:::::::::::::::::::::":[{"_SNICallback":null,"_closeAfterHandlingError":false,"_controlReleased":true,"_events":{"close":[null,null,null]},"_eventsCount":8,"_hadError":false,"_host":"api.gm.com","_httpMessage":"[Circular]","_newSessionPending":false,"_parent":null,"_pendingData":null,"_pendingEncoding":"","_readableState":{"awaitDrainWriters":null,"buffer":{"head":null,"length":0,"tail":null},"decoder":null,"defaultEncoding":"utf8","encoding":null,"errored":null,"flowing":true,"highWaterMark":16384,"length":0,"pipes":[],"state":323672},"_rejectUnauthorized":true,"_requestCert":true,"_secureEstablished":true,"_securePending":false,"_server":null,"_sockname":null,"_tlsOptions":{"isServer":false,"pipe":false,"rejectUnauthorized":true,"requestCert":true,"secureContext":{"context":{}},"session":{"data":EDITEDOU],"type":"Buffer"}},"_writableState":{"afterWriteTickInfo":null,"allBuffers":true,"allNoop":true,"autoDestroy":true,"bufferProcessing":false,"buffered":[],"bufferedIndex":0,"closeEmitted":true,"closed":true,"constructed":true,"corked":0,"decodeStrings":false,"defaultEncoding":"utf8","destroyed":true,"emitClose":false,"ended":false,"ending":false,"errorEmitted":false,"errored":null,"finalCalled":false,"finished":fals�@e,"highWaterMark":16384,"length":0,"needDrain":false,"objectMode":false,"pendingcb":0,"prefinished":false,"sync":false,"writecb":null,"writelen":0,"writing":false},"allowHalfOpen":false,"alpnProtocol":false,"authorizationError":null,"authorized":true,"connecting":false,"encrypted":true,"parser":null,"secureConnecting":false,"servername":"api.gm.com","ssl":null}]},"totalSocketCount":1}}},"path":"/api/v1/account/vehicles/EDITEDOU/requests/cancelStart1349688941703384630752","pathname":"/api/v1/account/vehicles/EDITEDOU/requests/cancelStart1349688941703384630752","port":"","protocol":"https:"},"_redirectCount":0,"_redirects":[],"_requestBodyBuffers":[],"_requestBodyLength":0,"_writableState":{"afterWriteTickInfo":null,"allBuffers":true,"allNoop":true,"autoDestroy":true,"bufferProcessing":false,"buffered":[],"bufferedIndex":0,"closeEmitted":false,"closed":false,"constructed":true,"corked":0,"decodeStrings":true,"defaultEncoding":"utf8","destroyed":false,"emitClose":true,"ended":false,"ending":false,"errorEmitted":false,"errored":null,"finalCalled":false,"finished":false,"highWaterMark":16384,"length":0,"needDrain":false,"objectMode":false,"pendingcb":0,"prefinished":false,"sync":true,"writecb":null,"writelen":0,"writing":false}},"_removedConnection":false,"_removedContLen":false,"_removedTE":false,"_trailer":"","aborted":false,"agent":{"_events":{},"_eventsCount":2,"_sessionCache":{"list":["api.gm.com:443:::::::::::::::::::::"],"map":{"api.gm.com:443:::::::::::::::::::::":{"data":[EDITEDOU],"type":"Buffer"}}},"defaultPort":443,"freeSockets":{},"keepAlive":false,"keepAliveMsecs":1000,"maxCachedSessions":100,"maxFreeSockets":256,"maxSockets":null,"maxTotalSockets":null,"options":{"noDelay":true,"path":null},"protocol":"https:","requests":{},"scheduling":"lifo","sockets":{"api.gm.com:443:::::::::::::::::::::":[{"_SNICallback":null,"_closeAfterHandlingError":false,"_controlReleased":true,"_events":{"close":[null,null,null]},"_eventsCount":8,"_hadError":false,"_host":"api.gm.com","_httpMessage":"[Circular]","_newSessionPending":false,"_parent":null,"_pendingData":null,"_pendingEncoding":"","_readableState":{"awaitDrainWriters":null,"buffer":{"head":null,"length":0,"tail":null},"decoder":null,"defaultEncoding":"utf8","encoding":null,"errored":null,"flowing":true,"highWaterMark":16384,"length":0,"pipes":[],"state":323672},"_rejectUnauthorized":true,"_requestCert":true,"_secureEstablished":true,"_securePending":false,"_server":null,"_sockname":null,"_tlsOptions":{"isServer":false,"pipe":false,"rejectUnauthorized":true,"requestCert":true,"secureContext":{"context":{}},"session":{"data":EDITEDOU],"type":"Buffer"}},"_writableState":{"afterWriteTickInfo":null,"allBuffers":true,"allNoop":true,"autoDestroy":true,"bufferProcessing":false,"buffered":[],"bufferedIndex":0,"closeEmitted":true,"closed":true,"constructed":true,"corked":0,"decodeStrings":false,"defaultEncoding":"utf8","destroyed":true,"emitClose":false,"ended":false,"ending":false,"errorEmitted":false,"errored":null,"finalCalled":false,"finished":false,"highWaterMark":16384,"length":0,"needDrain":false,"objectMode":false,"pendingcb":0,"prefinished":false,"sync":false,"writecb":null,"writelen":0,"writing":false},"allowHalfOpen":false,"alpnProtocol":false,"authorizationError":null,"authorized":true,"connecting":false,"encrypted":true,"parser":null,"secureConnecting":false,"servername":"api.gm.com","ssl":null}]},"totalSocketCount":1},"chunkedEncoding":false,"destroyed":true,"finished":true,"host":"api.gm.com","maxHeadersCount":null,"maxRequestsOnConnectionReached":false,"method":"GET","outputData":[],"outputSize":0,"parser":null,"path":"/api/v1/account/vehicles/EDITEDOU/requests/cancelStart1349688941703384630752","protocol":"https:","res":{"_consuming":false,"_dumped":false,"_events":{"end":[null,null]},"_eventsCount":4,"_readableState":{"awaitDrainWriters":null,"buffer":{"head":null,"length":0,"tail":null},"decoder":null,"defaultEncoding":"utf8","encoding":null,"errored":null,"flowing":true,"highWaterMark":16384,"length":0,"pipes":[],"state":456758},"aborted":false,"client":{"_SNICallback":null,"_closeAfterHandlingError":false,"_controlReleased":true,"_events":{"close":[null,null,null]},"_eventsCount":8,"_hadError":false,"_host":"api.gm.com","_httpMessage":"[Circular]","_newSessionPending":false,"_parent":null,"_pendingData":null,"_pendingEncoding":"","_readableState":{"awaitDrainWriters":null,"buffer":{"head":null,"length":0,"tail":null},"decoder":null,"defaultEncoding":"utf8","encoding":null,"errored":null,"flowing":true,"highWaterMark":16384,"length":0,"pipes":[],"state":323672},"_rejectUnauthorized":true,"_requestCert":true,"_secureEstablished":true,"_securePending":false,"_server":null,"_sockname":null,"_tlsOptions":{"isServer":false,"pipe":false,"rejectUnauthorized":true,"requestCert":true,"secureContext":{"context":{}},"session":{"data":,"type":"Buffer"}},"_writableState":{"afterWriteTickInfo":null,"allBuffers":true,"allNoop":true,"autoDestroy":true,"bufferProcessing":false,"buffered":[],"bufferedIndex":0,"closeEmitted":true,"closed":true,"constructed":true,"corked":0,"decodeStrings":false,"defaultEncoding":"utf8","destroyed":true,"em/app/src/index.js:114 client.publish(commandStatusTopic, JSON.stringify({"Command": err}), {retain: true})}); ^ TypeError: Converting circular structure to JSON --> starting at object with constructor 'ClientRequest' | property 'socket' -> object with constructor 'TLSSocket' --- property '_httpMessage' closes the circle at JSON.stringify (<anonymous>) at /app/src/index.js:114:53 at process.processTicksAndRejections (node:internal/process/task_queues:95:5)``

Spoke too soon. Ended up using NodeRed to create MQTT IN node that is subscripted to the specified topic.

@BennyDaBee, please also see here: https://github.com/BigThunderSR/onstar2mqtt/blob/main/HA-MQTT.md#mqtt-polling-status-success-monitor

I will be running it for a bit, but when testing the topics, got this error.

`error: Command error {"command":"cancelStartVehicle","err":{"request":{"authRequired":true,"body":"{}","checkRequestStatus":true,"contentType":"application/json; charset=UTF-8","headers":{},"method":0,"upgradeRequired":false,"url":"https://api.gm.com:443/api/v1/account/vehicles/EDITEDOU/requests/cancelStart1349688941703384630752"},"response":{"config":{"adapter":["xhr","http"],"env":{},"headers":{"Accept":"application/json","Accept-Encoding":"br, gzip, deflate","Accept-Language":"en-US","Authorization":"Bearer EDITED OUT","Connection":"keep-alive","Content-Type":"application/json; charset=UTF-8","Host":"api.gm.com","User-Agent":"myChevrolet/118 .........``

@BennyDaBee, this is not an error but is the output of the actual error response message from OnStar in JSON format to the command you submitted.

I will be running it for a bit, but when testing the topics, got this error.
`error: Command error {"command":"cancelStartVehicle","err":{"request":{"authRequired":true,"body":"{}","checkRequestStatus":true,"contentType":"application/json; charset=UTF-8","headers":{},"method":0,"upgradeRequired":false,"url":"https://api.gm.com:443/api/v1/account/vehicles/EDITEDOU/requests/cancelStart1349688941703384630752"},"response":{"config":{"adapter":["xhr","http"],"env":{},"headers":{"Accept":"application/json","Accept-Encoding":"br, gzip, deflate","Accept-Language":"en-US","Authorization":"Bearer EDITED OUT","Connection":"keep-alive","Content-Type":"application/json; charset=UTF-8","Host":"api.gm.com","User-Agent":"myChevrolet/118 .........``

@BennyDaBee, this is not an error but is the output of the actual error response message from OnStar in JSON format to the command you submitted wrapped with a root "error" tag since the OK status has a root "ok" tag.

@BigThunderSR Is it intended to not publish a failure to the MQTT? As it did not for this. As well, the error caused the container to crash and reboot. The end of it has an actual error.

^ TypeError: Converting circular structure to JSON --> starting at object with constructor 'ClientRequest' | property 'socket' -> object with constructor 'TLSSocket' --- property '_httpMessage' closes the circle at JSON.stringify (<anonymous>) at /app/src/index.js:114:53 at process.processTicksAndRejections

@BigThunderSR Is it intended to not publish a failure to the MQTT? As it did not for this. As well, the error caused the container to crash and reboot. The end of it has an actual error.

^ TypeError: Converting circular structure to JSON --> starting at object with constructor 'ClientRequest' | property 'socket' -> object with constructor 'TLSSocket' --- property '_httpMessage' closes the circle at JSON.stringify (<anonymous>) at /app/src/index.js:114:53 at process.processTicksAndRejections

@BennyDaBee, the code is just sending the error response from OnStar (same error you see in the docker logs of onstar2mqtt for the command response error) back to the MQTT topic. It's not doing any kind of changes to the message and is verbatim what OnStar is sending back. You can parse the JSON in Home Assistant to do all kinds of things which provides much more flexibility than just sending back success/fail messages.

I see what you mean about the container crashing and need to look into that. Thanks for catching that.

@BennyDaBee, I put a fix into the build with the "latest" tag. Please try it out and LMK. Thanks.

Closing as related to API performance.