Author Topic: HTTP/1.0 400 Bad Request in get_access_token  (Read 141 times)

Offline KovVlad

  • Newbie
  • *
  • Posts: 4
  • Karma: +0/-0
HTTP/1.0 400 Bad Request in get_access_token
« on: January 17, 2019, 05:13:28 am »
Hi
I installed and prepared Gcal3 exactly as in your documentation. But now then I'm moving device in Armed state, error 400 appears
Exact text:
token error code: HTTP/1.0 400 Bad Request
Fatal Calendar Error

Found this text in GCal3.lua and added some debug info. So there is log output:
50   01/16/19 20:10:35.775   luup_log:83: GCal3 device: 8383 - Checking for access-token <0x7624f520>
50   01/16/19 20:10:35.775   luup_log:83: GCal3 device: 8383 - local function: get_access_token <0x7624f520>
50   01/16/19 20:10:35.776   luup_log:83: GCal3 device: 8383 - Getting a new token <0x7624f520>
50   01/16/19 20:10:35.776   luup_log:83: GCal3 device: 8383 - local function: os_command <0x7624f520>
50   01/16/19 20:10:35.777   luup_log:83: GCal3 device: 8383 - Command was: echo -n '{"iss":"gcal3-for-friday@gcal3-228616.iam.gserviceaccount.com","scope":"https://www.googleapis.com/auth/calendar","aud":"https://accounts.google.com/o/oauth2/token","exp":1547662235, "iat":1547658635}' | openssl base64 -e <0x7624f520>
50   01/16/19 20:10:35.799   luup_log:83: GCal3 device: 8383 - local function: os_command <0x7624f520>
50   01/16/19 20:10:35.800   luup_log:83: GCal3 device: 8383 - Command was: echo -n **hidden** | openssl dgst -sha256 -sign /etc/cmh-ludl/GCal3/GCal3cred.pem | openssl base64 -e <0x7624f520>
50   01/16/19 20:10:35.830   luup_log:83: GCal3 device: 8383 - post request for token: grant_type=urn%3Aietf%3Aparams%3Aoauth%3Agrant-type%3Ajwt-bearer&assertion=**hidden** <0x7624f520> <-- log added by me
50   01/16/19 20:10:35.999   luup_log:83: GCal3 device: 8383 - https token code: 400 <0x7624f520>
50   01/16/19 20:10:36.000   luup_log:83: GCal3 device: 8383 - https token status: HTTP/1.0 400 Bad Request <0x7624f520>
50   01/16/19 20:10:36.000   luup_log:83: GCal3 device: 8383 - token error code: HTTP/1.0 400 Bad Request <0x7624f520>
06   01/16/19 20:10:36.001   Device_Variable::m_szValue_set device: 83 service: urn:srs-com:serviceId:GCalIII variable: gc_NextEvent was: CalendarID is set now: token error code: HTTP/1.0 400 Bad Request #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:0 <0x7624f520>
06   01/16/19 20:10:36.003   Device_Variable::m_szValue_set device: 83 service: urn:srs-com:serviceId:GCalIII variable: gc_NextEventTime was: Credentials File Set now:  #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:0 <0x7624f520>
50   01/16/19 20:10:36.004   luup_log:83: GCal3 device: 8383 - GC.access_token is: false <0x7624f520>
50   01/16/19 20:10:36.005   luup_log:83: GCal3 device: 8383 - GCV.CredentialCheck is false <0x7624f520>

May be also helpful:
When I execute same request in Postman I get

Code: [Select]
{
    "error": "unsupported_grant_type",
    "error_description": "Invalid grant_type: "
}

What I'm doing wrong??

Offline Stuart

  • Moderator
  • Hero Member
  • *****
  • Posts: 728
  • Karma: +71/-2
Re: HTTP/1.0 400 Bad Request in get_access_token
« Reply #1 on: January 17, 2019, 11:24:27 pm »
Codes in the 400 group generally mean that there is something like a calendar ID /credentials mismatch (i.e. right calendar wrong credentials file or vice-versa) or your settings in the calendar permissions are incorrect.

This code is very stable - so absent a network / connectivity issue with google, you should recheck your settings and the accuracy with which you created the credential file.

First, just in case something crazy is happening,  use the test calendar ID and test credentials to eliminate all else.

Offline KovVlad

  • Newbie
  • *
  • Posts: 4
  • Karma: +0/-0
Re: HTTP/1.0 400 Bad Request in get_access_token
« Reply #2 on: January 18, 2019, 03:24:25 am »
Hi
Thank you for your answer

Quote
use the test calendar ID and test credentials to eliminate all else.

Result is the same: error 400

50   01/18/19 11:18:33.156   luup_log:83: GCal3 device: 838383 -  ************** ARMED STATUS : 1 ***************** <0x75731520>
50   01/18/19 11:18:33.157   luup_log:83: GCal3 device: 838383 - local function: checkGCal <0x75731520>
50   01/18/19 11:18:33.157   luup_log:83: GCal3 device: 838383 - local function: getStartMinMax <0x75731520>
50   01/18/19 11:18:33.160   luup_log:83: GCal3 device: 838383 - StartMin is 2019-01-17T20:55:00Z StartMax is 2019-01-19T00:00:00Z <0x75731520>
50   01/18/19 11:18:33.161   luup_log:83: GCal3 device: 838383 - End of day is 2019-01-19T00:00:00 <0x75731520>
50   01/18/19 11:18:33.161   luup_log:83: GCal3 device: 838383 - local function: requestCalendar <0x75731520>
50   01/18/19 11:18:33.162   luup_log:83: GCal3 device: 838383 - local function: get_access_token <0x75731520>
50   01/18/19 11:18:33.162   luup_log:83: GCal3 device: 838383 - Getting a new token <0x75731520>
50   01/18/19 11:18:33.163   luup_log:83: GCal3 device: 838383 - local function: os_command <0x75731520>
50   01/18/19 11:18:33.164   luup_log:83: GCal3 device: 838383 - Command was: echo -n '{"iss":"gcaltest@gcal-test-1203.iam.gserviceaccount.com","scope":"https://www.googleapis.com/auth/calendar","aud":"https://accounts.google.com/o/oauth2/token","exp":1547803113, "iat":1547799513}' | openssl base64 -e <0x75731520>
50   01/18/19 11:18:33.185   luup_log:83: GCal3 device: 838383 - local function: os_command <0x75731520>
50   01/18/19 11:18:33.186   luup_log:83: GCal3 device: 838383 - Command was: echo -n **hidden**. | openssl dgst -sha256 -sign /etc/cmh-ludl/GCal3/GCal3Test.pem | openssl base64 -e <0x75731520>                                                                                                                                         
50   01/18/19 11:18:33.216   luup_log:83: GCal3 device: 838383 - post request for token: grant_type=urn%3Aietf%3Aparams%3Aoauth%3Agrant-type%3Ajwt-bearer&assertion=**hidden** <0x75731520>
50   01/18/19 11:18:33.389   luup_log:83: GCal3 device: 838383 - https token code: 400 <0x75731520>
50   01/18/19 11:18:33.390   luup_log:83: GCal3 device: 838383 - https token status: HTTP/1.0 400 Bad Request <0x75731520>
50   01/18/19 11:18:33.390   luup_log:83: GCal3 device: 838383 - token error code: HTTP/1.0 400 Bad Request <0x75731520>

I also noticed that jwt is the same either with your credential oor mine

Offline KovVlad

  • Newbie
  • *
  • Posts: 4
  • Karma: +0/-0
Re: HTTP/1.0 400 Bad Request in get_access_token
« Reply #3 on: January 18, 2019, 05:14:15 am »
Quote
I also noticed that jwt is the same either with your credential oor mine
... and almost the same as jwt1 in your code ))

Code: [Select]
  -- jwt1 is base 64 encoded form of {"alg":"RS256","typ":"JWT"}
  local jwt1 = 'eyJhbGciOiJSUzI1NiIsInR5cCI6IkpXVCJ9'

Call of openssl only adds point at the end of string.
So the problem is with openssl?



Offline Stuart

  • Moderator
  • Hero Member
  • *****
  • Posts: 728
  • Karma: +71/-2
Re: HTTP/1.0 400 Bad Request in get_access_token
« Reply #4 on: January 18, 2019, 02:50:32 pm »
Quote
I also noticed that jwt is the same either with your credential oor mine
... and almost the same as jwt1 in your code ))

Code: [Select]
  -- jwt1 is base 64 encoded form of {"alg":"RS256","typ":"JWT"}
  local jwt1 = 'eyJhbGciOiJSUzI1NiIsInR5cCI6IkpXVCJ9'

Call of openssl only adds point at the end of string.
So the problem is with openssl?

What version of vera are you using and what version of openssl.

I've never seen this problem before - so something has changed / is different than expected  :-(


Offline KovVlad

  • Newbie
  • *
  • Posts: 4
  • Karma: +0/-0
Re: HTTP/1.0 400 Bad Request in get_access_token
« Reply #5 on: January 18, 2019, 05:18:20 pm »
Solved by openssl's re-install

First it isn't working
Code: [Select]
root@MiOS_45003051:~# openssl version
Segmentation fault

After remove and install plugin works fine.
Thanks a lot