GCAL Binding stopped working (org.openhab.io.gcal-1.9.0-SNAPSHOT.jar with OH 1.8.3)

Add-ons Bindings
,
1

Hi,
Yesterday I installed the GCAL Binding org.openhab.io.gcal-1.9.0-SNAPSHOT.jar on Openhab Runtime 1.8.3 and configured Google API. all was working fine after initial setup and I was successfully able to execute command based on calendar scheduling.

after a few hours, GCAL Binding stopped working and does not come back even if I restart Openhab. it always. on start and on every refresh (15min default), I can see the following error in Openhab.log

2016-12-25 11:06:23.290 [ERROR] [.service.AbstractActiveService] - Error while executing background thread Google Calender Event-Downloader
java.lang.NullPointerException: null
at org.openhab.io.gcal.internal.GCalEventDownloader.processEntries(GCalEventDownloader.java:340) ~[na:na]
at org.openhab.io.gcal.internal.GCalEventDownloader.execute(GCalEventDownloader.java:182) ~[na:na]
at org.openhab.core.service.AbstractActiveService$RefreshThread.run(AbstractActiveService.java:173) ~[na:na]

does anybody has an idea how to fix this ? I really loved the gCAL Binding even though it was just working for a few hours.

2

Hello, I think itā€™s odd that the stack trace does not agree with the current code on the master branch. Would you mind double-checking that you are using the latest JAR and report back here?

3

Hello,
I just tried with the jar from your link. unfortunatelly, I get the same result.

4

Are you totally sure you only have one io.gcal JAR in your addons folder? Sorry to ask again, because the given stack trace canā€™t come from latest code (best I can tell).

5

yes,

root@nuc01:/opt/openhab/addons# ls
org.openhab.action.mail-1.8.3.jar
org.openhab.action.xmpp-1.8.3.jar
org.openhab.binding.exec-1.8.3.jar
org.openhab.binding.knx-1.8.3.jar
org.openhab.binding.mqtt-1.8.3.jar
org.openhab.binding.netatmo-1.8.3.jar
org.openhab.binding.ntp-1.8.3.jar
org.openhab.io.gcal-1.9.0-SNAPSHOT.jar
org.openhab.io.openhabcloud_1.9.0.201612192331.jar
org.openhab.persistence.rrd4j-1.8.3.jar

Do i need to store the .JSON file from Google and store it somewhere in the openhab Folders ?
or can I force the initialization process once again and start from stretch with the latest .jar you provided ?

thanks for your hints and support

6

No; should not be necessary.

On openHAB 1.8.3 server, if you

telnet localhost 5555
osgi> bundles | grep gcal

What does it return?

7

unfortunatelly, I never managed to Telnet into osgi console. when ever i telnet to localhost on port 555, I got a root@nuc01:~# telnet localhost 5555
Trying 127.0.0.1ā€¦
telnet: Unable to connect to remote host: Connection refused
I also have the -console=5555 in the start.sh but it does not help.

8

Something seems odd about your openHAB 1.8.3 installation. Is there a reason you did not install using the apt-get method (which puts files in /etc/openhab, /usr/share/openhab, /var/log/openhab, etc.)?

9

i found it more easy to have it running as runtime. I can easelly do a backup of the whole Folder and re-install (copy back) if something goes wrong with Ubuntu or Openhab. Since Iā€™m not really the Unix expert, I could not really troubleshoot if apt-get does something I donā€™t like.
beside the gcal issue, openhab runs absolutelly fine without any isse. I had it on 1.7 since at least 2 years without any Problem and upgraded recently to 1.8.3 without any Problem. it is really just the gcal causing Problems.

10

Hi,
my fault. I had a ā€œ=ā€ after the -cosole. thatā€™s why the osgi was not working. hereā€™s the output for the osgi console

osgi> bundles | grep gcal
{org.osgi.service.cm.ManagedService}={service.pid=org.openhab.gcal, component.name=org.openhab.binding.gcal.eventdownloader, component.id=80, service.id=158}
org.openhab.io.gcal_1.9.0.201612250211 [230]
{org.osgi.service.cm.ManagedService}={service.pid=org.openhab.gcal, component.name=org.openhab.binding.gcal.eventdownloader, component.id=80, service.id=158}
true
osgi>

11

John,
can I somehow force a new registration with Google ? i.e. can I somehow force to repeat the following steps ?
I wonder if the issue is because I did not open the URL below on the openhab machine but on my PC i remotly managed the Openhab.

-################################################################################################
[INFO ] [g.internal.GCalEventDownloader] - # 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 !!
[INFO ] [g.internal.GCalEventDownloader] - # 1. Open URL ā€˜https://www.google.com/deviceā€™
[INFO ] [g.internal.GCalEventDownloader] - # 2. Type provided code ZPWT-UVXXS
[INFO ] [g.internal.GCalEventDownloader] - # 3. Grant openHAB access to your Google calendar
[INFO ] [g.internal.GCalEventDownloader] - # 4. openHAB will automatically detect the permiossions and complete the authentication process
[INFO ] [g.internal.GCalEventDownloader] - # NOTE: You will only have 1800 mins before openHAB gives up waiting for the access!!!
[INFO ] [g.internal.GCalEventDownloader] -################################################################################################

12

On openHAB 1.8.3 using the apt-get installation, the credentials appear to be stored in /var/lib/openhab/gcal/gcal_oauth2_token. On other versions or operating systems, search for the file gcal_oauth2_token. I think if you back it up, delete it, and restart openHAB, it should go through the process again. Please report back with your observations and thanks.

13

thanks to your hint, re-pairing worked fine. this time I did it with the latest JAR you provided and paired it locally on the machines browser.
openhab log confirms successfull Connection (like last time)

2016-12-27 17:53:05.164 [INFO ] [.service.AbstractActiveService] - Google Calender Event-Downloader has been started

I already scheduled an Event and it worked fine (like last time).
last time, failure showed up after a few hours. Iā€™ll watch it and report back if failure Comes up again after a few hours.

for records, osgi now shows:

osgi> bundles | grep gcal
    {org.osgi.service.cm.ManagedService}={service.pid=org.openhab.gcal, component.name=org.openhab.binding.gcal.eventdownloader, component.id=93, service.id=171}
org.openhab.io.gcal_1.9.0.201612250211 [230]
    {org.osgi.service.cm.ManagedService}={service.pid=org.openhab.gcal, component.name=org.openhab.binding.gcal.eventdownloader, component.id=93, service.id=171}
true
1 Like
14

since i restarted the process again with your latest jar, everything works fine. issue did not came back so far. even after a restart of openhab, everything continues to work fine. seems like problem is fixed.
quick last question. how do I know thereā€™s a new JAR binding since itā€™s not included in the official add-on download ? is there a URL I can check if thereā€™s an updated binding ?
thanks again for your help
Juerg

15

Hi John,
it happened once again, but this time after a few days. gcal binding just gave up in the middle of the night.

2016-12-30 23:37:13.781 [ERROR] [.service.AbstractActiveService] - Error while executing background thread Google Calender Event-Downloader
java.lang.NullPointerException: null
        at org.openhab.io.gcal.internal.GCalEventDownloader.processEntries(GCalEventDownloader.java:276) ~[na:na]
        at org.openhab.io.gcal.internal.GCalEventDownloader.execute(GCalEventDownloader.java:140) ~[na:na]
        at org.openhab.core.service.AbstractActiveService$RefreshThread.run(AbstractActiveService.java:173) ~[na:na]

any idea why this is so unreliable ?

16

Hi Juerg,

The offending line in the source code is here, where there are about 3 possible null pointers.

Would you mind running the service with DEBUG logging turned on (for org.openhab.io.gcal)?

Iā€™ve checked my openHAB 1.8.3 log where I run two scheduled events a day over the holidays and I donā€™t have any NPEs.

The latest build of the JAR will be here.

17

sure. can you please remind me how to run this in debug mode / how to turn it on ? sorry for the basic question but iā€™m not really used to this.
thanks

18

On openHAB 1.8.3, add this line to logback.xml:

<logger name="org.openhab.io.gcal" level="TRACE"/>

(or DEBUG instead of TRACE if the output is overwhelming).

19

this is what I got with log level TRACE when I restart openhab

2017-01-01 18:46:22.575 [DEBUG] [o.io.gcal.auth.GCalGoogleOAuth] - Got calendar primary CalendarID: 
2017-01-01 18:46:22.576 [DEBUG] [g.internal.GCalEventDownloader] - Downloading calendar feed for time interval: 2017-01-01T18:46:                                             22.575+01:00 to  2017-01-01T19:16:22.575+01:00
2017-01-01 18:46:22.594 [DEBUG] [o.io.gcal.auth.GCalGoogleOAuth] - Loaded credential
2017-01-01 18:46:22.594 [DEBUG] [o.io.gcal.auth.GCalGoogleOAuth] - device access token:                                              
2017-01-01 18:46:22.595 [DEBUG] [o.io.gcal.auth.GCalGoogleOAuth] - device refresh_token: 
2017-01-01 18:46:22.595 [DEBUG] [o.io.gcal.auth.GCalGoogleOAuth] - device expires_in: 1483294103311
2017-01-01 18:46:22.917 [DEBUG] [g.internal.GCalEventDownloader] - found 1 calendar events to process
2017-01-01 18:46:22.919 [DEBUG] [g.internal.GCalEventDownloader] - found event 'Neujahrstag' with no content, add this event to t                                             he excluded TimeRangesCalendar - this event could be referenced by the modifiedBy clause
2017-01-01 18:46:22.979 [ERROR] [.service.AbstractActiveService] - Error while executing background thread Google Calender Event-                                             Downloader
java.lang.NullPointerException: null
        at org.openhab.io.gcal.internal.GCalEventDownloader.processEntries(GCalEventDownloader.java:276) ~[na:na]
        at org.openhab.io.gcal.internal.GCalEventDownloader.execute(GCalEventDownloader.java:140) ~[na:na]
        at org.openhab.core.service.AbstractActiveService$RefreshThread.run(AbstractActiveService.java:173) ~[na:na]

does this help any further ?

20

I will try to make use of that log, but it looks like the lines were truncated (bad for knowing more about the entries but good for not printing complete tokens should anyone want to misuse them!)

I will let you know if I need more, and thanks for providing it.