post GCal3 0.9 -> 1.2 upgrade auth problem

Vera3, UI5.

I decided to update GCal3 from 0.9 to 1.2 today.

Bad idea, as it turns out!

After using the usual “http://[Vera_IP]:3480/data_request?id=update_plugin&Plugin=7016” method to update and reloading, I was met with access errors.

Upon checking the logs the errors were referring to auth tokens. I went to the Google Developer center and made a new Client ID, authorized the user in my Calendar settings, and uploaded the new GCal3.json file.

Still got access errors ???

I tried removing and reinstalling the plugin, and restarting Vera (vs reloading Lua). No change in results.

A little further searching of the forums led me to look for /usr/lib/lua/googlejwt.sh … I don’t have that file on my system, which might explain why the Gcal3.token file doesn’t match my GCal3.json file ::slight_smile:

With gc_debug=3, my logfile looks like this:

50 04/28/15 20:39:30.115 luup_log:78: GCal3 V 1.2:Checking semaphore <0x2ead3680> 50 04/28/15 20:39:30.139 luup_log:78: GCal3 V 1.2:Command ls /etc/cmh-ludl/GCal3/GCal3.sem returned 0 <0x2ead3680> 50 04/28/15 20:39:30.139 luup_log:78: GCal3 V 1.2:Semaphore file returned 0 <0x2ead3680> 50 04/28/15 20:39:30.140 luup_log:78: GCal3 V 1.2:Device 78 requested semaphore <0x2ead3680> 50 04/28/15 20:39:30.165 luup_log:78: GCal3 V 1.2:Command ls /etc/cmh-ludl/GCal3/GCal3.sem returned 0 <0x2ead3680> 50 04/28/15 20:39:30.166 luup_log:78: GCal3 V 1.2:Device 78 claimed semaphore <0x2ead3680> 50 04/28/15 20:39:30.168 luup_log:78: GCal3 V 1.2:StartMin is 2015-04-28T04:00:00Z StartMax is 2015-04-30T00:39:00Z <0x2ead3680> 50 04/28/15 20:39:30.169 luup_log:78: GCal3 V 1.2:End of day is 2015-04-28T23:59:59 <0x2ead3680> 50 04/28/15 20:39:30.169 luup_log:78: GCal3 V 1.2:Function: requestCalendar <0x2ead3680> 50 04/28/15 20:39:30.169 luup_log:78: GCal3 V 1.2:Function: get_access_token <0x2ead3680> 50 04/28/15 20:39:30.348 luup_log:78: GCal3 V 1.2:Token Info request status: HTTP/1.1 400 Bad Request <0x2ead3680> 50 04/28/15 20:39:30.348 luup_log:78: GCal3 V 1.2:Getting a new token <0x2ead3680> 50 04/28/15 20:39:30.752 luup_log:78: GCal3 V 1.2:The token request did not provide an access token <0x2ead3680> 50 04/28/15 20:39:30.754 luup_log:78: GCal3 V 1.2:Fatal error trying to get access token <0x2ead3680> 50 04/28/15 20:39:30.765 luup_log:78: GCal3 V 1.2:Device 78 released the semaphore - reason: calendar check complete <0x2ead3680> 50 04/28/15 20:39:30.841 luup_log:78: GCal3 V 1.2:Next check will be in 60 sec on 2015-04-28 at 20:40:30 <0x2ead3680>

I do see my calendar on the device Calendar tab, however ::slight_smile:

Any suggestions on how to go about fixing this?

Thanks in advance…

/usr/lib/lua/googlejwt.sh is no longer used so it’s good that you cannot find it - the plugin will remove it if it’s there ;D

Take a look at your calendar sharing settings: They need to be either “See all event details” or “Make Changes to Events” - if you intend to use the add event to calendar feature then it needs to be set to “Make Changes to Events”.

Try that and let me know.

“Make Changes to Events”

Is GCal3.token still used? Mine has a Calendar ID in it that doesn’t match the one I am using…

[quote=“kapstaad, post:3, topic:187111”]“Make Changes to Events”

Is GCal3.token still used? Mine has a Calendar ID in it that doesn’t match the one I am using…[/quote]

GCal3.token is no longer used and can be disregarded.

Is it working ?

Nope :cry:

The request for the token is providing a response but it is not finding a token in the response.

Try this - I added an additional debug line to print out what is actually being returned. I’m not sure this will help but lets try.

No-one has had problems with this for a long time - so I suspect that their is a mismatch between the authorization set in your calendar and the credentials. If this additional debug does not reveal the problem - then we will likely need to IM and look specifically at what is set where …

Thanks for your continued help and support, Stuart :slight_smile:

I mv’d /etc/cmh-ludl/GCal3.lua.lzo to a backup dir, then uploaded your customized GCal3.lua to /etc/cmh-ludl and reloaded. The result is as follows:

50 04/29/15 22:22:10.113 luup_log:133: GCal3 V 1.2:Checking semaphore <0x30abf680> 50 04/29/15 22:22:10.137 luup_log:133: GCal3 V 1.2:Command ls /etc/cmh-ludl/GCal3/GCal3.sem returned 0 <0x30abf680> 50 04/29/15 22:22:10.138 luup_log:133: GCal3 V 1.2:Semaphore file returned 0 <0x30abf680> 50 04/29/15 22:22:10.139 luup_log:133: GCal3 V 1.2:Device 133 requested semaphore <0x30abf680> 50 04/29/15 22:22:10.163 luup_log:133: GCal3 V 1.2:Command ls /etc/cmh-ludl/GCal3/GCal3.sem returned 0 <0x30abf680> 50 04/29/15 22:22:10.163 luup_log:133: GCal3 V 1.2:Device 133 claimed semaphore <0x30abf680> 50 04/29/15 22:22:10.166 luup_log:133: GCal3 V 1.2:StartMin is 2015-04-29T04:00:00Z StartMax is 2015-05-01T02:22:00Z <0x30abf680> 50 04/29/15 22:22:10.167 luup_log:133: GCal3 V 1.2:End of day is 2015-04-29T23:59:59 <0x30abf680> 50 04/29/15 22:22:10.167 luup_log:133: GCal3 V 1.2:Function: requestCalendar <0x30abf680> 50 04/29/15 22:22:10.167 luup_log:133: GCal3 V 1.2:Function: get_access_token <0x30abf680> 50 04/29/15 22:22:10.359 luup_log:133: GCal3 V 1.2:Token Info request status: HTTP/1.1 400 Bad Request <0x30abf680> 50 04/29/15 22:22:10.360 luup_log:133: GCal3 V 1.2:Getting a new token <0x30abf680> 50 04/29/15 22:22:10.676 luup_log:133: GCal3 V 1.2:The token request did not provide an access token <0x30abf680> 50 04/29/15 22:22:10.677 luup_log:133: GCal3 V 1.2:{ 06 04/29/15 22:22:10.677 Device_Variable::m_szValue_set device: 133 service: urn:srs-com:serviceId:GCalIII variable: gc_NextEvent was: Access or Calendar Error now: Fatal error - access token #hooks: 0 upnp: 0 v:(nil)/NONE duplicate:0 <0x30abf680> 06 04/29/15 22:22:10.678 Device_Variable::m_szValue_set device: 133 service: urn:srs-com:serviceId:GCalIII variable: gc_NextEventTime was: 71 now: . #hooks: 0 upnp: 0 v:(nil)/NONE duplicate:0 <0x30abf680> 50 04/29/15 22:22:10.678 luup_log:133: GCal3 V 1.2:Fatal error trying to get access token <0x30abf680> 50 04/29/15 22:22:10.679 luup_log:133: GCal3 V 1.2:Device 133 released the semaphore - reason: calendar check complete <0x30abf680> 06 04/29/15 22:22:10.679 Device_Variable::m_szValue_set device: 133 service: urn:srs-com:serviceId:GCalIII variable: gc_NextEvent was: Fatal error - access token now: Access or Calendar Error #hooks: 0 upnp: 0 v:(nil)/NONE duplicate:0 <0x30abf680> 06 04/29/15 22:22:10.680 Device_Variable::m_szValue_set device: 133 service: urn:srs-com:serviceId:GCalIII variable: gc_NextEventTime was: . now: 72 #hooks: 0 upnp: 0 v:(nil)/NONE duplicate:0 <0x30abf680> 06 04/29/15 22:22:10.681 Device_Variable::m_szValue_set device: 133 service: urn:srs-com:serviceId:GCalIII variable: gc_lastCheck was: 2015-04-29 at 22:22:08 now: 2015-04-29 at 22:22:10 #hooks: 0 upnp: 0 v:(nil)/NONE duplicate:0 <0x30abf680> 06 04/29/15 22:22:10.684 Device_Variable::m_szValue_set device: 133 service: urn:srs-com:serviceId:GCalIII variable: gc_nextCheck was: 2015-04-29 at 22:23:08 now: 2015-04-29 at 22:23:10 #hooks: 0 upnp: 0 v:(nil)/NONE duplicate:0 <0x30abf680> 50 04/29/15 22:22:10.684 luup_log:133: GCal3 V 1.2:Next check will be in 60 sec on 2015-04-29 at 22:23:10 <0x30abf680>

The problem is clearly associated with the token but I don’t know what’s going wrong ???

Yes - you are right. As I thought about it - it’s not yet trying to access the calendar. I’m near 100% sure that the problem lies in the GCal3.json file. This code has been very robust and it is getting a return from the token request, just not what we expect.

Can you do two things via IM
(1) Send me a copy of the GCal3.json file you are currently using
(2) Carefully create a new GCal3.json file following the instructions posted here
http://forum.micasaverde.com/index.php/topic,26692.0.html
and send me a copy of that

I’ll then try to see what’s happening.

And by IM I really meant PM…

Stuart,

Wasn’t able to attach a file to a PM :-. The “Attachments and other options” link, which appears under the composition box for regular forum replies, doesn’t appear for me when I click the PM icon ???

Instead, I cut/pasted my .json files and tagged them as code, which will hopefully work just about as well :wink:

Thanks again for your help!

[quote=“kapstaad, post:10, topic:187111”]Stuart,

Wasn’t able to attach a file to a PM :-. The “Attachments and other options” link, which appears under the composition box for regular forum replies, doesn’t appear for me when I click the PM icon ???

Instead, I cut/pasted my .json files and tagged them as code, which will hopefully work just about as well :wink:

Thanks again for your help![/quote]

I tried the new GCal3.json file you posted against the GCal V1.2 and it worked perfectly. So we know the problem is not with the GCal3.json or (likely) the plugin code.

Try this:

go to /etc/cmh-ludl/GCal3
remove all the files from that directory
upload your new GCal3.json file (using the vera interface - not directly - otherwise it will not work)
reboot the vera

If it still does not work - have a look in /etc/cmh-ludl/GCal3. There should be three files (1) GCal3.json, (2) GCal3.pem and (3) GCal3.sem.

The GCal3.json file should be the same as the one you uploaded. The .pem file will just be a subset of the .json file and look like this
-----BEGIN PRIVATE KEY-----
M…

…j
-----END PRIVATE KEY-----

If this still does not work (send me the full log anyway) then I’m suspecting some form of network issue (unlikely but possible).

Also - what vera version are you on ?

—SOLVED—

;D ;D ;D ;D

The .pem file contained the pvt key from the previous .json file. Not sure how, but it looks like they got out of sync. Deleting the /etc/cmh-ludl/GCal3/* followed by an upload of the new .json file and a reboot, then re-configuring the calendar ID in the plug-in did the trick.

Thanks for the assistance!

[quote=“kapstaad, post:12, topic:187111”]—SOLVED—

;D ;D ;D ;D

The .pem file contained the pvt key from the previous .json file. Not sure how, but it looks like they got out of sync. Deleting the /etc/cmh-ludl/GCal3/* followed by an upload of the new .json file and a reboot, then re-configuring the calendar ID in the plug-in did the trick.

Thanks for the assistance![/quote]
The .pem file gets created from the json file and gets updated by the appearance of a json file in /etc/cmh-ludl. Strictly speaking it’s the appearance of a .json.lzo file an that only occurs when it’s uploaded using the vera UI (Vera converts the original) and when the plugin restarts.

So if there was no restart or if the json file was copid directly using some other means - that would account for the behavior.

Anyway - glad it’s now working for you. As an aside - V3 will clean up .token files and json files from the …/GCal3 directory - so all that should be there in the future is the pem file and the sem file