Caldav google calendar problem

michal_kornatowski75 · May 16, 2016, 10:39am

My fault, I have set TRACE for caldav_personal instead of io.caldav

2016-05-16 12:33:18.690 [DEBUG] [o.i.c.internal.CalDavActivator] - CalDav Calendar IO has been started.
2016-05-16 12:33:18.784 [TRACE] [.i.c.internal.CalDavLoaderImpl] - configuration parameter: service.pid
2016-05-16 12:33:18.784 [TRACE] [.i.c.internal.CalDavLoaderImpl] - configuration parameter: tasks:lastModifiedFileTimeStampValid
2016-05-16 12:33:18.800 [TRACE] [.i.c.internal.CalDavLoaderImpl] - configuration parameter: tasks:password
2016-05-16 12:33:18.800 [TRACE] [.i.c.internal.CalDavLoaderImpl] - configuration parameter: tasks:preloadTime
2016-05-16 12:33:18.815 [TRACE] [.i.c.internal.CalDavLoaderImpl] - configuration parameter: tasks:reloadInterval
2016-05-16 12:33:18.815 [TRACE] [.i.c.internal.CalDavLoaderImpl] - configuration parameter: tasks:url
2016-05-16 12:33:18.831 [TRACE] [.i.c.internal.CalDavLoaderImpl] - configuration parameter: tasks:username
2016-05-16 12:33:18.831 [TRACE] [.i.c.internal.CalDavLoaderImpl] - config for id ‘tasks’: CalDavConfig [key=tasks, username=michalXXXXXXX@gmail.com, password=XXXXXX, url=https://www.google.com/calendar/dav/michalXXXXXX@gmail.com/events, reloadMinutes=15, preloadMinutes=20000, disableCertificateVerification=false, lastModifiedFileTimeStampValid=false]
2016-05-16 12:33:18.862 [INFO ] [.service.AbstractActiveService] - CalDav Loader has been started
2016-05-16 12:33:18.878 [TRACE] [.i.c.internal.CalDavLoaderImpl] - starting execution…
2016-05-16 12:33:18.924 [INFO ] [.i.c.internal.CalDavLoaderImpl] - reload job scheduled for: tasks
2016-05-16 12:33:19.112 [TRACE] [.i.c.internal.CalDavLoaderImpl] - quering events for filter: CalDavQuery [calendarIds=[tasks], from=2016-05-16T12:33:19.049+02:00, to=null, sort=ASCENDING]
2016-05-16 12:33:19.112 [DEBUG] [.i.c.internal.CalDavLoaderImpl] - return event list for CalDavQuery [calendarIds=[tasks], from=2016-05-16T12:33:19.049+02:00, to=null, sort=ASCENDING] with 0 entries

…

2016-05-16 12:33:29.486 [TRACE] [.i.c.internal.CalDavLoaderImpl] - listeners for events: 1
2016-05-16 12:33:29.486 [DEBUG] [o.o.i.c.i.job.EventReloaderJob] - loading events for config: tasks
2016-05-16 12:33:32.091 [TRACE] [o.o.i.c.i.job.EventReloaderJob] - eventContainer found: true
2016-05-16 12:33:32.091 [TRACE] [o.o.i.c.i.job.EventReloaderJob] - last resource modification: 2016-05-16T12:33:32.091+02:00
2016-05-16 12:33:32.106 [TRACE] [o.o.i.c.i.job.EventReloaderJob] - last change of already loaded event: 2015-01-15T20:05:02.000+01:00
2016-05-16 12:33:32.106 [DEBUG] [o.o.i.c.i.job.EventReloaderJob] - loading resource: /calendar/dav/michalXXXXXXX@gmail.com/events/ac8cc55f-2346-496c-9563-c2ab114b4882.ics
2016-05-16 12:33:32.465 [TRACE] [o.o.i.c.i.job.EventReloaderJob] - loading event: ac8cc55f-2346-496c-9563-c2ab114b4882:Statt
2016-05-16 12:33:32.496 [TRACE] [o.o.i.c.i.job.EventReloaderJob] - eventContainer found: false
2016-05-16 12:33:32.512 [TRACE] [o.o.i.c.i.job.EventReloaderJob] - last resource modification: 2016-05-16T12:33:32.496+02:00
2016-05-16 12:33:32.512 [TRACE] [o.o.i.c.i.job.EventReloaderJob] - last change of already loaded event: null
2016-05-16 12:33:32.512 [DEBUG] [o.o.i.c.i.job.EventReloaderJob] - loading resource: /calendar/dav/michalXXXXXXX@gmail.com/events/c7gsve1p7kke2kifpukb5eokh0@google.com.ics
2016-05-16 12:33:32.808 [ERROR] [o.o.i.c.i.job.EventReloaderJob] - error while loading calendar entries: null
java.lang.NullPointerException: null
at org.openhab.io.caldav.internal.job.EventReloaderJob.loadEvents(EventReloaderJob.java:325) ~[na:na]
at org.openhab.io.caldav.internal.job.EventReloaderJob.loadEvents(EventReloaderJob.java:282) ~[na:na]
at org.openhab.io.caldav.internal.job.EventReloaderJob.execute(EventReloaderJob.java:118) ~[na:na]
at org.quartz.core.JobRunShell.run(JobRunShell.java:213) [quartz-all-2.1.7.jar:na]
at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:557) [quartz-all-2.1.7.jar:na]

…

This one should be today in the evening

BEGIN:VEVENT
DTSTART;TZID=Europe/Warsaw:20151123T213000
DTEND;TZID=Europe/Warsaw:20151123T230000
RRULE:FREQ=WEEKLY;WKST=MO;UNTIL=20201123T203000Z;INTERVAL=1;BYDAY=MO
DTSTAMP:20160516T091642Z
UID:a2nrnbqa1pqmv29m15ag839qd0@google.com
CREATED:20151119T092913Z
DESCRIPTION:
LAST-MODIFIED:20151119T092913Z
LOCATION:
SEQUENCE:1
STATUS:TENTATIVE
SUMMARY:Basen krynia
TRANSP:OPAQUE
BEGIN:VALARM
ACTION:DISPLAY
DESCRIPTION:This is an event reminder
TRIGGER:-P0DT0H15M0S
END:VALARM
END:VEVENT

querdenker2k · May 18, 2016, 7:48pm

implementation is ongoing… needs some time…

querdenker2k · May 20, 2016, 8:12pm

OK, here is an update.
http://speedy.sh/fv7BN/org.openhab.io.caldav-1.9.0-SNAPSHOT.jar

thucke · May 21, 2016, 11:06am

Hmm, slightly different behaviour now.
All the same during startup phase.

This is the entry for the first EventLoaderJob:

2016-05-21 12:19:34.197 [DEBUG] [o.o.i.c.i.job.EventReloaderJob] - reload cached events for config: openhab_tasks
2016-05-21 12:19:34.319 [DEBUG] [o.o.i.c.i.job.EventReloaderJob] - loading events for config: openhab_tasks

After the second logentry:

2016-05-21 12:24:34.083 [DEBUG] [o.o.i.c.i.job.EventReloaderJob] - loading events for config: openhab_tasks

Nothing happened until I stoppen OpenHAB:

2016-05-21 12:36:21.522 [ERROR] [o.io.caldav.internal.OAuthUtil] - error accessing OAuth
javax.net.ssl.SSLHandshakeException: Remote host closed connection during handshake
at sun.security.ssl.SSLSocketImpl.readRecord(SSLSocketImpl.java:992) ~[na:1.8.0_92]
at sun.security.ssl.SSLSocketImpl.performInitialHandshake(SSLSocketImpl.java:1375) ~[na:1.8.0_92]
at sun.security.ssl.SSLSocketImpl.startHandshake(SSLSocketImpl.java:1403) ~[na:1.8.0_92]
at sun.security.ssl.SSLSocketImpl.startHandshake(SSLSocketImpl.java:1387) ~[na:1.8.0_92]
at org.apache.http.conn.ssl.SSLConnectionSocketFactory.createLayeredSocket(SSLConnectionSocketFactory.java:275) ~[httpclient-4.3.5.jar:4.3.5]
at org.apache.http.conn.ssl.SSLConnectionSocketFactory.connectSocket(SSLConnectionSocketFactory.java:254) ~[httpclient-4.3.5.jar:4.3.5]
at org.apache.http.impl.conn.HttpClientConnectionOperator.connect(HttpClientConnectionOperator.java:123) ~[httpclient-4.3.5.jar:4.3.5]
at org.apache.http.impl.conn.PoolingHttpClientConnectionManager.connect(PoolingHttpClientConnectionManager.java:318) ~[httpclient-4.3.5.jar:4.3.5]
at org.apache.http.impl.execchain.MainClientExec.establishRoute(MainClientExec.java:363) ~[httpclient-4.3.5.jar:4.3.5]
at org.apache.http.impl.execchain.MainClientExec.execute(MainClientExec.java:219) ~[httpclient-4.3.5.jar:4.3.5]
at org.apache.http.impl.execchain.ProtocolExec.execute(ProtocolExec.java:195) ~[httpclient-4.3.5.jar:4.3.5]
at org.apache.http.impl.execchain.RetryExec.execute(RetryExec.java:86) ~[httpclient-4.3.5.jar:4.3.5]
at org.apache.http.impl.execchain.RedirectExec.execute(RedirectExec.java:108) ~[httpclient-4.3.5.jar:4.3.5]
at org.apache.http.impl.client.InternalHttpClient.doExecute(InternalHttpClient.java:184) ~[httpclient-4.3.5.jar:4.3.5]
at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:82) ~[httpclient-4.3.5.jar:4.3.5]
at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:106) ~[httpclient-4.3.5.jar:4.3.5]
at org.openhab.io.caldav.internal.OAuthUtil.getCalendars(OAuthUtil.java:130) [bundlefile:na]
at org.openhab.io.caldav.internal.OAuthUtil.getCalendars(OAuthUtil.java:150) [bundlefile:na]
at org.openhab.io.caldav.internal.OAuthUtil.getCalendars(OAuthUtil.java:150) [bundlefile:na]
at org.openhab.io.caldav.internal.OAuthUtil.getCalendars(OAuthUtil.java:150) [bundlefile:na]
at org.openhab.io.caldav.internal.OAuthUtil.getCalendars(OAuthUtil.java:150) [bundlefile:na]
… 1008 times
Caused by: java.io.EOFException: SSL peer shut down incorrectly
at sun.security.ssl.InputRecord.read(InputRecord.java:505) ~[na:1.8.0_92]
at sun.security.ssl.SSLSocketImpl.readRecord(SSLSocketImpl.java:973) ~[na:1.8.0_92]
at sun.security.ssl.SSLSocketImpl.performInitialHandshake(SSLSocketImpl.java:1375) ~[na:1.8.0_92]
at sun.security.ssl.SSLSocketImpl.startHandshake(SSLSocketImpl.java:1403) ~[na:1.8.0_92]
at sun.security.ssl.SSLSocketImpl.startHandshake(SSLSocketImpl.java:1387) ~[na:1.8.0_92]
at org.apache.http.conn.ssl.SSLConnectionSocketFactory.createLayeredSocket(SSLConnectionSocketFactory.java:275) ~[httpclient-4.3.5.jar:4.3.5]
at org.apache.http.conn.ssl.SSLConnectionSocketFactory.connectSocket(SSLConnectionSocketFactory.java:254) ~[httpclient-4.3.5.jar:4.3.5]
at org.apache.http.impl.conn.HttpClientConnectionOperator.connect(HttpClientConnectionOperator.java:123) ~[httpclient-4.3.5.jar:4.3.5]
at org.apache.http.impl.conn.PoolingHttpClientConnectionManager.connect(PoolingHttpClientConnectionManager.java:318) ~[httpclient-4.3.5.jar:4.3.5]
at org.apache.http.impl.execchain.MainClientExec.establishRoute(MainClientExec.java:363) ~[httpclient-4.3.5.jar:4.3.5]
at org.apache.http.impl.execchain.MainClientExec.execute(MainClientExec.java:219) ~[httpclient-4.3.5.jar:4.3.5]
at org.apache.http.impl.execchain.ProtocolExec.execute(ProtocolExec.java:195) ~[httpclient-4.3.5.jar:4.3.5]
at org.apache.http.impl.execchain.RetryExec.execute(RetryExec.java:86) ~[httpclient-4.3.5.jar:4.3.5]
at org.apache.http.impl.execchain.RedirectExec.execute(RedirectExec.java:108) ~[httpclient-4.3.5.jar:4.3.5]
at org.apache.http.impl.client.InternalHttpClient.doExecute(InternalHttpClient.java:184) ~[httpclient-4.3.5.jar:4.3.5]
at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:82) ~[httpclient-4.3.5.jar:4.3.5]
at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:106) ~[httpclient-4.3.5.jar:4.3.5]
at org.openhab.io.caldav.internal.OAuthUtil.getCalendars(OAuthUtil.java:130) [bundlefile:na]
… 1006 common frames omitted
2016-05-21 12:36:27.752 [ERROR] [o.o.i.c.i.job.EventReloaderJob] - error loading calendar entries
java.lang.IllegalStateException: error accessing OAuth
at org.openhab.io.caldav.internal.OAuthUtil.getCalendars(OAuthUtil.java:159) ~[na:na]
at org.openhab.io.caldav.internal.OAuthUtil.getCalendars(OAuthUtil.java:150) ~[na:na]
at org.openhab.io.caldav.internal.OAuthUtil.getCalendars(OAuthUtil.java:150) ~[na:na]
at org.openhab.io.caldav.internal.OAuthUtil.getCalendars(OAuthUtil.java:150) ~[na:na]
… 1024 times
Caused by: javax.net.ssl.SSLHandshakeException: Remote host closed connection during handshake
at sun.security.ssl.SSLSocketImpl.readRecord(SSLSocketImpl.java:992) ~[na:1.8.0_92]
at sun.security.ssl.SSLSocketImpl.performInitialHandshake(SSLSocketImpl.java:1375) ~[na:1.8.0_92]
at sun.security.ssl.SSLSocketImpl.startHandshake(SSLSocketImpl.java:1403) ~[na:1.8.0_92]
at sun.security.ssl.SSLSocketImpl.startHandshake(SSLSocketImpl.java:1387) ~[na:1.8.0_92]
at org.apache.http.conn.ssl.SSLConnectionSocketFactory.createLayeredSocket(SSLConnectionSocketFactory.java:275) ~[na:na]
at org.apache.http.conn.ssl.SSLConnectionSocketFactory.connectSocket(SSLConnectionSocketFactory.java:254) ~[na:na]
at org.apache.http.impl.conn.HttpClientConnectionOperator.connect(HttpClientConnectionOperator.java:123) ~[na:na]
at org.apache.http.impl.conn.PoolingHttpClientConnectionManager.connect(PoolingHttpClientConnectionManager.java:318) ~[na:na]
at org.apache.http.impl.execchain.MainClientExec.establishRoute(MainClientExec.java:363) ~[na:na]
at org.apache.http.impl.execchain.MainClientExec.execute(MainClientExec.java:219) ~[na:na]
at org.apache.http.impl.execchain.ProtocolExec.execute(ProtocolExec.java:195) ~[na:na]
at org.apache.http.impl.execchain.RetryExec.execute(RetryExec.java:86) ~[na:na]
at org.apache.http.impl.execchain.RedirectExec.execute(RedirectExec.java:108) ~[na:na]
at org.apache.http.impl.client.InternalHttpClient.doExecute(InternalHttpClient.java:184) ~[na:na]
at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:82) ~[na:na]
at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:106) ~[na:na]
at org.openhab.io.caldav.internal.OAuthUtil.getCalendars(OAuthUtil.java:130) ~[na:na]
… 1007 common frames omitted
Caused by: java.io.EOFException: SSL peer shut down incorrectly
at sun.security.ssl.InputRecord.read(InputRecord.java:505) ~[na:1.8.0_92]
at sun.security.ssl.SSLSocketImpl.readRecord(SSLSocketImpl.java:973) ~[na:1.8.0_92]
at sun.security.ssl.SSLSocketImpl.performInitialHandshake(SSLSocketImpl.java:1375) ~[na:1.8.0_92]
at sun.security.ssl.SSLSocketImpl.startHandshake(SSLSocketImpl.java:1403) ~[na:1.8.0_92]
at sun.security.ssl.SSLSocketImpl.startHandshake(SSLSocketImpl.java:1387) ~[na:1.8.0_92]
at org.apache.http.conn.ssl.SSLConnectionSocketFactory.createLayeredSocket(SSLConnectionSocketFactory.java:275) ~[na:na]
at org.apache.http.conn.ssl.SSLConnectionSocketFactory.connectSocket(SSLConnectionSocketFactory.java:254) ~[na:na]
at org.apache.http.impl.conn.HttpClientConnectionOperator.connect(HttpClientConnectionOperator.java:123) ~[na:na]
at org.apache.http.impl.conn.PoolingHttpClientConnectionManager.connect(PoolingHttpClientConnectionManager.java:318) ~[na:na]
at org.apache.http.impl.execchain.MainClientExec.establishRoute(MainClientExec.java:363) ~[na:na]
at org.apache.http.impl.execchain.MainClientExec.execute(MainClientExec.java:219) ~[na:na]
at org.apache.http.impl.execchain.ProtocolExec.execute(ProtocolExec.java:195) ~[na:na]
at org.apache.http.impl.execchain.RetryExec.execute(RetryExec.java:86) ~[na:na]
at org.apache.http.impl.execchain.RedirectExec.execute(RedirectExec.java:108) ~[na:na]
at org.apache.http.impl.client.InternalHttpClient.doExecute(InternalHttpClient.java:184) ~[na:na]
at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:82) ~[na:na]
at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:106) ~[na:na]
at org.openhab.io.caldav.internal.OAuthUtil.getCalendars(OAuthUtil.java:130) ~[na:na]
… 1006 common frames omitted
2016-05-21 12:36:27.771 [DEBUG] [o.o.b.c.internal.CalDavBinding] - calendar reloaded: openhab_tasks
2016-05-21 12:36:27.783 [TRACE] [.i.c.internal.CalDavLoaderImpl] - quering events for filter: CalDavQuery [calendarIds=[openhab_tasks], from=2016-05-21T12:36:27.771+02:00, to=null, sort=ASCENDING, filterName=null]
2016-05-21 12:36:27.787 [DEBUG] [.i.c.internal.CalDavLoaderImpl] - return event list for CalDavQuery [calendarIds=[openhab_tasks], from=2016-05-21T12:36:27.771+02:00, to=null, sort=ASCENDING, filterName=null] with 0 entries
2016-05-21 12:36:27.787 [DEBUG] [o.o.b.c.internal.CalDavBinding] - no event found for GoogleCalName1, setting to UNDEF
2016-05-21 12:36:27.788 [DEBUG] [o.o.b.c.internal.CalDavBinding] - no event found for GoogleCalTime1, setting to UNDEF

Well, the issue causing memory leak seem to be solved. Don’t get any heap space exception. Hence accessing the webservice still doesn’t work.
I’m still not sure if my OAuth login does really work. Am I using the correct entries for username/password? I doubt I’m doing not so.
It’d be great having the logon process set to trace level. Would also have to trace the IP-communication between OpenHAB and Google which is unfortunately senseless because of SSL encryption.

Thank you a lot for your support.

thucke · May 21, 2016, 4:10pm

Hi querdenker2k,
I got the connection running.
Obviousliy I created the wrong google credential.
In my former tries I used a Service account key for server-server-communication as described in サーバー間アプリケーションに OAuth 2.0 を使用する | Authorization | Google for Developers.
Today your remark in post #9 Caldav google calendar problem - #9 by querdenker2k let me re-think about if this was correct.
Now I’ve created a “normal” OAuth-Client-ID and got two information items (Client-Id, Client-Key) which I used as username/password in the openhab.cfg.
After a clean restart of my OpenHAB instance the logfile came up with the mentioned information:

authentication required for account with client_id=your-client-id
user_code=user-code-to-be-entered-in-the-website
verification_url=url-to-enter-the-code

The URL brought me to a Google confirmation page and since I passed that my calendar entry appears in sitemap.

In conclusion the main issue here was that Googles API manager offers three different credential types:

API key
OAuth Client ID
Service account key

If one would like to use the CalDAV binding to access a Google calandar he should create a OAuth Client ID.

querdenker2k · May 21, 2016, 5:40pm

Hi thucke,

Nice to hear, that it’s working now.
I will fix this in the next version…

at org.openhab.io.caldav.internal.OAuthUtil.getCalendars(OAuthUtil.java:130) [bundlefile:na]
at org.openhab.io.caldav.internal.OAuthUtil.getCalendars(OAuthUtil.java:150) [bundlefile:na]
at org.openhab.io.caldav.internal.OAuthUtil.getCalendars(OAuthUtil.java:150) [bundlefile:na]
at org.openhab.io.caldav.internal.OAuthUtil.getCalendars(OAuthUtil.java:150) [bundlefile:na]
at org.openhab.io.caldav.internal.OAuthUtil.getCalendars(OAuthUtil.java:150) [bundlefile:na]
… 1008 times

michal_kornatowski75 · May 24, 2016, 10:56pm

Hi Querdenker2k,

Big thanks for your involvement and priceless help.
I have make caldav synchronization working (I suppose) but none of events appears

2016-05-25 00:10:45.719 [DEBUG] [o.i.c.internal.CalDavActivator] - CalDav Calendar IO has been started.
2016-05-25 00:10:45.813 [TRACE] [.i.c.internal.CalDavLoaderImpl] - configuration parameter: openhab_tasks:lastModifiedFileTimeStampValid
2016-05-25 00:10:45.829 [TRACE] [.i.c.internal.CalDavLoaderImpl] - configuration parameter: openhab_tasks:oauth
2016-05-25 00:10:45.829 [TRACE] [.i.c.internal.CalDavLoaderImpl] - configuration parameter: openhab_tasks:password
2016-05-25 00:10:45.829 [TRACE] [.i.c.internal.CalDavLoaderImpl] - configuration parameter: openhab_tasks:preloadTime
2016-05-25 00:10:45.829 [TRACE] [.i.c.internal.CalDavLoaderImpl] - configuration parameter: openhab_tasks:reloadInterval
2016-05-25 00:10:45.829 [TRACE] [.i.c.internal.CalDavLoaderImpl] - configuration parameter: openhab_tasks:url
2016-05-25 00:10:45.829 [TRACE] [.i.c.internal.CalDavLoaderImpl] - configuration parameter: openhab_tasks:username
2016-05-25 00:10:45.829 [TRACE] [.i.c.internal.CalDavLoaderImpl] - configuration parameter: service.pid
2016-05-25 00:10:45.829 [TRACE] [.i.c.internal.CalDavLoaderImpl] - config for id ‘openhab_tasks’: CalDavConfig [key=openhab_tasks, username=some_long_value.apps.googleusercontent.com, password=_shorter_value, url=https://apidata.googleusercontent.com/caldav/v2/michal.XXXX@gmail.com/events, reloadMinutes=30, preloadMinutes=10080, disableCertificateVerification=false, lastModifiedFileTimeStampValid=false]
2016-05-25 00:10:45.860 [INFO ] [.service.AbstractActiveService] - CalDav Loader has been started
2016-05-25 00:10:45.860 [TRACE] [.i.c.internal.CalDavLoaderImpl] - starting execution…
2016-05-25 00:10:45.907 [INFO ] [.i.c.internal.CalDavLoaderImpl] - reload job scheduled for: openhab_tasks
2016-05-25 00:10:55.906 [DEBUG] [o.o.i.c.i.job.EventReloaderJob] - reload cached events for config: openhab_tasks
2016-05-25 00:10:58.075 [TRACE] [o.o.i.c.i.job.EventReloaderJob] - loading event: 040000008200E00074C5B7101A82E008000000000C15E75C437544295C939D8D0C0C74A610000000440DE161237E644103148B4CDFEC9EC9:Imieniny mamy
2016-05-25 00:10:58.106 [TRACE] [.i.c.internal.CalDavLoaderImpl] - listeners for events: 1
2016-05-25 00:10:58.121 [TRACE] [o.o.i.c.i.job.EventReloaderJob] - loading event: 040000008200E00074C5B7101A82E008000000000C15E75C437544295C939D8D0C0C74A610000000CBB7491A4B11012BCEA8A6FE971D08E8:Niedziela imieniny patrycji
2016-05-25 00:10:58.121 [TRACE] [.i.c.internal.CalDavLoaderImpl] - listeners for events: 1
2016-05-25 00:10:58.121 [TRACE] [o.o.i.c.i.job.EventReloaderJob] - loading event: 040000008200E00074C5B7101A82E00800000000364926DDF51651FA71A7A0CB2DF93DF21000000027F17ECC3206BF8CAF936742E810C65F:Mama urodziny
2016-05-25 00:10:58.121 [TRACE] [.i.c.internal.CalDavLoaderImpl] - listeners for events: 1

…A lot of events…
This event should appear as Upcoming one hour ago and as active for now

2016-05-25 00:10:58.792 [TRACE] [o.o.i.c.i.job.EventReloaderJob] - loading event: i8379es5la7g6s0jesm9bhlpc0@google.com:PrzyszĹ‚y tydzieĹ„ Hania
2016-05-25 00:10:58.792 [TRACE] [o.o.i.c.i.job.EventReloaderJob] - start is with known timezone: Europe/Warsaw
2016-05-25 00:10:58.792 [TRACE] [o.o.i.c.i.job.EventReloaderJob] - end is with known timezone: Europe/Warsaw
2016-05-25 00:10:58.792 [TRACE] [o.o.i.c.i.job.EventReloaderJob] - adding event: i8379es5la7g6s0jesm9bhlpc0@google.com(PrzyszĹ‚y tydzieĹ„ Hania@25.05.2016/11:00-25.05.2016/12:00)
2016-05-25 00:10:58.792 [TRACE] [.i.c.internal.CalDavLoaderImpl] - listeners for events: 1
2016-05-25 00:10:58.808 [TRACE] [.i.c.internal.CalDavLoaderImpl] - notify listener… org.openhab.binding.caldav_personal.internal.CalDavBinding@1a65018
2016-05-25 00:10:58.808 [TRACE] [.i.c.internal.CalDavLoaderImpl] - old start job (event-start-i8379es5la7g6s0jesm9bhlpc0@google.com(PrzyszĹ‚y tydzieĹ„ Hania@25.05.2016/11:00-25.05.2016/12:00)-0) deleted? false/false
2016-05-25 00:10:58.808 [DEBUG] [.i.c.internal.CalDavLoaderImpl] - begin timer scheduled for event ‘i8379es5la7g6s0jesm9bhlpc0@google.com(PrzyszĹ‚y tydzieĹ„ Hania@25.05.2016/11:00-25.05.2016/12:00)’ @ Wed May 25 11:00:00 CEST 2016
2016-05-25 00:10:58.808 [TRACE] [.i.c.internal.CalDavLoaderImpl] - old end job (event-end-i8379es5la7g6s0jesm9bhlpc0@google.com(PrzyszĹ‚y tydzieĹ„ Hania@25.05.2016/11:00-25.05.2016/12:00)-0) deleted? false/false
2016-05-25 00:10:58.808 [DEBUG] [.i.c.internal.CalDavLoaderImpl] - end timer scheduled for event ‘i8379es5la7g6s0jesm9bhlpc0@google.com(PrzyszĹ‚y tydzieĹ„ Hania@25.05.2016/11:00-25.05.2016/12:00)’ @ Wed May 25 12:00:00 CEST 2016

…Much more events…

Some repeatable events

2016-05-25 00:10:59.588 [TRACE] [o.o.i.c.i.job.EventReloaderJob] - loading event: jr8mu225g3fsriee35e56jpof8@google.com:Us
2016-05-25 00:10:59.588 [DEBUG] [.i.c.internal.CalDavLoaderImpl] - event is already in event map and newer -> delete the old one, reschedule timer
2016-05-25 00:10:59.588 [DEBUG] [o.o.i.c.i.job.EventReloaderJob] - loading events for config: openhab_tasks

…And more …
Too old events?

2016-05-25 00:11:03.035 [TRACE] [o.o.i.c.i.job.EventReloaderJob] - loading event: fo9ce75qrdd5jml0jbg4d8l8v4@google.com:Za dwa dni imieniny patrycji
2016-05-25 00:11:03.035 [TRACE] [o.o.i.c.i.job.EventReloaderJob] - skipping resource processing fo9ce75qrdd5jml0jbg4d8l8v4@google.com, not changed

…Same again after half an hour, but without event which was active before…

2016-05-25 00:40:55.900 [DEBUG] [o.o.i.c.i.job.EventReloaderJob] - loading events for config: openhab_tasks
2016-05-25 00:40:59.207 [TRACE] [o.o.i.c.i.job.EventReloaderJob] - loading event: 040000008200E00074C5B7101A82E008000000000C15E75C437544295C939D8D0C0C74A610000000440DE161237E644103148B4CDFEC9EC9:Imieniny mamy
2016-05-25 00:40:59.207 [TRACE] [o.o.i.c.i.job.EventReloaderJob] - skipping resource processing 040000008200E00074C5B7101A82E008000000000C15E75C437544295C939D8D0C0C74A610000000440DE161237E644103148B4CDFEC9EC9, not changed

…A lot of events…
…End of log

Please help one more time

querdenker2k · May 25, 2016, 4:38pm

Which binding are you using as well? the caldav-personal binding? Can please post your config. The items config as well as the binding config.

michal_kornatowski75 · May 25, 2016, 9:10pm

Solved,
forgot to add - caldavPersonal:usedCalendars=openhab_tasks

Big thanks one more time

JohnnyX · June 5, 2016, 4:20pm

@querdenker2k
How are appointment series handled in that binding? I created in outlook an appointment series (daily, duration is 1 hour, no end date) but it will never be executed. In my logfile I can see the following error:

2016-06-05 18:07:45.951 [ERROR] [o.o.i.c.i.job.EventReloaderJob] - error while loading calendar entries: www.google.com
java.net.UnknownHostException: www.google.com
	at java.net.Inet6AddressImpl.lookupAllHostAddr(Native Method) ~[na:1.8.0_91]
	at java.net.InetAddress$2.lookupAllHostAddr(Unknown Source) ~[na:1.8.0_91]
	at java.net.InetAddress.getAddressesFromNameService(Unknown Source) ~[na:1.8.0_91]
	at java.net.InetAddress.getAllByName0(Unknown Source) ~[na:1.8.0_91]
	at java.net.InetAddress.getAllByName(Unknown Source) ~[na:1.8.0_91]
	at java.net.InetAddress.getAllByName(Unknown Source) ~[na:1.8.0_91]
	at org.apache.http.impl.conn.SystemDefaultDnsResolver.resolve(SystemDefaultDnsResolver.java:44) ~[na:na]
	at org.apache.http.impl.conn.HttpClientConnectionOperator.connect(HttpClientConnectionOperator.java:101) ~[na:na]
	at org.apache.http.impl.conn.PoolingHttpClientConnectionManager.connect(PoolingHttpClientConnectionManager.java:318) ~[na:na]
	at org.apache.http.impl.execchain.MainClientExec.establishRoute(MainClientExec.java:363) ~[na:na]
	at org.apache.http.impl.execchain.MainClientExec.execute(MainClientExec.java:219) ~[na:na]
	at org.apache.http.impl.execchain.ProtocolExec.execute(ProtocolExec.java:195) ~[na:na]
	at org.apache.http.impl.execchain.RetryExec.execute(RetryExec.java:86) ~[na:na]
	at org.apache.http.impl.execchain.RedirectExec.execute(RedirectExec.java:108) ~[na:na]
	at org.apache.http.impl.client.InternalHttpClient.doExecute(InternalHttpClient.java:184) ~[na:na]
	at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:72) ~[na:na]
	at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:214) ~[na:na]
	at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:160) ~[na:na]
	at com.github.sardine.impl.SardineImpl.execute(SardineImpl.java:962) ~[na:na]
	at com.github.sardine.impl.SardineImpl.list(SardineImpl.java:417) ~[na:na]
	at com.github.sardine.impl.SardineImpl.list(SardineImpl.java:409) ~[na:na]
	at com.github.sardine.impl.SardineImpl.list(SardineImpl.java:386) ~[na:na]
	at org.openhab.io.caldav.internal.job.EventReloaderJob.loadEvents(EventReloaderJob.java:217) ~[na:na]
	at org.openhab.io.caldav.internal.job.EventReloaderJob.execute(EventReloaderJob.java:118) ~[na:na]
	at org.quartz.core.JobRunShell.run(JobRunShell.java:213) [quartz-all-2.1.7.jar:na]
	at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:557) [quartz-all-2.1.7.jar:na]

I’m still using OH 1.8.2

Thanks & Regards
John

P.S: I hope my question is not a kind of hijacking of this thread…

querdenker2k · June 5, 2016, 6:48pm

Looks like your DNS is not working. Can you ping www.Google.com?

JohnnyX · June 7, 2016, 8:26am

Just tried, see result:

C:\OH>ping google.com

Ping wird ausgefhrt fr google.com [172.217.16.142] mit 32 Bytes Daten:
Antwort von 172.217.16.142: Bytes=32 Zeit=8ms TTL=57
Antwort von 172.217.16.142: Bytes=32 Zeit=8ms TTL=57
Antwort von 172.217.16.142: Bytes=32 Zeit=7ms TTL=57
Antwort von 172.217.16.142: Bytes=32 Zeit=8ms TTL=57

Ping-Statistik fr 172.217.16.142:
Pakete: Gesendet = 4, Empfangen = 4, Verloren = 0
(0% Verlust),
Ca. Zeitangaben in Millisek.:
Minimum = 7ms, Maximum = 8ms, Mittelwert = 7ms

querdenker2k · June 7, 2016, 6:54pm

Can you post your config please and can you try this as well:

-Djava.net.preferIPv4Stack=true

Add this as a start parameter for openHAB.
Can you do a wget with the url given in your config and post what you get.

JohnnyX · June 13, 2016, 2:32pm

Done. I’m still getting the following error:

2016-06-13 16:21:30.787 [ERROR] [o.o.i.c.i.job.EventReloaderJob] - error while loading calendar entries: Unexpected response
com.github.sardine.impl.SardineException: Unexpected response
	at com.github.sardine.impl.handler.ValidatingResponseHandler.validateResponse(ValidatingResponseHandler.java:48) ~[na:na]
	at com.github.sardine.impl.handler.MultiStatusResponseHandler.handleResponse(MultiStatusResponseHandler.java:40) ~[na:na]
	at com.github.sardine.impl.handler.MultiStatusResponseHandler.handleResponse(MultiStatusResponseHandler.java:35) ~[na:na]
	at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:218) ~[na:na]
	at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:160) ~[na:na]
	at com.github.sardine.impl.SardineImpl.execute(SardineImpl.java:962) ~[na:na]
	at com.github.sardine.impl.SardineImpl.list(SardineImpl.java:417) ~[na:na]
	at com.github.sardine.impl.SardineImpl.list(SardineImpl.java:409) ~[na:na]
	at com.github.sardine.impl.SardineImpl.list(SardineImpl.java:386) ~[na:na]
	at org.openhab.io.caldav.internal.job.EventReloaderJob.loadEvents(EventReloaderJob.java:217) ~[na:na]
	at org.openhab.io.caldav.internal.job.EventReloaderJob.execute(EventReloaderJob.java:118) ~[na:na]
	at org.quartz.core.JobRunShell.run(JobRunShell.java:213) [quartz-all-2.1.7.jar:na]
	at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:557) [quartz-all-2.1.7.jar:na]

My config:
########################### calDAV Persistence Service ##################################
# Every item which is stored, results in an event entry in the defined calendar
#
# Calendar ID, which is defined in calDAV IO section
caldav-persistence:calendarId=smarthome
#
# Default duration for an calendar entry is 5 minutes
caldav-persistence:duration=5
#
# For Switch-, Contact- and Percent-Items it is possible to create events,
# with the correct duration for e. g. Switch ON to Switch OFF, otherwise every item change
# will result in a new single calendar entry.
caldav-persistence:singleEvents=true
################################### CalDAV IO Binding ###################################
#
# Used to connect to Cal DAV. All parameters are required.
# Path to the calendar
caldavio:smarthome:url=https://www.google.com/calendar/dav/xxxx.xxxx@gmail.com/events
#
# Username for the calendar
caldavio:smarthome:username=xxxx.xxxx@gmail.com
#
# Password for the calendar
caldavio:smarthome:password=XXXXXXXXXX
#
# Reload interval unit is minutes.
# Defines how often the calendar should be reloaded from server.
# Default is 60 minutes
caldavio:smarthome:reloadInterval=10
#
# This defines which events are relevant for execution. Unit is in minutes.
# Default is 1 Day (1440 minutes)
caldavio:smarthome:preloadTime=20000
#
# A caldav Server is just a webdav Server which list files. Some servers does not use the valid timestamp for modifications.
# If your calendar does not provide correct timestamps you have to set this false.
# Default is true
# caldavio:smarthome:lastModifiedFileTimeStampValid=false
#
# SSL verification can be disabled, if you don’t want to import the server certificate
# into the java keystore. This is just needed for self-signed certificates, where the
# certificate path cannot be verified. Default is false. Do not set to true if no SSL is used.
# caldavio:smarthome:disableCertificateVerification=
#
# Timezone for events which does not have a timeZone information.
# Normally this is not required
# caldavio:timeZone=Berlin
################################ CalDAV Command Binding ############################
# see CalDAV IO Binding
# Used to execute commands if events starts or ends with an easy notation in the event description.
# commaseperated (e. g. openhab, anothercalendar)
caldavCommand:readCalendars=smarthome
############################# CalDAV Personal Binding ################################
# see CalDAV IO Binding
# Used to toggle switch items for presence. Switched to ON if an event in the calendar occurs.
# And back to OFF if the event ends.
# Can also be used to show upcoming or active events
#
# Which calendars should be used to detect presence (comma separated)
caldavPersonal:usedCalendars=smarthome
#
# If the location of the event is one of this identifiers, the presence will not be changed.
# Can be used for events which are at home or are just reminders. (comma separated, optional)
caldavPersonal:homeIdentifiers=smarthome

I don’t know what a “wget” is, I guess this is a linux command → I’m using a windows machine. Any Idea how I can get your desired information there?

Thanks & Regards
John

querdenker2k · June 18, 2016, 5:25am

Your username should be xxxx.xxxx, not xxxx.xxxx@gmail.com

Just enter the url in the browser and enter your credentials in the upcoming window, check if you’re getting a download.

JohnnyX · June 21, 2016, 6:08pm

Seems to be that it is working now
The issue had two parts:

the above mentioned username problem and
there was something wrong with the password. After setting a new password the CalDav binding is now working very well.

Thank you for your effort and your support

thucke · July 6, 2016, 7:02pm

Hi querdenker2k,

I’m using your snapshot version 1.9.0 connecting Google calendar via OAuth - works quiet well, thank you so far.
No I stumbled upon a potential issue which I would like asking you for a check.

I got the following item configured:
String googleSmartHomeCalAlarm2 "Kalender Müllabfuhrtermin [%s]" <calendar> { caldavPersonal="calendar:GoogleSmarthomeCal type:upcoming eventNr:1 value:NAMEANDTIME filter-name:'Muell'" }

Obviously the filter-name does not do anything.
Looking into the trace would comfirm this guess:

2016-07-06 20:52:26.472 [TRACE] [.c.i.CalDavBindingProviderImpl] - handling config: calendar:GoogleSmarthomeCal type:upcoming eventNr:1 value:NAMEANDTIME filter-name:'Muell' 2016-07-06 20:52:26.476 [TRACE] [.c.i.CalDavBindingProviderImpl] - handling config part: calendar:GoogleSmarthomeCal 2016-07-06 20:52:26.476 [TRACE] [.c.i.CalDavBindingProviderImpl] - handling config part: type:upcoming 2016-07-06 20:52:26.477 [TRACE] [.c.i.CalDavBindingProviderImpl] - handling config part: eventNr:1 2016-07-06 20:52:26.478 [TRACE] [.c.i.CalDavBindingProviderImpl] - handling config part: value:NAMEANDTIME 2016-07-06 20:52:26.479 [TRACE] [.c.i.CalDavBindingProviderImpl] - handling config part: filter-name:'Muell' 2016-07-06 20:52:26.480 [TRACE] [.c.i.CalDavBindingProviderImpl] - found values: calendar=[GoogleSmarthomeCal], type=upcoming, eventNr=1, value=NAMEANDTIME

Additionally I doubt that german umlauts are not respected.
Looking at CalDavProviderImpl - sources I found the following definition:
private static final String REGEX_FILTER_NAME = "filter-name:'?([A-Za-z\\.\\*\\+\\- \\|]+)'?";

https://regex101.com/ is telling me an error in that definition.
The correct one would be
filter-name:'?([A-Za-z\\.\\*\\+\\\- \\|]+)'?
Anyway, checking this against strings containing umlauts won’t hit the whole word.

Thank you a lot for your support!
Thomas

thucke · September 5, 2016, 6:29pm

Hi @querdenker2k,

just let me again address my issue of post #37.
Is there any updated version of the plugin avaiable?

Thank you
Thomas

querdenker2k · September 5, 2016, 7:25pm

Now…
https://ufile.io/4b024
The Regex is correct for Java Syntax.

thucke · September 5, 2016, 7:54pm

That’s it - thank you a lot!