xrs444
November 25, 2015, 4:03am
1
I’m having some problems connecting to the Google Calendar with my Vera Lite, running UI7, firmware 1.7.719.
I have enabled the Calendar API and generated the .json file as an ‘other’ OAuth type, then installed the plugin (1.4 from the Vera Install Apps section, uploaded the file and pasted in the full embedded URL for the calendar. (I’ve also tried with the direct URL, with and without converting the & to %26).
Once this is done, under the control tab it says Variable setup complete.
However with or without a reboot I get a Fatal Error: Credentials when it tries to check the events.
If I SSH into the box, I can see it has created the /etc/cmh-ludl/GCal3 folder which contains D_GCal3.json, GCal3.json and GCal3.sem.
The calendar tab won’t display the calendar due to a DNS error, it’s possibly missing a /?https://calendar.google.com %26showprint%3D0%26showtabs… is the URL it’s trying to use.
The gc_CalendarID is still set to https://calendar.google.com in the variables.
I don’t see anything in the logs that suggest exactly where the issue lies.
I’m betting I’ve missed something fundamental, but I can’t spot what it is! I’ve tried uninstalling and re-installing the plugin, but to no avail.
I can grab you whatever data you need.
Thanks in advance!
Stuart
November 25, 2015, 11:39am
2
I’m traveling and cannot offer direct assistance. My guess is that you have not created the credentials file correctly. As a result some of the files in the …/ GCal3 directory are wrong The credentials file needs to be for a service account. Take a look at the instructions on the first post of the main thread. They are a little dated from a UI perspective but otherwise accurate.
Setting gc_debug to 3 will give maximum debug messages.
xrs444
December 3, 2015, 9:18pm
3
Sorry, I didn’t get a chance to update this sooner.
I recreated the service account again, and it cleared the credentials error, however I’m still not able to view the calendar on the calendar tab, and it’s not picking up the events.
I’ll turn the logging up and dig in, see what’s going on.
Stuart
December 4, 2015, 3:03am
4
No problem. You need to be logged into your google account in the current browser session for the calendar tab to show up. One day I will figure out how to pass the credentials within the calendar tab but until then … ???
xrs444
December 4, 2015, 3:25am
5
Looks like either I’m being an utter muppet, or it’s not happy with my Calendar URL.
I used the iframe URL as suggested, however the logs are showing it gets a 404 error when it tries to connect.
If I extract the URL from the link and paste it into the browser it works fine. The calendar link in vera still shows a DNS error.
Tried under both Firefox and Chrome just in case.
gc_CalendarID is set to https://calendar.google.com when I look.
I’ve tried the iframe link both with the &, and the %26.
In the log, these seem the most relevant entries:
06 12/03/15 20:20:20.133 Device_Variable::m_szValue_set device: 34 service: urn:srs-com:serviceId:GCalIII variable: gc_CalendarID was: now: https://calendar.google.com #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:0 <0x2dce4680>
10 12/03/15 20:20:20.134 UserData::m_iDataVersion_Variables_incr gc_CalendarID user data 196581001 variables 196585201 <0x2dce4680>
06 12/03/15 20:21:20.822 Device_Variable::m_szValue_set device: 34 service: urn:srs-com:serviceId:GCalIII variable: gc_NextEvent was: Accessing Calendar now: Http error code: 404 #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:0 <0x2dce4680>
Thanks for your help so far!
Stuart
December 4, 2015, 6:16pm
6
are you pasting the entire iframe link including the <iframe … e.g.
Note that the link details cannot be input into the gc_CalendarID variable on the advanced tab (some people do this and have similar problems). It must be input using the Control Tab and the “set” button. This is because the plugin parses out the bits that it needs.
The resultant value for gc_CalendarID that you describe is clearly wrong - which suggests that the parser failed. This can be because the wrong format was input, google changed their format and the parser no longer recognizes it or there is a bug in the parser.
If the above does not help - I’ll put some debug messages into the parser routine (have not needed them up till now) and have you retest.
xrs444
December 6, 2015, 3:34pm
7
Yep, both for the main calendar for that account and the calendar I’m trying to use:
<iframe src="https://calendar.google.com/calendar/embed?src={USER}%40gmail.com&ctz=America/Phoenix" style="border: 0" width="800" height="600" frameborder="0" scrolling="no"></iframe>
<iframe src="https://calendar.google.com/calendar/embed?src={GUID}%40group.calendar.google.com&ctz=America/Phoenix" style="border: 0" width="800" height="600" frameborder="0" scrolling="no"></iframe>
<iframe src="https://calendar.google.com/calendar/embed?src={GUID}%40gmail.com&ctz=America/Phoenix" style="border: 0" width="800" height="600" frameborder="0" scrolling="no"></iframe>
Stuart
December 6, 2015, 8:56pm
8
I think I have it fixed - I’d been a little lazy and a little too optimistic about some google calendar format variations …
Try the update file here:
http://forum.micasaverde.com/index.php/topic,26692.msg259438.html#msg259438
Thank you for pointing this out and providing the failing examples - that really helped.
Remember to F5 after using ‘set’ before looking at the result of gc_CalendarID in the advanced tab :-). It’s spooky when things that should have changed do not …
xrs444
December 10, 2015, 4:30am
9
Thank you for taking a look!
As soon as I get a chance I’ll get that update done, it’s currently 1.4 so we’re good there.
I’ll let you know how I get on.
xrs444
December 11, 2015, 4:24am
10
Hello,
I uploaded the GCal3.lua file from the other thread, but the version number still says 1.4, even after a reboot.
I did however change the urn and the calendar url to use www. and the calendar tab now works, although it still gives a Access or Calendar error.
I’ve probably missed something in the upgrade process, but this initial test at least shows it was the DNS name that was affecting it!
I’ll take a closer look at the weekend, I’ve probably just missed a step along the way.
Stuart
December 12, 2015, 3:32pm
11
Did you use the vera UI to upload ? As opposed to something like WINSCP ? The vera upload (from memory) creates a lzo file and that’s what triggers the internal upgrade of the plugin file.
I’d also reboot to be doubly certain (not usually required but …)
I assume you are saying “1.4” because that’s what shows up in the log file (the log file is definitive)? The “My apps” version number will only show the version from your last install / upgrade from the apps store.
xrs444
December 12, 2015, 10:44pm
12
I’ll check the logs tonight, but yes, I took the MyApps number, so it may well have worked.
I did upload it with the Vera GUI so I expect it did upgrade. Is there a way to check the installed version from the command line?
Stuart
December 13, 2015, 4:31am
13
As far as I know the installed version number is set by the vera marketplace. I’m not aware of any way to programmatically set the version number. I use a variable that gets included in log messages - so checking the logs is the only way I can suggest.
xrs444
December 15, 2015, 12:49am
14
Hello,
I’ve had a look through the logs, the Calendar tab works, copying the variable to the browser and running it works, but the log says 404 when it tries to get events. It is running 15b though!
Here’s the last run in the logs. {} changed to protect the innocent!
06 12/14/15 17:41:13.102 Device_Variable::m_szValue_set device: 35 service: urn:srs-com:serviceId:GCalIII variable: gc_NextEvent was: Access or Calendar Error now: Start up ... #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:0 <{DEV_ID}>
06 12/14/15 17:41:13.102 Device_Variable::m_szValue_set device: 35 service: urn:srs-com:serviceId:GCalIII variable: gc_NextEventTime was: 307 now: . #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:0 <{DEV_ID}>
06 12/14/15 17:41:13.103 Device_Variable::m_szValue_set device: 35 service: urn:srs-com:serviceId:GCalIII variable: gc_NextEvent was: Start up ... now: The CalendarID is set #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:0 <{DEV_ID}>
06 12/14/15 17:41:13.104 Device_Variable::m_szValue_set device: 35 service: urn:srs-com:serviceId:GCalIII variable: gc_NextEventTime was: . now: . #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:1 <{DEV_ID}>
06 12/14/15 17:41:13.138 Device_Variable::m_szValue_set device: 35 service: urn:srs-com:serviceId:GCalIII variable: gc_NextEventTime was: . now: Set up variables #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:0 <{DEV_ID}>
06 12/14/15 17:41:13.139 Device_Variable::m_szValue_set device: 35 service: urn:srs-com:serviceId:GCalIII variable: gc_NextEvent was: The CalendarID is set now: #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:0 <{DEV_ID}>
06 12/14/15 17:41:13.140 Device_Variable::m_szValue_set device: 35 service: urn:srs-com:serviceId:GCalIII variable: gc_NextEventTime was: Set up variables now: . #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:0 <{DEV_ID}>
06 12/14/15 17:41:13.141 Device_Variable::m_szValue_set device: 35 service: urn:srs-com:serviceId:GCalIII variable: gc_exactKeyword was: true now: true #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:1 <{DEV_ID}>
06 12/14/15 17:41:13.142 Device_Variable::m_szValue_set device: 35 service: urn:srs-com:serviceId:GCalIII variable: gc_ignoreKeyword was: false now: false #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:1 <{DEV_ID}>
06 12/14/15 17:41:13.142 Device_Variable::m_szValue_set device: 35 service: urn:srs-com:serviceId:GCalIII variable: gc_triggerNoKeyword was: false now: false #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:1 <{DEV_ID}>
06 12/14/15 17:41:13.143 Device_Variable::m_szValue_set device: 35 service: urn:srs-com:serviceId:GCalIII variable: gc_ignoreAllDayEvent was: false now: false #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:1 <{DEV_ID}>
06 12/14/15 17:41:13.144 Device_Variable::m_szValue_set device: 35 service: urn:srs-com:serviceId:GCalIII variable: gc_retrip was: true now: true #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:1 <{DEV_ID}>
06 12/14/15 17:41:13.144 Device_Variable::m_szValue_set device: 35 service: urn:srs-com:serviceId:GCalIII variable: gc_CalendarID was: https://calendar.google.com/calendar/embed?src={GUID}0%40group.calendar.google.com now: #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:0 <{DEV_ID}>
06 12/14/15 17:41:13.154 Device_Variable::m_szValue_set device: 35 service: urn:srs-com:serviceId:GCalIII variable: gc_CalendarID was: now: https://calendar.google.com/calendar/embed?src={GUID}0%40group.calendar.google.com #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:0 <{DEV_ID}>
06 12/14/15 17:41:13.155 Device_Variable::m_szValue_set device: 35 service: urn:srs-com:serviceId:GCalIII variable: gc_jsonEvents was: [] now: [] #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:1 <{DEV_ID}>
06 12/14/15 17:41:13.156 Device_Variable::m_szValue_set device: 35 service: urn:srs-com:serviceId:GCalIII variable: gc_jsonActiveEvents was: [] now: [] #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:1 <{DEV_ID}>
06 12/14/15 17:41:13.156 Device_Variable::m_szValue_set device: 35 service: urn:srs-com:serviceId:GCalIII variable: gc_ActiveEvents was: now: #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:1 <{DEV_ID}>
06 12/14/15 17:41:13.157 Device_Variable::m_szValue_set device: 35 service: urn:srs-com:serviceId:GCalIII variable: gc_NextEventTime was: . now: Variable setup complete #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:0 <{DEV_ID}>
04 12/14/15 17:41:13.249 <0x2b4ec680>
06 12/14/15 17:41:13.250 Device_Variable::m_szValue_set device: 4 service: urn:micasaverde-com:serviceId:ZWaveNetwork1 variable: LastPollSuccess was: 1450139953 now: 1450140073 #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:0 <0x2b4ec680>
06 12/14/15 17:41:13.251 Device_Variable::m_szValue_set device: 4 service: urn:micasaverde-com:serviceId:ZWaveNetwork1 variable: ConsecutivePollFails was: 0 now: 0 #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:1 <0x2b4ec680>
06 12/14/15 17:41:13.537 Device_Variable::m_szValue_set device: 35 service: urn:srs-com:serviceId:GCalIII variable: gc_NextEvent was: now: Accessing Calendar #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:0 <{DEV_ID}>
06 12/14/15 17:41:13.538 Device_Variable::m_szValue_set device: 35 service: urn:srs-com:serviceId:GCalIII variable: gc_NextEventTime was: Variable setup complete now: . #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:0 <{DEV_ID}>
06 12/14/15 17:41:14.001 Device_Variable::m_szValue_set device: 35 service: urn:srs-com:serviceId:GCalIII variable: gc_NextEvent was: Accessing Calendar now: Http error code: 404 #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:0 <{DEV_ID}>
06 12/14/15 17:41:14.001 Device_Variable::m_szValue_set device: 35 service: urn:srs-com:serviceId:GCalIII variable: gc_NextEventTime was: . now: . #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:1 <{DEV_ID}>
06 12/14/15 17:41:14.002 Device_Variable::m_szValue_set device: 35 service: urn:srs-com:serviceId:GCalIII variable: gc_NextEvent was: Http error code: 404 now: Access or Calendar Error #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:0 <{DEV_ID}>
06 12/14/15 17:41:14.003 Device_Variable::m_szValue_set device: 35 service: urn:srs-com:serviceId:GCalIII variable: gc_NextEventTime was: . now: 308 #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:0 <{DEV_ID}>
06 12/14/15 17:41:14.003 Device_Variable::m_szValue_set device: 35 service: urn:srs-com:serviceId:GCalIII variable: gc_jsonEvents was: [] now: [] #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:1 <{DEV_ID}>
06 12/14/15 17:41:14.004 Device_Variable::m_szValue_set device: 35 service: urn:srs-com:serviceId:GCalIII variable: gc_jsonActiveEvents was: [] now: [] #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:1 <{DEV_ID}>
06 12/14/15 17:41:14.004 Device_Variable::m_szValue_set device: 35 service: urn:srs-com:serviceId:GCalIII variable: gc_ActiveEvents was: now: #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:1 <{DEV_ID}>
06 12/14/15 17:41:14.006 Device_Variable::m_szValue_set device: 35 service: urn:srs-com:serviceId:GCalIII variable: gc_lastCheck was: 2015-12-14 at 17:41:04 now: 2015-12-14 at 17:41:13 #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:0 <{DEV_ID}>
06 12/14/15 17:41:14.009 Device_Variable::m_szValue_set device: 35 service: urn:srs-com:serviceId:GCalIII variable: gc_nextCheck was: 2015-12-14 at 17:42:04 now: 2015-12-14 at 17:42:13 #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:0 <{DEV_ID}>
50 12/14/15 17:41:14.009 luup_log:35: GCal3 V 1.5b:Next check will be in 60 sec on 2015-12-14 at 17:42:13 <{DEV_ID}>
Stuart
December 15, 2015, 5:24am
15
Please set gc_debug = 3. That way we will see the debug messages and can begin to make sense of what’s happening.
xrs444
December 16, 2015, 4:59am
16
Duly set, I think this is all of one run:
06 12/15/15 21:43:53.118 Device_Variable::m_szValue_set device: 35 service: urn:srs-com:serviceId:GCalIII variable: gc_NextEvent was: Access or Calendar Error now: GCal3.sem #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:0 <{DEV_ID}>
06 12/15/15 21:43:53.119 Device_Variable::m_szValue_set device: 35 service: urn:srs-com:serviceId:GCalIII variable: gc_NextEventTime was: 544 now: Could not Open #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:0 <{DEV_ID}>
50 12/15/15 21:43:53.139 luup_log:35: GCal3 V 1.5b:Device 35 claimed semaphore <{DEV_ID}>
06 12/15/15 21:43:53.140 Device_Variable::m_szValue_set device: 35 service: urn:srs-com:serviceId:GCalIII variable: gc_NextEvent was: GCal3.sem now: #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:0 <{DEV_ID}>
06 12/15/15 21:43:53.141 Device_Variable::m_szValue_set device: 35 service: urn:srs-com:serviceId:GCalIII variable: gc_NextEventTime was: Could not Open now: . #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:0 <{DEV_ID}>
06 12/15/15 21:43:53.142 Device_Variable::m_szValue_set device: 35 service: urn:srs-com:serviceId:GCalIII variable: gc_exactKeyword was: true now: true #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:1 <{DEV_ID}>
06 12/15/15 21:43:53.142 Device_Variable::m_szValue_set device: 35 service: urn:srs-com:serviceId:GCalIII variable: gc_ignoreKeyword was: false now: false #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:1 <{DEV_ID}>
06 12/15/15 21:43:53.143 Device_Variable::m_szValue_set device: 35 service: urn:srs-com:serviceId:GCalIII variable: gc_triggerNoKeyword was: false now: false #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:1 <{DEV_ID}>
06 12/15/15 21:43:53.144 Device_Variable::m_szValue_set device: 35 service: urn:srs-com:serviceId:GCalIII variable: gc_ignoreAllDayEvent was: false now: false #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:1 <{DEV_ID}>
06 12/15/15 21:43:53.145 Device_Variable::m_szValue_set device: 35 service: urn:srs-com:serviceId:GCalIII variable: gc_retrip was: true now: true #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:1 <{DEV_ID}>
06 12/15/15 21:43:53.146 Device_Variable::m_szValue_set device: 35 service: urn:srs-com:serviceId:GCalIII variable: gc_CalendarID was: https://calendar.google.com/calendar/embed?src={GUID}%40group.calendar.google.com now: #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:0 <{DEV_ID}>
06 12/15/15 21:43:53.152 Device_Variable::m_szValue_set device: 35 service: urn:srs-com:serviceId:GCalIII variable: gc_CalendarID was: now: https://calendar.google.com/calendar/embed?src={GUID}%40group.calendar.google.com #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:0 <{DEV_ID}>
06 12/15/15 21:43:53.153 Device_Variable::m_szValue_set device: 35 service: urn:srs-com:serviceId:GCalIII variable: gc_jsonEvents was: [] now: [] #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:1 <{DEV_ID}>
06 12/15/15 21:43:53.154 Device_Variable::m_szValue_set device: 35 service: urn:srs-com:serviceId:GCalIII variable: gc_jsonActiveEvents was: [] now: [] #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:1 <{DEV_ID}>
06 12/15/15 21:43:53.155 Device_Variable::m_szValue_set device: 35 service: urn:srs-com:serviceId:GCalIII variable: gc_ActiveEvents was: now: #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:1 <{DEV_ID}>
50 12/15/15 21:43:53.156 luup_log:35: GCal3 V 1.5b:GCal3 V 1.5b:Variables initialized ... <{DEV_ID}>
50 12/15/15 21:43:53.174 luup_log:35: GCal3 V 1.5b:Command /bin/ls /usr/lib/lua/json.lua returned 0 <{DEV_ID}>
50 12/15/15 21:43:53.232 luup_log:35: GCal3 V 1.5b:Existing openssl version is: 1.0.0d-1 <{DEV_ID}>
50 12/15/15 21:43:53.246 luup_log:35: GCal3 V 1.5b:local function: checkforcredentials <{DEV_ID}>
50 12/15/15 21:43:53.264 luup_log:35: GCal3 V 1.5b:Command /bin/ls /etc/cmh-ludl/GCal3.json.lzo returned 256 <{DEV_ID}>
50 12/15/15 21:43:53.282 luup_log:35: GCal3 V 1.5b:Command /bin/ls /etc/cmh-ludl/GCal3/GCal3.json returned 0 <{DEV_ID}>
50 12/15/15 21:43:53.283 luup_log:35: GCal3 V 1.5b:local function: readfromFile <{DEV_ID}>
50 12/15/15 21:43:53.300 luup_log:35: GCal3 V 1.5b:Command /bin/ls /etc/cmh-ludl/GCal3/GCal3.json returned 0 <{DEV_ID}>
50 12/15/15 21:43:53.383 luup_log:35: GCal3 V 1.5b:local function: getTimezone <{DEV_ID}>
50 12/15/15 21:43:53.384 luup_log:35: GCal3 V 1.5b:GCal3 V 1.5b:Timezone is -7 hrs and -0 min <{DEV_ID}>
50 12/15/15 21:43:53.385 luup_log:35: GCal3 V 1.5b:GCal3 V 1.5b:Running Plugin ... <{DEV_ID}>
06 12/15/15 21:43:53.385 Device_Variable::m_szValue_set device: 35 service: urn:srs-com:serviceId:GCalIII variable: gc_NextEvent was: now: Successfully Initialized #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:0 <{DEV_ID}>
06 12/15/15 21:43:53.386 Device_Variable::m_szValue_set device: 35 service: urn:srs-com:serviceId:GCalIII variable: gc_NextEventTime was: . now: . #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:1 <{DEV_ID}>
50 12/15/15 21:43:53.387 luup_log:35: GCal3 V 1.5b:local function: writetoFile <{DEV_ID}>
50 12/15/15 21:43:53.389 luup_log:35: GCal3 V 1.5b:Device 35 released the semaphore - reason: initialization complete <{DEV_ID}>
50 12/15/15 21:43:54.100 luup_log:35: GCal3 V 1.5b:local function: GCalMain <{DEV_ID}>
06 12/15/15 21:43:54.101 Device_Variable::m_szValue_set device: 35 service: urn:srs-com:serviceId:GCalIII variable: gc_NextEvent was: Successfully Initialized now: Start up ... #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:0 <{DEV_ID}>
06 12/15/15 21:43:54.102 Device_Variable::m_szValue_set device: 35 service: urn:srs-com:serviceId:GCalIII variable: gc_NextEventTime was: . now: . #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:1 <{DEV_ID}>
06 12/15/15 21:43:54.102 Device_Variable::m_szValue_set device: 35 service: urn:srs-com:serviceId:GCalIII variable: gc_NextEvent was: Start up ... now: The CalendarID is set #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:0 <{DEV_ID}>
06 12/15/15 21:43:54.103 Device_Variable::m_szValue_set device: 35 service: urn:srs-com:serviceId:GCalIII variable: gc_NextEventTime was: . now: . #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:1 <{DEV_ID}>
50 12/15/15 21:43:54.104 luup_log:35: GCal3 V 1.5b: ************** ARMED STATUS : 1 ***************** <{DEV_ID}>
50 12/15/15 21:43:54.375 luup_log:35: GCal3 V 1.5b:local function: checkGCal <{DEV_ID}>
06 12/15/15 21:43:54.376 Device_Variable::m_szValue_set device: 35 service: urn:srs-com:serviceId:GCalIII variable: gc_NextEventTime was: . now: Set up variables #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:0 <{DEV_ID}>
50 12/15/15 21:43:54.377 luup_log:35: GCal3 V 1.5b:local function: setupVariables <{DEV_ID}>
06 12/15/15 21:43:54.421 Device_Variable::m_szValue_set device: 35 service: urn:srs-com:serviceId:GCalIII variable: gc_NextEvent was: The CalendarID is set now: #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:0 <{DEV_ID}>
06 12/15/15 21:43:54.421 Device_Variable::m_szValue_set device: 35 service: urn:srs-com:serviceId:GCalIII variable: gc_NextEventTime was: Set up variables now: . #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:0 <{DEV_ID}>
50 12/15/15 21:43:54.422 luup_log:35: GCal3 V 1.5b:local function: makeBoolean <{DEV_ID}>
06 12/15/15 21:43:54.423 Device_Variable::m_szValue_set device: 35 service: urn:srs-com:serviceId:GCalIII variable: gc_exactKeyword was: true now: true #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:1 <{DEV_ID}>
50 12/15/15 21:43:54.424 luup_log:35: GCal3 V 1.5b:local function: makeBoolean <{DEV_ID}>
06 12/15/15 21:43:54.425 Device_Variable::m_szValue_set device: 35 service: urn:srs-com:serviceId:GCalIII variable: gc_ignoreKeyword was: false now: false #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:1 <{DEV_ID}>
50 12/15/15 21:43:54.425 luup_log:35: GCal3 V 1.5b:local function: makeBoolean <{DEV_ID}>
06 12/15/15 21:43:54.426 Device_Variable::m_szValue_set device: 35 service: urn:srs-com:serviceId:GCalIII variable: gc_triggerNoKeyword was: false now: false #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:1 <{DEV_ID}>
50 12/15/15 21:43:54.427 luup_log:35: GCal3 V 1.5b:local function: makeBoolean <{DEV_ID}>
06 12/15/15 21:43:54.427 Device_Variable::m_szValue_set device: 35 service: urn:srs-com:serviceId:GCalIII variable: gc_ignoreAllDayEvent was: false now: false #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:1 <{DEV_ID}>
50 12/15/15 21:43:54.444 luup_log:35: GCal3 V 1.5b:local function: makeBoolean <{DEV_ID}>
06 12/15/15 21:43:54.444 Device_Variable::m_szValue_set device: 35 service: urn:srs-com:serviceId:GCalIII variable: gc_retrip was: true now: true #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:1 <{DEV_ID}>
50 12/15/15 21:43:54.445 luup_log:35: GCal3 V 1.5b:local function: parseCalendar <{DEV_ID}>
50 12/15/15 21:43:54.446 luup_log:35: GCal3 V 1.5b:As Input <{DEV_ID}>
50 12/15/15 21:43:54.446 luup_log:35: GCal3 V 1.5b:https://calendar.google.com/calendar/embed?src={GUID}%40group.calendar.google.com <{DEV_ID}>
06 12/15/15 21:43:54.447 Device_Variable::m_szValue_set device: 35 service: urn:srs-com:serviceId:GCalIII variable: gc_CalendarID was: https://calendar.google.com/calendar/embed?src={GUID}%40group.calendar.google.com now: #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:0 <{DEV_ID}>
50 12/15/15 21:43:54.526 luup_log:35: GCal3 V 1.5b:After recoding <{DEV_ID}>
50 12/15/15 21:43:54.527 luup_log:35: GCal3 V 1.5b:https://calendar.google.com/calendar/embed?src={GUID}%40group.calendar.google.com <{DEV_ID}>
50 12/15/15 21:43:54.611 luup_log:35: GCal3 V 1.5b:Eliminate anything after %40group.calendar.google.com <{DEV_ID}>
50 12/15/15 21:43:54.611 luup_log:35: GCal3 V 1.5b:https://calendar.google.com/calendar/embed?src={GUID}%40group.calendar.google.com <{DEV_ID}>
50 12/15/15 21:43:54.613 luup_log:35: GCal3 V 1.5b: -- ?src= <{DEV_ID}>
50 12/15/15 21:43:54.614 luup_log:35: GCal3 V 1.5b:{GUID}%40group.calendar.google.com <{DEV_ID}>
50 12/15/15 21:43:54.616 luup_log:35: GCal3 V 1.5b: -- &src= <{DEV_ID}>
50 12/15/15 21:43:54.616 luup_log:35: GCal3 V 1.5b:{GUID}%40group.calendar.google.com <{DEV_ID}>
06 12/15/15 21:43:54.617 Device_Variable::m_szValue_set device: 35 service: urn:srs-com:serviceId:GCalIII variable: gc_CalendarID was: now: https://calendar.google.com/calendar/embed?src={GUID}%40group.calendar.google.com #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:0 <{DEV_ID}>
50 12/15/15 21:43:54.628 luup_log:35: GCal3 V 1.5b:Calendar ID is: {GUID}%40group.calendar.google.com <{DEV_ID}>
50 12/15/15 21:43:54.629 luup_log:35: GCal3 V 1.5b:local function: makejson <{DEV_ID}>
06 12/15/15 21:43:54.629 Device_Variable::m_szValue_set device: 35 service: urn:srs-com:serviceId:GCalIII variable: gc_jsonEvents was: [] now: [] #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:1 <{DEV_ID}>
50 12/15/15 21:43:54.630 luup_log:35: GCal3 V 1.5b:local function: makejson <{DEV_ID}>
06 12/15/15 21:43:54.631 Device_Variable::m_szValue_set device: 35 service: urn:srs-com:serviceId:GCalIII variable: gc_jsonActiveEvents was: [] now: [] #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:1 <{DEV_ID}>
06 12/15/15 21:43:54.631 Device_Variable::m_szValue_set device: 35 service: urn:srs-com:serviceId:GCalIII variable: gc_ActiveEvents was: now: #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:1 <{DEV_ID}>
06 12/15/15 21:43:54.632 Device_Variable::m_szValue_set device: 35 service: urn:srs-com:serviceId:GCalIII variable: gc_NextEventTime was: . now: Variable setup complete #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:0 <{DEV_ID}>
50 12/15/15 21:43:54.633 luup_log:35: GCal3 V 1.5b:local function: getStartMinMax <{DEV_ID}>
50 12/15/15 21:43:54.636 luup_log:35: GCal3 V 1.5b:StartMin is 2015-12-15T07:00:00Z StartMax is 2015-12-17T04:44:00Z <{DEV_ID}>
50 12/15/15 21:43:54.636 luup_log:35: GCal3 V 1.5b:End of day is 2015-12-15T23:59:59 <{DEV_ID}>
50 12/15/15 21:43:54.637 luup_log:35: GCal3 V 1.5b:local function: requestCalendar <{DEV_ID}>
50 12/15/15 21:43:54.657 luup_log:35: GCal3 V 1.5b:local function: get_access_token <{DEV_ID}>
50 12/15/15 21:43:55.046 luup_log:35: GCal3 V 1.5b:Token Info request status: HTTP/1.1 400 Bad Request <{DEV_ID}>
50 12/15/15 21:43:55.046 luup_log:35: GCal3 V 1.5b:Getting a new token <{DEV_ID}>
50 12/15/15 21:43:55.047 luup_log:35: GCal3 V 1.5b:local function: os_command <{DEV_ID}>
50 12/15/15 21:43:55.383 luup_log:35: GCal3 V 1.5b:local function: os_command <{DEV_ID}>
50 12/15/15 21:43:55.423 luup_log:35: GCal3 V 1.5b:local function: os_command <{DEV_ID}>
50 12/15/15 21:43:55.729 luup_log:35: GCal3 V 1.5b:local function: os_command <{DEV_ID}>
50 12/15/15 21:43:56.067 luup_log:35: GCal3 V 1.5b:Got new token <{DEV_ID}>
50 12/15/15 21:43:56.075 luup_log:35: GCal3 V 1.5b:Checking google calendar <{DEV_ID}>
06 12/15/15 21:43:56.076 Device_Variable::m_szValue_set device: 35 service: urn:srs-com:serviceId:GCalIII variable: gc_NextEvent was: now: Accessing Calendar #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:0 <{DEV_ID}>
06 12/15/15 21:43:56.077 Device_Variable::m_szValue_set device: 35 service: urn:srs-com:serviceId:GCalIII variable: gc_NextEventTime was: Variable setup complete now: . #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:0 <{DEV_ID}>
50 12/15/15 21:43:56.078 luup_log:35: GCal3 V 1.5b:Requested url: https://www.googleapis.com/calendar/v3/calendars/{GUID}%40group.calendar.google.com/events?access_token=ya29.{TOKEN}-Vuyl1Dg&timeZone=utc&singleEvents=true&orderBy=startTime&timeMax=2015-12-17T04:44:00Z&timeMin=2015-12-15T07:00:00Z&fields=items(description%2Cend%2Cstart%2Csummary) <{DEV_ID}>
01 12/15/15 21:43:56.101 LuaInterface::CallFunction_Timer-5 function StartupCheck failed [string "module("L_VeraAlert", package.seeall)..."]:1137: attempt to concatenate global 'lul_device' (a nil value) <0x2d276680>
50 12/15/15 21:43:56.601 luup_log:35: GCal3 V 1.5b:Http error code: 404 <{DEV_ID}>
06 12/15/15 21:43:56.602 Device_Variable::m_szValue_set device: 35 service: urn:srs-com:serviceId:GCalIII variable: gc_NextEvent was: Accessing Calendar now: Http error code: 404 #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:0 <{DEV_ID}>
06 12/15/15 21:43:56.603 Device_Variable::m_szValue_set device: 35 service: urn:srs-com:serviceId:GCalIII variable: gc_NextEventTime was: . now: . #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:1 <{DEV_ID}>
06 12/15/15 21:43:56.603 Device_Variable::m_szValue_set device: 35 service: urn:srs-com:serviceId:GCalIII variable: gc_NextEvent was: Http error code: 404 now: Access or Calendar Error #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:0 <{DEV_ID}>
06 12/15/15 21:43:56.604 Device_Variable::m_szValue_set device: 35 service: urn:srs-com:serviceId:GCalIII variable: gc_NextEventTime was: . now: 1 #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:0 <{DEV_ID}>
06 12/15/15 21:43:56.605 Device_Variable::m_szValue_set device: 35 service: urn:srs-com:serviceId:GCalIII variable: gc_jsonEvents was: [] now: [] #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:1 <{DEV_ID}>
06 12/15/15 21:43:56.606 Device_Variable::m_szValue_set device: 35 service: urn:srs-com:serviceId:GCalIII variable: gc_jsonActiveEvents was: [] now: [] #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:1 <{DEV_ID}>
06 12/15/15 21:43:56.606 Device_Variable::m_szValue_set device: 35 service: urn:srs-com:serviceId:GCalIII variable: gc_ActiveEvents was: now: #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:1 <{DEV_ID}>
50 12/15/15 21:43:56.607 luup_log:35: GCal3 V 1.5b:local function: setNextTimeCheck <{DEV_ID}>
50 12/15/15 21:43:56.608 luup_log:35: GCal3 V 1.5b:nextCheckTime: 1450241096 <{DEV_ID}>
06 12/15/15 21:43:56.609 Device_Variable::m_szValue_set device: 35 service: urn:srs-com:serviceId:GCalIII variable: gc_lastCheck was: 2015-12-15 at 21:42:03 now: 2015-12-15 at 21:43:56 #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:0 <{DEV_ID}>
06 12/15/15 21:43:56.612 Device_Variable::m_szValue_set device: 35 service: urn:srs-com:serviceId:GCalIII variable: gc_nextCheck was: 2015-12-15 at 21:43:03 now: 2015-12-15 at 21:44:56 #hooks: 0 upnp: 0 skip: 0 v:(nil)/NONE duplicate:0 <{DEV_ID}>
50 12/15/15 21:43:56.613 luup_log:35: GCal3 V 1.5b:Next check will be in 60 sec on 2015-12-15 at 21:44:56 <{DEV_ID}>
Stuart
December 16, 2015, 5:56am
17
Everything looks normal - right up to:
50 12/15/15 21:43:56.078 luup_log:35: GCal3 V 1.5b:Requested url: https://www.googleapis.com/calendar/v3/calendars/{GUID}%40group.calendar.google.com/events?access_token=ya29.{TOKEN}-Vuyl1Dg&timeZone=utc&singleEvents=true&orderBy=startTime&timeMax=2015-12-17T04:44:00Z&timeMin=2015-12-15T07:00:00Z&fields=items(description%2Cend%2Cstart%2Csummary) <{DEV_ID}>
01 12/15/15 21:43:56.101 LuaInterface::CallFunction_Timer-5 function StartupCheck failed [string "module("L_VeraAlert", package.seeall)..."]:1137: attempt to concatenate global 'lul_device' (a nil value) <0x2d276680>
50 12/15/15 21:43:56.601 luup_log:35: GCal3 V 1.5b:Http error code: 404 <{DEV_ID}>There is an error being thrown in L_VeraAlert – but that’s not our concern.
The 404 error could easily be a permissions problem.
xrs444
December 31, 2015, 5:21pm
18
Sorry, thought I’d updated this, but evidently not!
I redid the config from scratch, and it’s working fine now. I’m not sure if it was co-incidence, but the calDav api is now separate to the main calendar api, when I enabled it, it all started working, but that could have been coincidence!
Thanks for all your help.
nealoff
January 15, 2016, 11:12pm
19
I’ve also recently started having this problem on UI5.
I see status messages:
then I get:
I’m running 1.6 and I’ve completely uninstalled, reinstalled, regenerated the .json file, reuploaded (via Vera UI), and removed and re-added the permission in Google Calendar and still the same thing. Unfortunately I’m remote so I can’t get to log files. I’ve tested uploading bogus .json files and I get a Credential Error so it is apparently seeing the file I’ve uploaded because I don’t see that when I upload a valid file. The calendar view successfully shows the calendar as well.
Any ideas?
Stuart
January 21, 2016, 3:41am
20
What it means is that there was no valid response being returned by the call to the calendar (so it retries every minute). This can be due to a number of issues - there will be an error message before you get that message - but its being overwritten.
Here is a patch file that might make it easier to spot the real error. I made a change (commented out a line) to stop the message “Access or Calendar Error” so we can better see the prior error. The counter will still count up.
Without a log file the error messages only get us in the ballpark.
EDIT: removed patched version