samrum/OnStarJS

Getting RequestError: Command Timeout when requesting diagnostics

Closed this issue · 12 comments

Getting RequestError: Command Timeout when requesting diagnostics. Im not sure whats causing the issue as the login credentials are working for app.

dev]# node vehicle.js
RequestError: Command Timeout
at RequestService. (/root/dev/node_modules/onstarjs/dist/index.js:552:35)
at Generator.next ()
at fulfilled (/root/dev/node_modules/onstarjs/dist/index.js:32:58)
at processTicksAndRejections (internal/process/task_queues.js:95:5) {
response: {
status: 200,
statusText: 'OK',
headers: {
server: 'Apache-Coyote/1.1',
'gccx-transactionid': '000001799a4c25fa-39753d',
'cache-control': 'public, max-age=5',
'content-type': 'application/json;charset=UTF-8',
'content-length': '183',
date: 'Tue, 25 May 2021 19:41:01 GMT'
},

vehicle.js is simple script based on example. Passing sensitive info at top, but have following as main part of script:

const onStar = OnStar.create(config);

onStar
.diagnostics({
diagnosticItem: ["ODOMETER", "TIRE PRESSURE"],
})
.catch(e => console.log(e));

Ah, there's a default timeout of 60 seconds for requests that would trigger that error.

I can make that configurable/overridable and you could try bumping that up to something longer.

Does it often take longer than 30 seconds to get info? Would it matter that its for a Silverado? Could it be trying to grab some type of electric vehicle object and just bottom out?

Takes ~25s for me with a Volt. I'd guess that vehicle and cellular connectivity speed would affect it. But it just seems like a slow system overall.
The way the OnStar API (and apps) work is that the initial request response returns a url that you have to poll until the request is complete. OnStarJS polls that url every 6s until the response says it's complete or it times out after 60s.

I do see that the response does include a url, so maybe it is a time out/connect from the gas vehicles. I do use your home bridge add on w/ home assistant so I can lock the truck, and that works fine every night but sometimes there is a very long delay (2-3 minutes for truck to lock/unlock after action was sent)

What would the level of effort to be to adjust timeout? Is there something I can try before you implement change to try and do the same thing to extend the timeout?

Oh, cool. Yeah, homebridge-onstar uses OnStarJS's checkRequestStatus option set to false. If the initial response doesn't error it assumes the request was successful and doesn't do that url polling I mentioned before. So for requests triggered from there, it's not really tied to the library and more to do with OnStar/the vehicle being slow for whatever reason.

As for as I know, there's nothing at the API level that would be different between gas/ev/phev.

I can make that change to support a different timeout in OnStarJS pretty easily and it makes sense to have it as an actual supported option for everyone.

I published 2.2.0 with support for two new config options: requestPollingIntervalSeconds and requestPollingTimeoutSeconds. Updated the README with a sample, too.

requestPollingTimeoutSeconds would be the one you would want to bump

Just got a chance to try this out, and I'm now getting a RequestError: Command Failure error using the same script as before but with the added config options

dev]# node vehicle.js
RequestError: Command Failure
at RequestService. (/root/dev/node_modules/onstarjs/dist/index.js:558:35)
at Generator.next ()
at fulfilled (/root/dev/node_modules/onstarjs/dist/index.js:32:58)
at processTicksAndRejections (internal/process/task_queues.js:95:5) {
response: {
status: 200,
statusText: 'OK',
headers: {
server: 'Apache-Coyote/1.1',
'gccx-transactionid': '00000179a4f44345-d18375',
'cache-control': 'public, max-age=5',
'content-type': 'application/json;charset=UTF-8',
'content-length': '258',
date: 'Tue, 01 Jun 2021 15:14:55 GMT'

Ok, you should be able to log the server response using e.getResponse() when that happens and it might have more information why it failed.

So your catch would be something like:

.catch(e => {
  console.log(e);

  if (e.getResponse) {
    console.log(JSON.stringify(e.getResponse()));
  }
})

Have you also tried running the diagnostics command with the default values? Just diagnostics()?

Yes, just ran my current test using just the default diagnostics(), but still getting Command Failure and here is out put with what you suggested:

file:///root/dev/vehicle.js:29
      console.log(JSON.stringify(e.getResponse()));
                       ^

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 file:///root/dev/vehicle.js:29:24
    at processTicksAndRejections (internal/process/task_queues.js:95:5)

Removed the JSON.stringify and just had it print response and this is what I got (omitted the sensitive stuff):

{
  status: 200,
  statusText: 'OK',
  headers: {
    server: 'Apache-Coyote/1.1',
    'gccx-transactionid': '00000179c7d6f148-d15dd',
    'cache-control': 'public, max-age=5',
    'content-type': 'application/json;charset=UTF-8',
    'content-length': '263',
    date: 'Wed, 02 Jun 2021 14:00:50 GMT'
  },
  config: {
    url: 'https://api.gm.com/api/v1/account/vehicles/OMITTED/requests/28589351791',
    method: 'get',
    headers: {
      Accept: 'application/json',
      'Accept-Language': 'en-US',
      'Content-Type': 'application/json; charset=UTF-8',
      Host: 'api.gm.com',
      Connection: 'keep-alive',
      'Accept-Encoding': 'br, gzip, deflate',
      'User-Agent': 'Mozilla/5.0 (Linux; U; Android 9; en-US; Google Pixel 2 Build/PI)',
      Authorization: 'Bearer OMITTED'
    },
    transformRequest: [ [Function: transformRequest] ],
    transformResponse: [ [Function: transformResponse] ],
    timeout: 0,
    adapter: [Function: httpAdapter],
    xsrfCookieName: 'XSRF-TOKEN',
    xsrfHeaderName: 'X-XSRF-TOKEN',
    maxContentLength: -1,
    maxBodyLength: -1,
    validateStatus: [Function: validateStatus],
    data: undefined
  },
  request: <ref *1> ClientRequest {
    _events: [Object: null prototype] {
      abort: [Function (anonymous)],
      aborted: [Function (anonymous)],
      connect: [Function (anonymous)],
      error: [Function (anonymous)],
      socket: [Function (anonymous)],
      timeout: [Function (anonymous)],
      prefinish: [Function: requestOnPrefinish]
    },
    _eventsCount: 7,
    _maxListeners: undefined,
    outputData: [],
    outputSize: 0,
    writable: true,
    destroyed: true,
    _last: true,
    chunkedEncoding: false,
    shouldKeepAlive: true,
    _defaultKeepAlive: true,
    useChunkedEncodingByDefault: false,
    sendDate: false,
    _removedConnection: false,
    _removedContLen: false,
    _removedTE: false,
    _contentLength: 0,
    _hasBody: true,
    _trailer: '',
    finished: true,
    _headerSent: true,
    socket: TLSSocket {
      _tlsOptions: [Object],
      _secureEstablished: true,
      _securePending: false,
      _newSessionPending: false,
      _controlReleased: true,
      secureConnecting: false,
      _SNICallback: null,
      servername: 'api.gm.com',
      alpnProtocol: false,
      authorized: true,
      authorizationError: null,
      encrypted: true,
      _events: [Object: null prototype],
      _eventsCount: 8,
      connecting: false,
      _hadError: false,
      _parent: null,
      _host: 'api.gm.com',
      _readableState: [ReadableState],
      _maxListeners: undefined,
      _writableState: [WritableState],
      allowHalfOpen: false,
      _sockname: null,
      _pendingData: null,
      _pendingEncoding: '',
      server: undefined,
      _server: null,
      ssl: null,
      _requestCert: true,
      _rejectUnauthorized: true,
      parser: null,
      _httpMessage: [Circular *1],
      [Symbol(res)]: null,
      [Symbol(verified)]: true,
      [Symbol(pendingSession)]: null,
      [Symbol(async_id_symbol)]: 588,
      [Symbol(kHandle)]: null,
      [Symbol(kSetNoDelay)]: false,
      [Symbol(lastWriteQueueSize)]: 0,
      [Symbol(timeout)]: null,
      [Symbol(kBuffer)]: null,
      [Symbol(kBufferCb)]: null,
      [Symbol(kBufferGen)]: null,
      [Symbol(kCapture)]: false,
      [Symbol(kBytesRead)]: 515,
      [Symbol(kBytesWritten)]: 394,
      [Symbol(connect-options)]: [Object],
      [Symbol(RequestTimeout)]: undefined
    },
    _header: 'GET /api/v1/account/vehicles/OMITTED/requests/28589351791 HTTP/1.1\r\n' +
      'Accept: application/json\r\n' +
      'Accept-Language: en-US\r\n' +
      'Content-Type: application/json; charset=UTF-8\r\n' +
      'Host: api.gm.com\r\n' +
      'Connection: keep-alive\r\n' +
      'Accept-Encoding: br, gzip, deflate\r\n' +
      'User-Agent: Mozilla/5.0 (Linux; U; Android 9; en-US; Google Pixel 2 Build/PI)\r\n' +
      'Authorization: Bearer OMITTED\r\n' +
      '\r\n',
    _keepAliveTimeout: 0,
    _onPendingData: [Function: noopPendingOutput],
    agent: Agent {
      _events: [Object: null prototype],
      _eventsCount: 2,
      _maxListeners: undefined,
      defaultPort: 443,
      protocol: 'https:',
      options: [Object],
      requests: {},
      sockets: {},
      freeSockets: {},
      keepAliveMsecs: 1000,
      keepAlive: false,
      maxSockets: Infinity,
      maxFreeSockets: 256,
      scheduling: 'lifo',
      maxTotalSockets: Infinity,
      totalSocketCount: 0,
      maxCachedSessions: 100,
      _sessionCache: [Object],
      [Symbol(kCapture)]: false
    },
    socketPath: undefined,
    method: 'GET',
    maxHeaderSize: undefined,
    insecureHTTPParser: undefined,
    path: '/api/v1/account/vehicles/OMITTED/requests/28589351791',
    _ended: true,
    res: IncomingMessage {
      _readableState: [ReadableState],
      _events: [Object: null prototype],
      _eventsCount: 1,
      _maxListeners: undefined,
      socket: null,
      httpVersionMajor: 1,
      httpVersionMinor: 1,
      httpVersion: '1.1',
      complete: true,
      headers: [Object],
      rawHeaders: [Array],
      trailers: {},
      rawTrailers: [],
      aborted: false,
      upgrade: false,
      url: '',
      method: null,
      statusCode: 200,
      statusMessage: 'OK',
      client: [TLSSocket],
      _consuming: false,
      _dumped: false,
      req: [Circular *1],
      responseUrl: 'https://api.gm.com/api/v1/account/vehicles/OMITTED/requests/28589351791',
      redirects: [],
      [Symbol(kCapture)]: false,
      [Symbol(RequestTimeout)]: undefined
    },
    aborted: false,
    timeoutCb: null,
    upgradeOrConnect: false,
    parser: null,
    maxHeadersCount: null,
    reusedSocket: false,
    host: 'api.gm.com',
    protocol: 'https:',
    _redirectable: Writable {
      _writableState: [WritableState],
      _events: [Object: null prototype],
      _eventsCount: 2,
      _maxListeners: undefined,
      _options: [Object],
      _ended: true,
      _ending: true,
      _redirectCount: 0,
      _redirects: [],
      _requestBodyLength: 0,
      _requestBodyBuffers: [],
      _onNativeResponse: [Function (anonymous)],
      _currentRequest: [Circular *1],
      _currentUrl: 'https://api.gm.com/api/v1/account/vehicles/OMITTED/requests/28589351791',
      [Symbol(kCapture)]: false
    },
    [Symbol(kCapture)]: false,
    [Symbol(kNeedDrain)]: false,
    [Symbol(corked)]: 0,
    [Symbol(kOutHeaders)]: [Object: null prototype] {
      accept: [Array],
      'accept-language': [Array],
      'content-type': [Array],
      host: [Array],
      connection: [Array],
      'accept-encoding': [Array],
      'user-agent': [Array],
      authorization: [Array]
    }
  },
  data: {
    commandResponse: {
      requestTime: '2021-06-02T13:58:46.051Z',
      completionTime: '2021-06-02T14:00:45.194Z',
      url: 'https://api.gm.com/api/v1/account/vehicles/OMITTED/requests/28589351791',
      status: 'failure',
      type: 'diagnostics',
      body: [Object]
    }
  }
}

This was with the default diagnostics(didnt include sensitive top info):

 onStar
   .diagnostics()

  .catch(e => {
    console.log(e);

    if (e.getResponse) {
      console.log(e.getResponse());
    }
  })

Seems like an odd one, not sure where to go from here

Issue can be closed, it was something "odd" about my onstar account itself. Called their number when I noticed my Smart Driver feature no longer working. They stated something wasn't "registered" right with their side, but could see a lot of command failures and cleared those.

I see. With that fixed do you still need to change the timeout value in order for it to work?

Also, for future reference, my original logging suggestion for the failure should have been:

.catch(e => {
  console.log(e);

  if (e.getResponse) {
    console.log(JSON.stringify(e.getResponse().data));
  }
})

Forgot that the actual response body is within that data property. In your comment, the potentially interesting part would have been in the body: [Object] bit within that property.