Gcal error

Tags: #<Tag:0x00007f61704576c0> #<Tag:0x00007f61704575a8>

Hi,

since few days my gcal addon is not working…

Today I updated my openhab (openhabian), uninstalled gcal, deleted gcal_oauth2_token, created a new project in the google api console (+all additional steps (Api, cliend,…)), updated my client_id and client_secret in the cfg, installed gcal again and entered the code in ‘https://www.google.com/device’.
Log:

2018-03-13 20:10:52.895 [INFO ] [b.core.service.AbstractActiveService] - Google Calendar Event Downloader has been shut down
2018-03-13 20:23:22.206 [INFO ] [openhab.io.gcal.auth.GCalGoogleOAuth] - ################################################################################################
2018-03-13 20:23:22.210 [INFO ] [openhab.io.gcal.auth.GCalGoogleOAuth] - # Google-Integration: U S E R   I N T E R A C T I O N   R E Q U I R E D !!
2018-03-13 20:23:22.213 [INFO ] [openhab.io.gcal.auth.GCalGoogleOAuth] - # 1. Open URL 'https://www.google.com/device'
2018-03-13 20:23:22.215 [INFO ] [openhab.io.gcal.auth.GCalGoogleOAuth] - # 2. Type provided code JQBD-CGBG 
2018-03-13 20:23:22.219 [INFO ] [openhab.io.gcal.auth.GCalGoogleOAuth] - # 3. Grant openHAB access to your Google calendar
2018-03-13 20:23:22.222 [INFO ] [openhab.io.gcal.auth.GCalGoogleOAuth] - # 4. openHAB will automatically detect the permiossions and complete the authentication process
2018-03-13 20:23:22.224 [INFO ] [openhab.io.gcal.auth.GCalGoogleOAuth] - # NOTE: You will only have 1800 mins before openHAB gives up waiting for the access!!!
2018-03-13 20:23:22.227 [INFO ] [openhab.io.gcal.auth.GCalGoogleOAuth] - ################################################################################################
2018-03-13 20:24:05.796 [INFO ] [b.core.service.AbstractActiveService] - Google Calendar Event Downloader has been started
2018-03-13 20:24:06.868 [ERROR] [b.core.service.AbstractActiveService] - Error while executing background thread Google Calendar Event Downloader
java.lang.NullPointerException: null
	at org.openhab.io.gcal.internal.GCalEventDownloader.processEntries(GCalEventDownloader.java:276) [236:org.openhab.io.gcal:1.11.0]
	at org.openhab.io.gcal.internal.GCalEventDownloader.execute(GCalEventDownloader.java:140) [236:org.openhab.io.gcal:1.11.0]
	at org.openhab.core.service.AbstractActiveService$RefreshThread.run(AbstractActiveService.java:166) [219:org.openhab.core.compat1x:2.2.0]
2018-03-13 20:25:07.256 [ERROR] [b.core.service.AbstractActiveService] - Error while executing background thread Google Calendar Event Downloader
java.lang.NullPointerException: null
	at org.openhab.io.gcal.internal.GCalEventDownloader.processEntries(GCalEventDownloader.java:276) [236:org.openhab.io.gcal:1.11.0]
	at org.openhab.io.gcal.internal.GCalEventDownloader.execute(GCalEventDownloader.java:140) [236:org.openhab.io.gcal:1.11.0]
	at org.openhab.core.service.AbstractActiveService$RefreshThread.run(AbstractActiveService.java:166) [219:org.openhab.core.compat1x:2.2.0]
2018-03-13 20:26:07.680 [ERROR] [b.core.service.AbstractActiveService] - Error while executing background thread Google Calendar Event Downloader
java.lang.NullPointerException: null
...

What I have done wrong?

regards
dimes

No idea. That’s a strange error. Could you try putting the gcal binding in DEBUG or TRACE mode? Maybe that will yield some clues to what’s going on.

Looks like the NPE is coming from this line:

timeRangeCalendar.addTimeRange(new LongRange(event.getStart().getDateTime().getValue(),
event.getEnd().getDateTime().getValue()));

Yeah I saw that. But I can’t tell why it’s happening.

I was hoping the OP would recognize the cause based on this. Most likely either the calendar entry has no start or no end.

without any changes from my site, the calender is working again and also I do not get any error…

1 Like

Started for me as well :confused:

2020-01-02 17:28:57.535 [DEBUG] [enhab.io.gcal.internal.GCalActivator] - Google Calendar IO has been started.

2020-01-02 17:28:57.607 [DEBUG] [openhab.io.gcal.auth.GCalGoogleOAuth] - Loaded credential

2020-01-02 17:28:57.615 [DEBUG] [openhab.io.gcal.auth.GCalGoogleOAuth] - device access token: ---

2020-01-02 17:28:57.619 [DEBUG] [openhab.io.gcal.auth.GCalGoogleOAuth] - device refresh_token: ---

2020-01-02 17:28:57.622 [DEBUG] [openhab.io.gcal.auth.GCalGoogleOAuth] - device expires_in: 1577986113120

2020-01-02 17:28:57.626 [INFO ] [b.core.service.AbstractActiveService] - Google Calendar Event Downloader has been started

2020-01-02 17:28:57.627 [DEBUG] [openhab.io.gcal.auth.GCalGoogleOAuth] - Got calendar Arbeiten CalendarID: ---@group.calendar.google.com

2020-01-02 17:28:57.630 [DEBUG] [io.gcal.internal.GCalEventDownloader] - Downloading calendar feed for time interval: 2020-01-02T17:28:57.629+01:00 to  2020-01-02T17:28:59.629+01:00 

2020-01-02 17:28:57.635 [DEBUG] [openhab.io.gcal.auth.GCalGoogleOAuth] - Loaded credential

2020-01-02 17:28:57.637 [DEBUG] [openhab.io.gcal.auth.GCalGoogleOAuth] - device access token: ---

2020-01-02 17:28:57.639 [DEBUG] [openhab.io.gcal.auth.GCalGoogleOAuth] - device refresh_token: ---

2020-01-02 17:28:57.642 [DEBUG] [openhab.io.gcal.auth.GCalGoogleOAuth] - device expires_in: 1577986113120

2020-01-02 17:28:57.874 [DEBUG] [io.gcal.internal.GCalEventDownloader] - found 1 calendar events to process

2020-01-02 17:28:57.877 [ERROR] [b.core.service.AbstractActiveService] - Error while executing background thread Google Calendar Event Downloader

java.lang.NullPointerException: null

	at org.openhab.io.gcal.internal.GCalEventDownloader.createTriggerAndSchedule(GCalEventDownloader.java:428) ~[?:?]

	at org.openhab.io.gcal.internal.GCalEventDownloader.processEntries(GCalEventDownloader.java:307) ~[?:?]

	at org.openhab.io.gcal.internal.GCalEventDownloader.execute(GCalEventDownloader.java:144) ~[?:?]

	at org.openhab.core.service.AbstractActiveService$RefreshThread.run(AbstractActiveService.java:169) [bundleFile:?]

2020-01-02 17:28:58.883 [DEBUG] [openhab.io.gcal.auth.GCalGoogleOAuth] - Got calendar Arbeiten CalendarID: ---@group.calendar.google.com

2020-01-02 17:28:58.885 [DEBUG] [io.gcal.internal.GCalEventDownloader] - Downloading calendar feed for time interval: 2020-01-02T17:28:58.884+01:00 to  2020-01-02T17:29:00.884+01:00 

2020-01-02 17:28:58.893 [DEBUG] [openhab.io.gcal.auth.GCalGoogleOAuth] - Loaded credential

2020-01-02 17:28:58.895 [DEBUG] [openhab.io.gcal.auth.GCalGoogleOAuth] - device access token: ---

2020-01-02 17:28:58.896 [DEBUG] [openhab.io.gcal.auth.GCalGoogleOAuth] - device refresh_token: ---

2020-01-02 17:28:58.898 [DEBUG] [openhab.io.gcal.auth.GCalGoogleOAuth] - device expires_in: 1577986113120

2020-01-02 17:28:59.076 [DEBUG] [io.gcal.internal.GCalEventDownloader] - found 1 calendar events to process

2020-01-02 17:28:59.079 [ERROR] [b.core.service.AbstractActiveService] - Error while executing background thread Google Calendar Event Downloader

java.lang.NullPointerException: null

	at org.openhab.io.gcal.internal.GCalEventDownloader.createTriggerAndSchedule(GCalEventDownloader.java:428) ~[?:?]

	at org.openhab.io.gcal.internal.GCalEventDownloader.processEntries(GCalEventDownloader.java:307) ~[?:?]

	at org.openhab.io.gcal.internal.GCalEventDownloader.execute(GCalEventDownloader.java:144) ~[?:?]

	at org.openhab.core.service.AbstractActiveService$RefreshThread.run(AbstractActiveService.java:169) [bundleFile:?]

2020-01-02 17:29:00.084 [DEBUG] [openhab.io.gcal.auth.GCalGoogleOAuth] - Got calendar Arbeiten CalendarID: ---@group.calendar.google.com

2020-01-02 17:29:00.087 [DEBUG] [io.gcal.internal.GCalEventDownloader] - Downloading calendar feed for time interval: 2020-01-02T17:29:00.086+01:00 to  2020-01-02T17:29:02.086+01:00 

2020-01-02 17:29:00.097 [DEBUG] [openhab.io.gcal.auth.GCalGoogleOAuth] - Loaded credential

2020-01-02 17:29:00.099 [DEBUG] [openhab.io.gcal.auth.GCalGoogleOAuth] - device access token: ---

2020-01-02 17:29:00.102 [DEBUG] [openhab.io.gcal.auth.GCalGoogleOAuth] - device refresh_token: ---

2020-01-02 17:29:00.104 [DEBUG] [openhab.io.gcal.auth.GCalGoogleOAuth] - device expires_in: 1577986113120

2020-01-02 17:29:00.293 [DEBUG] [io.gcal.internal.GCalEventDownloader] - found 1 calendar events to process

If you’re actually wanting help with this, you should:
a) start a new thread for it
b) provide your configuration

My gcal.cfg only has credentials in it. Refresh rate was not set, so it should’ve been set to 900000 by default. However, the updates posted came every second.
I now set it manually to 900000, saved, restarted the bundle and then removed and restarted it again, so now it’s updating in the default rate.

Digging through the log files I saw that it started just before an all-day event started with this:

2020-01-01 23:59:59.399 [ERROR] [b.core.service.AbstractActiveService] - Error while executing background thread Google Calendar Event Downloader
java.lang.NullPointerException: null
	at org.openhab.io.gcal.internal.GCalEventDownloader.createTriggerAndSchedule(GCalEventDownloader.java:428) ~[?:?]
	at org.openhab.io.gcal.internal.GCalEventDownloader.processEntries(GCalEventDownloader.java:307) ~[?:?]
	at org.openhab.io.gcal.internal.GCalEventDownloader.execute(GCalEventDownloader.java:144) ~[?:?]
	at org.openhab.core.service.AbstractActiveService$RefreshThread.run(AbstractActiveService.java:169) [251:org.openhab.core.compat1x:2.5.0.M4]

and then continued every second until I stopped the bundle. Today (no event) I don’t get any errors, just this:

2020-01-03 07:41:08.767 [INFO ] [b.core.service.AbstractActiveService] - Google Calendar Event Downloader has been started

2020-01-03 07:41:08.769 [DEBUG] [openhab.io.gcal.auth.GCalGoogleOAuth] - Got calendar Arbeiten CalendarID: ---@group.calendar.google.com

2020-01-03 07:41:08.774 [DEBUG] [io.gcal.internal.GCalEventDownloader] - Downloading calendar feed for time interval: 2020-01-03T07:41:08.772+01:00 to  2020-01-03T08:11:08.772+01:00 

2020-01-03 07:41:08.781 [DEBUG] [openhab.io.gcal.auth.GCalGoogleOAuth] - Loaded credential

2020-01-03 07:41:08.783 [DEBUG] [openhab.io.gcal.auth.GCalGoogleOAuth] - device access token: ya29.---

2020-01-03 07:41:08.785 [DEBUG] [openhab.io.gcal.auth.GCalGoogleOAuth] - device refresh_token: ---

2020-01-03 07:41:08.787 [DEBUG] [openhab.io.gcal.auth.GCalGoogleOAuth] - device expires_in: 1578037053054

2020-01-03 07:41:08.989 [DEBUG] [io.gcal.internal.GCalEventDownloader] - gcal feed contains no events ...

The logfile shows a lot of this though:

2019-12-29 14:03:26.507 [ERROR] [io.gcal.internal.GCalEventDownloader] - Event fetch failed: connect timed out
2019-12-29 14:06:54.778 [ERROR] [io.gcal.internal.GCalEventDownloader] - Event fetch failed: www.googleapis.com
2019-12-29 14:07:01.085 [ERROR] [io.gcal.internal.GCalEventDownloader] - Event fetch failed: sun.security.validator.ValidatorException: PKIX path building failed: sun.security.provider.certpath.SunCertPathBuilderException: unable to find valid certification path to requested target
2019-12-30 13:33:30.693 [ERROR] [io.gcal.internal.GCalEventDownloader] - Event fetch failed: No route to host (Host unreachable)

When I tested it previously with non-all-day events (but instead starting at a specific time), it did work for me.

What other info would be helpful here?

Things that could help:

  1. a debug log
  2. the definition of the event

I’ve created an updated version of the jar for you to use. It traps the error and spits out a little additional debug information.

Thank you!

I removed the 1.14 bundle and installed the jar.
Debug log when starting is as follows:

2020-01-03 20:53:03.395 [DEBUG] [enhab.io.gcal.internal.GCalActivator] - Google Calendar IO has been started.
2020-01-03 20:53:03.672 [DEBUG] [openhab.io.gcal.auth.GCalGoogleOAuth] - Loaded credential
2020-01-03 20:53:03.675 [DEBUG] [openhab.io.gcal.auth.GCalGoogleOAuth] - device access token: ---
2020-01-03 20:53:03.677 [DEBUG] [openhab.io.gcal.auth.GCalGoogleOAuth] - device refresh_token: ---
2020-01-03 20:53:03.679 [DEBUG] [openhab.io.gcal.auth.GCalGoogleOAuth] - device expires_in: 1578084094187
2020-01-03 20:53:03.682 [INFO ] [b.core.service.AbstractActiveService] - Google Calendar Event Downloader has been started
2020-01-03 20:53:03.703 [DEBUG] [openhab.io.gcal.auth.GCalGoogleOAuth] - Loaded credential
2020-01-03 20:53:03.705 [DEBUG] [openhab.io.gcal.auth.GCalGoogleOAuth] - device access token: ---
2020-01-03 20:53:03.706 [DEBUG] [openhab.io.gcal.auth.GCalGoogleOAuth] - device refresh_token: ---
2020-01-03 20:53:03.709 [DEBUG] [openhab.io.gcal.auth.GCalGoogleOAuth] - device expires_in: 1578084094187
2020-01-03 20:53:04.525 [DEBUG] [openhab.io.gcal.auth.GCalGoogleOAuth] - Got calendar Arbeiten CalendarID: ---@group.calendar.google.com
2020-01-03 20:53:04.528 [DEBUG] [io.gcal.internal.GCalEventDownloader] - Downloading calendar feed for time interval: 2020-01-03T20:53:04.527+01:00 to  2020-01-03T21:23:04.527+01:00 
2020-01-03 20:53:04.533 [DEBUG] [openhab.io.gcal.auth.GCalGoogleOAuth] - Loaded credential
2020-01-03 20:53:04.535 [DEBUG] [openhab.io.gcal.auth.GCalGoogleOAuth] - device access token: ---
2020-01-03 20:53:04.537 [DEBUG] [openhab.io.gcal.auth.GCalGoogleOAuth] - device refresh_token: ---
2020-01-03 20:53:04.538 [DEBUG] [openhab.io.gcal.auth.GCalGoogleOAuth] - device expires_in: 1578084094187
2020-01-03 20:53:04.831 [DEBUG] [io.gcal.internal.GCalEventDownloader] - gcal feed contains no events ...

On the day mentioned above I had 2 all-day events in the calender. The events were defined as follows:

start { send AlexHomeoffice ON } end { send AlexHomeoffice OFF }

and

start {send VanyFrei ON} end {send VanyFrei OFF}

I just set up a new event starting in 5 minutes and restarted the bundle, but it still tells me “gcal feed contains no events …”

So we’re kind of stuck if you’re not getting any events. Our code just calls on the google api to fetch events. That call appears to be returning nothing…

Just checked the Google dashboard and noted that on Jan 2nd between 2pm and 6pm the API request traffic dropped to 0.

I didn’t change anything in that time period though, neither in the API nor in the Openhab settings…

Since I don’t get any error messages on both token and used calender, accessing the right feed shouldn’t be the issue, right?
Do you know of any hurdles that can prevent gcal from finding the events…?

Not aware of anything that would cause that.

One thing you might try:
shutdown, clear cache, remove or falsify the gcal credentials in the config, restart; this should generate some sort of login error. You can then reset to the right credentials and see if normal behavior is restored.

Hmm, just tried that… no change unfortunately. Also generated a new secret, but still no change.
Noted 2 things though…

  • I got 2 bundles active. Not sure why 280 is in there - I removed it from my addons.cfg and it was uninstalled previously…
179 x Active  x  80 x 1.15.0.202001031746     x org.openhab.io.gcal
280 x Active  x  80 x 1.14.0                  x org.openhab.io.gcal
  • I created a new calender, but it can’t be found. Other calenders however are recognized.