Caldav google calendar problem

According to another discussion with @querdenker2k in the German KNX forum about this binding it was mentioned that OAuth isn’t yet implemented. But maybe Robert can answer this question better…

It’s not implemented yet and not really planned. My problem is, that Google is the only caldav server which uses OAuth. I don’t really know if this is standardized or is it proprietary?

How many people are using the Google Calendar and are interessted in using the preferred OAuth API for this (because the old one will be turned off)?

+1.

+1!

Ok. I tested it a litte bit. Can somebody of you test it “really”. I am not using the Google calendar.

io binding

Description for getting client id

caldavio:openhab_tasks:url=https://apidata.googleusercontent.com/caldav/v2/address@gmail.com/events
caldavio:openhab_tasks:oauth=true
# client_id for OAuth
caldavio:openhab_tasks:username=client-id-a-very-long-value
# client_secret for OAuth
caldavio:openhab_tasks:password=a-little-bit-shorter
caldavio:openhab_tasks:reloadInterval=30
caldavio:openhab_tasks:preloadTime=10080

caldavio:timeZone=Europe/Berlin

After you started the binding first you have to authorize openhab to access your calendar.
Therefore this log entries occur in the logfile with log-level warn

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

Hi querdenker2k,
in my installation i replaced the file org.openhab.io.caldav-1.8.0.jar with yours.
I also created a project in google and a new OAuth credential account to access the calendar.

Loglevel has been raised to DEBUG by <logger name="org.openhab.io.caldav" level="DEBUG" />

It’s a bit weird that I neither get any error or exception nor OpenHAB shows up any upcomig event.

Those items are defined:
String GoogleCalName1 "Termine [%s]" <calendar> { caldavPersonal="calendar:SmartHome type:EVENT eventNr:1 value:NAME" } DateTime GoogleCalTime1 "Beginn [%1$tT, %1$td.%1$tm.%1$tY]" <calendar> { caldavPersonal="calendar:SmartHome type:EVENT eventNr:1 value:START" }

featuring the following sitemap entries:
Frame { Text item=GoogleCalName1 Text item=GoogleCalTime1 }

The logfile only comes up showing this:
2016-04-26 20:13:59.041 [DEBUG] [o.o.i.c.i.job.EventReloaderJob] - reload cached events for config: openhab_tasks 2016-04-26 20:13:59.250 [DEBUG] [o.o.i.c.i.job.EventReloaderJob] - loading events for config: openhab_tasks

In your post it’s not clear to me, which information should be configured to make it work.
After creating the new OAuth credential I’ve been provided downloading a JSON file:
{ "type": "service_account", "project_id": "myProjectId", "private_key_id": "1234567890123456789012345678901234567890", "private_key": "-----BEGIN PRIVATE KEY-----\n<private key>\n-----END PRIVATE KEY-----\n", "client_email": "client@myProjectId.iam.gserviceaccount.com", "client_id": "123456789012345678901", "auth_uri": "https://accounts.google.com/o/oauth2/auth", "token_uri": "https://accounts.google.com/o/oauth2/token", "auth_provider_x509_cert_url": "https://www.googleapis.com/oauth2/v1/certs", "client_x509_cert_url": "https://www.googleapis.com/robot/v1/metadata/x509/....... }

Later entry in the log:
2016-04-26 20:43:59.948 [DEBUG] [o.o.i.c.i.job.EventReloaderJob] - loading events for config: openhab_tasks 2016-04-26 20:49:31.740 [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]

Is ssl enabled in configuration. Can you please post your complete configuration.

Hi, I have similar problem.

I suppose that is some mistake in config, but I cannot find it.

//ADDONS
org.openhab.binding.caldav-personal-1.8.2.jar
org.openhab.io.caldav-1.8.2.jar

.CFG
caldavio:tasks:url=https://www.google.com/calendar/dav/usrname@gmail.com/events
caldavio:tasks:username=usrname@gmail.com
caldavio:tasks:password=passwd
caldavio:tasks:reloadInterval=15
caldavio:tasks:preloadTime=20000

.ITEMS
String KalendarzN1 “Name [%s]” {caldavPersonal=“calendar:tasks type:ACTIVE eventNr:1 value:NAME” }
String KalendarzP1 “Place [%s]” {caldavPersonal=“calendar:tasks type:ACTIVE eventNr:1 value:PLACE” }
DateTime KalendarzS1 “Start [%1$tT, %1$td.%1$tm.%1$tY]” {caldavPersonal=“calendar:tasks type:ACTIVE eventNr:1 value:START” }
DateTime KalendarzE1 “END [%1$tT, %1$td.%1$tm.%1$tY]” {caldavPersonal=“calendar:tasks type:UPCOMING eventNr:1 value:END” }

.LOG
2016-05-08 00:29:15.766 [INFO ] [.service.AbstractActiveService] - CalDav Loader has been started
2016-05-08 00:29:15.829 [INFO ] [.i.c.internal.CalDavLoaderImpl] - reload job scheduled for: tasks
2016-05-08 00:29:29.369 [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]

Any ideas where is mistake

Can you please enable TRACE logging and post it. The ERROR and the previous 5 lines should be enough.

It looks like no entry, but if I download *.ics file there are a lot of entries

2016-05-08 11:35:32.981 [DEBUG] [.c.i.CalDavBindingProviderImpl] - adding item: KalendarzS3
2016-05-08 11:35:32.997 [TRACE] [.c.i.CalDavBindingProviderImpl] - handling config: calendar:tasks type:UPCOMING eventNr:2 value:END
2016-05-08 11:35:32.997 [TRACE] [.c.i.CalDavBindingProviderImpl] - handling config part: calendar:tasks
2016-05-08 11:35:32.997 [TRACE] [.c.i.CalDavBindingProviderImpl] - handling config part: type:UPCOMING
2016-05-08 11:35:32.997 [TRACE] [.c.i.CalDavBindingProviderImpl] - handling config part: eventNr:2
2016-05-08 11:35:32.997 [TRACE] [.c.i.CalDavBindingProviderImpl] - handling config part: value:END
2016-05-08 11:35:32.997 [TRACE] [.c.i.CalDavBindingProviderImpl] - found values: calendar=[tasks], type=UPCOMING, eventNr=2, value=END
2016-05-08 11:35:33.012 [DEBUG] [.c.i.CalDavBindingProviderImpl] - adding item: KalendarzE3
2016-05-08 11:35:33.184 [DEBUG] [o.o.b.c.internal.CalDavBinding] - setting CalDavLoader: true
2016-05-08 11:35:33.199 [DEBUG] [o.o.b.c.internal.CalDavBinding] - CalDavBinding (personal) activated
2016-05-08 11:35:33.199 [DEBUG] [o.o.b.c.internal.CalDavBinding] - loading configuration…
2016-05-08 11:35:33.199 [DEBUG] [o.o.b.c.internal.CalDavBinding] - loading configuration done
2016-05-08 11:35:33.199 [TRACE] [o.o.b.c.internal.CalDavBinding] - reloading events
2016-05-08 11:35:33.199 [DEBUG] [o.o.b.c.internal.CalDavBinding] - calendar reloaded: tasks
2016-05-08 11:35:33.215 [DEBUG] [o.o.b.c.internal.CalDavBinding] - no event found for KalendarzP2, setting to UNDEF
2016-05-08 11:35:33.215 [DEBUG] [o.o.b.c.internal.CalDavBinding] - no event found for KalendarzN1, setting to UNDEF
2016-05-08 11:35:33.215 [DEBUG] [o.o.b.c.internal.CalDavBinding] - no event found for KalendarzP3, setting to UNDEF
2016-05-08 11:35:33.215 [DEBUG] [o.o.b.c.internal.CalDavBinding] - no event found for KalendarzN2, setting to UNDEF
2016-05-08 11:35:33.231 [DEBUG] [o.o.b.c.internal.CalDavBinding] - no event found for KalendarzN3, setting to UNDEF
2016-05-08 11:35:33.231 [DEBUG] [o.o.b.c.internal.CalDavBinding] - no event found for KalendarzS3, setting to UNDEF
2016-05-08 11:35:33.246 [DEBUG] [o.o.b.c.internal.CalDavBinding] - no event found for KalendarzE3, setting to UNDEF

2016-05-08 11:35:46.023 [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]
2016-05-08 11:37:59.980 [ERROR] [o.u.i.items.ItemUIRegistryImpl] - Cannot retrieve item KalentarzS1 for widget org.openhab.model.sitemap.Text
2016-05-08 11:37:59.980 [ERROR] [o.u.i.items.ItemUIRegistryImpl] - Cannot retrieve item KalentarzS1 for widget org.openhab.model.sitemap.Text

Hi querdenker2k,

sorry for the delay.
I kept on struggling myself facing the issue :wink:
Now from scratch and hopefully featuring all information you need.

This is my current configuration:

caldavio:openhab_tasks:url=https://apidata.googleusercontent.com/caldav/v2/ caldenderId from Goggle /events
caldavio:openhab_tasks:oauth=true
caldavio:openhab_tasks:reloadInterval=5
caldavio:openhab_tasks:preloadTime=10080
caldavio:openhab_tasks:disableCertificateVerification=true

client_id for OAuth

caldavio:openhab_tasks:username=field client_email from Googles-Serviceaccount-JSON
caldavio:openhab_tasks:password=field private_key_id from Googles-Serviceaccount-JSON
caldavPersonal:usedCalendars=openhab_tasks

This results in the following error message:

2016-05-10 18:40:13.593 [DEBUG] [o.o.i.c.i.job.EventReloaderJob] - loading events for config: openhab_tasks
2016-05-10 18:40:13.823 [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]

Looking forward your feedback. I stand by trying myself on that topic.

Thank you a lot for your support
Thomas

Oh my god - what a fool I am …
Sorry Querdenker2k - I made my former test using the 1.8.2 version of the file org.openhab.io.caldav.
After switching to your version 1.9.0 the there seem to be a memory leak. Look at the stack trace.
After the instance has been started alle seem to be good:

2016-05-10 20:55:22.994 [TRACE] [.c.i.CalDavBindingProviderImpl] - handling config: calendar:openhab_tasks type:EVENT eventNr:1 value:NAME
2016-05-10 20:55:22.995 [TRACE] [.c.i.CalDavBindingProviderImpl] - handling config part: calendar:openhab_tasks
2016-05-10 20:55:23.012 [TRACE] [.c.i.CalDavBindingProviderImpl] - handling config part: type:EVENT
2016-05-10 20:55:23.014 [TRACE] [.c.i.CalDavBindingProviderImpl] - handling config part: eventNr:1
2016-05-10 20:55:23.022 [TRACE] [.c.i.CalDavBindingProviderImpl] - handling config part: value:NAME
2016-05-10 20:55:23.023 [TRACE] [.c.i.CalDavBindingProviderImpl] - found values: calendar=[openhab_tasks], type=EVENT, eventNr=1, value=NAME
2016-05-10 20:55:23.038 [TRACE] [.i.c.internal.CalDavLoaderImpl] - starting execution…
2016-05-10 20:55:23.064 [DEBUG] [.c.i.CalDavBindingProviderImpl] - adding item: GoogleCalName1
2016-05-10 20:55:23.067 [TRACE] [.c.i.CalDavBindingProviderImpl] - handling config: calendar:openhab_tasks type:EVENT eventNr:1 value:START
2016-05-10 20:55:23.068 [TRACE] [.c.i.CalDavBindingProviderImpl] - handling config part: calendar:openhab_tasks
2016-05-10 20:55:23.069 [TRACE] [.c.i.CalDavBindingProviderImpl] - handling config part: type:EVENT
2016-05-10 20:55:23.076 [TRACE] [.c.i.CalDavBindingProviderImpl] - handling config part: eventNr:1
2016-05-10 20:55:23.077 [TRACE] [.c.i.CalDavBindingProviderImpl] - handling config part: value:START
2016-05-10 20:55:23.079 [TRACE] [.c.i.CalDavBindingProviderImpl] - found values: calendar=[openhab_tasks], type=EVENT, eventNr=1, value=START
2016-05-10 20:55:23.080 [DEBUG] [.c.i.CalDavBindingProviderImpl] - adding item: GoogleCalTime1
2016-05-10 20:55:23.081 [TRACE] [.c.i.CalDavBindingProviderImpl] - handling config: calendar:webTom type:EVENT eventNr:1 value:NAME
2016-05-10 20:55:23.089 [TRACE] [.c.i.CalDavBindingProviderImpl] - handling config part: calendar:webTom
2016-05-10 20:55:23.091 [TRACE] [.c.i.CalDavBindingProviderImpl] - handling config part: type:EVENT
2016-05-10 20:55:23.102 [TRACE] [.c.i.CalDavBindingProviderImpl] - handling config part: eventNr:1
2016-05-10 20:55:23.105 [TRACE] [.c.i.CalDavBindingProviderImpl] - handling config part: value:NAME
2016-05-10 20:55:23.166 [INFO ] [.i.c.internal.CalDavLoaderImpl] - reload job scheduled for: openhab_tasks

Unfortunately already then no items will be found:

2016-05-10 20:55:23.893 [TRACE] [.i.c.internal.CalDavLoaderImpl] - quering events for filter: CalDavQuery [calendarIds=[openhab_tasks], from=2016-05-10T20:55:23.893+02:00, to=null, sort=ASCENDING, filterName=null]
2016-05-10 20:55:23.894 [DEBUG] [.i.c.internal.CalDavLoaderImpl] - return event list for CalDavQuery [calendarIds=[openhab_tasks], from=2016-05-10T20:55:23.893+02:00, to=null, sort=ASCENDING, filterName=null] with 0 entries
2016-05-10 20:55:23.899 [DEBUG] [o.o.b.c.internal.CalDavBinding] - no event found for GoogleCalName1, setting to UNDEF
2016-05-10 20:55:23.904 [DEBUG] [o.o.b.c.internal.CalDavBinding] - no event found for GoogleCalTime1, setting to UNDEF

The next entries are not really full of information:

2016-05-10 20:55:33.123 [DEBUG] [o.o.i.c.i.job.EventReloaderJob] - reload cached events for config: openhab_tasks
2016-05-10 20:55:33.166 [DEBUG] [o.o.i.c.i.job.EventReloaderJob] - loading events for config: openhab_tasks
2016-05-10 21:00:33.094 [DEBUG] [o.o.i.c.i.job.EventReloaderJob] - loading events for config: openhab_tasks
The last entry is the beginning of raising CPU usage in conjunction with memory allocation.
In this example after 18 minutes a stack trace occurred:

2016-05-10 21:18:08.064 [ERROR] [o.io.caldav.internal.OAuthUtil] - error accessing OAuth
java.net.SocketException: Broken pipe
at java.net.SocketOutputStream.socketWrite0(Native Method) ~[na:1.8.0_92]
at java.net.SocketOutputStream.socketWrite(SocketOutputStream.java:109) ~[na:1.8.0_92]
at java.net.SocketOutputStream.write(SocketOutputStream.java:153) ~[na:1.8.0_92]
at sun.security.ssl.OutputRecord.writeBuffer(OutputRecord.java:431) ~[na:1.8.0_92]
at sun.security.ssl.OutputRecord.write(OutputRecord.java:417) ~[na:1.8.0_92]
at sun.security.ssl.SSLSocketImpl.writeRecordInternal(SSLSocketImpl.java:876) ~[na:1.8.0_92]
at sun.security.ssl.SSLSocketImpl.writeRecord(SSLSocketImpl.java:847) ~[na:1.8.0_92]
at sun.security.ssl.SSLSocketImpl.writeRecord(SSLSocketImpl.java:717) ~[na:1.8.0_92]
at sun.security.ssl.Handshaker.sendChangeCipherSpec(Handshaker.java:1077) ~[na:1.8.0_92]
at sun.security.ssl.ClientHandshaker.sendChangeCipherAndFinish(ClientHandshaker.java:1222) ~[na:1.8.0_92]
at sun.security.ssl.ClientHandshaker.serverHelloDone(ClientHandshaker.java:1134) ~[na:1.8.0_92]
at sun.security.ssl.ClientHandshaker.processMessage(ClientHandshaker.java:348) ~[na:1.8.0_92]
at sun.security.ssl.Handshaker.processLoop(Handshaker.java:979) ~[na:1.8.0_92]
at sun.security.ssl.Handshaker.process_record(Handshaker.java:914) ~[na:1.8.0_92]
at sun.security.ssl.SSLSocketImpl.readRecord(SSLSocketImpl.java:1062) ~[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.requestAccess(OAuthUtil.java:34) [bundlefile:na]
at org.openhab.io.caldav.internal.OAuthUtil.getCalendars(OAuthUtil.java:131) [bundlefile:na]
… 993 times
2016-05-10 21:18:30.774 [ERROR] [org.quartz.core.JobRunShell ] - Job event-reloader.openhab_tasks threw an unhandled Exception:
java.lang.OutOfMemoryError: Java heap space
at java.util.Arrays.copyOf(Arrays.java:3332) ~[na:1.8.0_92]
at java.lang.AbstractStringBuilder.expandCapacity(AbstractStringBuilder.java:137) ~[na:1.8.0_92]
at java.lang.AbstractStringBuilder.ensureCapacityInternal(AbstractStringBuilder.java:121) ~[na:1.8.0_92]
at java.lang.AbstractStringBuilder.append(AbstractStringBuilder.java:421) ~[na:1.8.0_92]
at java.lang.StringBuilder.append(StringBuilder.java:136) ~[na:1.8.0_92]
at ch.qos.logback.classic.pattern.ThrowableProxyConverter.subjoinThrowableProxy(ThrowableProxyConverter.java:167) ~[ch.qos.logback.classic_1.0.7.v20121108-1250.jar:na]
at ch.qos.logback.classic.pattern.ThrowableProxyConverter.throwableProxyToString(ThrowableProxyConverter.java:144) ~[ch.qos.logback.classic_1.0.7.v20121108-1250.jar:na]
at ch.qos.logback.classic.pattern.ThrowableProxyConverter.convert(ThrowableProxyConverter.java:137) ~[ch.qos.logback.classic_1.0.7.v20121108-1250.jar:na]
at ch.qos.logback.classic.pattern.ThrowableProxyConverter.convert(ThrowableProxyConverter.java:35) ~[ch.qos.logback.classic_1.0.7.v20121108-1250.jar:na]
at ch.qos.logback.core.pattern.FormattingConverter.write(FormattingConverter.java:37) ~[ch.qos.logback.core_1.0.7.v20121108-1250.jar:na]
at ch.qos.logback.core.pattern.PatternLayoutBase.writeLoopOnConverters(PatternLayoutBase.java:119) ~[ch.qos.logback.core_1.0.7.v20121108-1250.jar:na]
at ch.qos.logback.classic.PatternLayout.doLayout(PatternLayout.java:168) ~[ch.qos.logback.classic_1.0.7.v20121108-1250.jar:na]
at ch.qos.logback.classic.PatternLayout.doLayout(PatternLayout.java:60) ~[ch.qos.logback.classic_1.0.7.v20121108-1250.jar:na]
at ch.qos.logback.core.encoder.LayoutWrappingEncoder.doEncode(LayoutWrappingEncoder.java:134) ~[ch.qos.logback.core_1.0.7.v20121108-1250.jar:na]
at ch.qos.logback.core.OutputStreamAppender.writeOut(OutputStreamAppender.java:188) ~[ch.qos.logback.core_1.0.7.v20121108-1250.jar:na]
at ch.qos.logback.core.FileAppender.writeOut(FileAppender.java:206) ~[ch.qos.logback.core_1.0.7.v20121108-1250.jar:na]
at ch.qos.logback.core.OutputStreamAppender.subAppend(OutputStreamAppender.java:212) ~[ch.qos.logback.core_1.0.7.v20121108-1250.jar:na]
at ch.qos.logback.core.rolling.RollingFileAppender.subAppend(RollingFileAppender.java:148) ~[ch.qos.logback.core_1.0.7.v20121108-1250.jar:na]
at ch.qos.logback.core.OutputStreamAppender.append(OutputStreamAppender.java:103) ~[ch.qos.logback.core_1.0.7.v20121108-1250.jar:na]
at ch.qos.logback.core.UnsynchronizedAppenderBase.doAppend(UnsynchronizedAppenderBase.java:88) ~[ch.qos.logback.core_1.0.7.v20121108-1250.jar:na]
at ch.qos.logback.core.spi.AppenderAttachableImpl.appendLoopOnAppenders(AppenderAttachableImpl.java:48) ~[ch.qos.logback.core_1.0.7.v20121108-1250.jar:na]
at ch.qos.logback.classic.Logger.appendLoopOnAppenders(Logger.java:280) ~[ch.qos.logback.classic_1.0.7.v20121108-1250.jar:na]
at ch.qos.logback.classic.Logger.callAppenders(Logger.java:267) ~[ch.qos.logback.classic_1.0.7.v20121108-1250.jar:na]
at ch.qos.logback.classic.Logger.buildLoggingEventAndAppend(Logger.java:449) ~[ch.qos.logback.classic_1.0.7.v20121108-1250.jar:na]
at ch.qos.logback.classic.Logger.filterAndLog_0_Or3Plus(Logger.java:403) ~[ch.qos.logback.classic_1.0.7.v20121108-1250.jar:na]
at ch.qos.logback.classic.Logger.error(Logger.java:566) ~[ch.qos.logback.classic_1.0.7.v20121108-1250.jar:na]
at org.openhab.io.caldav.internal.OAuthUtil.requestAccess(OAuthUtil.java:50) ~[na:na]
at org.openhab.io.caldav.internal.OAuthUtil.getCalendars(OAuthUtil.java:131) ~[na:na]
at org.openhab.io.caldav.internal.OAuthUtil.getCalendars(OAuthUtil.java:142) ~[na:na]
at org.openhab.io.caldav.internal.OAuthUtil.getCalendars(OAuthUtil.java:142) ~[na:na]
at org.openhab.io.caldav.internal.OAuthUtil.getCalendars(OAuthUtil.java:142) ~[na:na]
at org.openhab.io.caldav.internal.OAuthUtil.getCalendars(OAuthUtil.java:142) ~[na:na]
2016-05-10 21:18:30.794 [ERROR] [org.quartz.core.ErrorLogger ] - Job (event-reloader.openhab_tasks threw an exception.
org.quartz.SchedulerException: Job threw an unhandled exception.
at org.quartz.core.JobRunShell.run(JobRunShell.java:224) ~[quartz-all-2.1.7.jar:na]
at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:557) [quartz-all-2.1.7.jar:na]
java.lang.OutOfMemoryError: Java heap space
at java.util.Arrays.copyOf(Arrays.java:3332) ~[na:1.8.0_92]
at java.lang.AbstractStringBuilder.expandCapacity(AbstractStringBuilder.java:137) ~[na:1.8.0_92]
at java.lang.AbstractStringBuilder.ensureCapacityInternal(AbstractStringBuilder.java:121) ~[na:1.8.0_92]
at java.lang.AbstractStringBuilder.append(AbstractStringBuilder.java:421) ~[na:1.8.0_92]
at java.lang.StringBuilder.append(StringBuilder.java:136) ~[na:1.8.0_92]
at ch.qos.logback.classic.pattern.ThrowableProxyConverter.subjoinThrowableProxy(ThrowableProxyConverter.java:167) ~[ch.qos.logback.classic_1.0.7.v20121108-1250.jar:na]
at ch.qos.logback.classic.pattern.ThrowableProxyConverter.throwableProxyToString(ThrowableProxyConverter.java:144) ~[ch.qos.logback.classic_1.0.7.v20121108-1250.jar:na]
at ch.qos.logback.classic.pattern.ThrowableProxyConverter.convert(ThrowableProxyConverter.java:137) ~[ch.qos.logback.classic_1.0.7.v20121108-1250.jar:na]
at ch.qos.logback.classic.pattern.ThrowableProxyConverter.convert(ThrowableProxyConverter.java:35) ~[ch.qos.logback.classic_1.0.7.v20121108-1250.jar:na]
at ch.qos.logback.core.pattern.FormattingConverter.write(FormattingConverter.java:37) ~[ch.qos.logback.core_1.0.7.v20121108-1250.jar:na]
at ch.qos.logback.core.pattern.PatternLayoutBase.writeLoopOnConverters(PatternLayoutBase.java:119) ~[ch.qos.logback.core_1.0.7.v20121108-1250.jar:na]
at ch.qos.logback.classic.PatternLayout.doLayout(PatternLayout.java:168) ~[ch.qos.logback.classic_1.0.7.v20121108-1250.jar:na]
at ch.qos.logback.classic.PatternLayout.doLayout(PatternLayout.java:60) ~[ch.qos.logback.classic_1.0.7.v20121108-1250.jar:na]
at ch.qos.logback.core.encoder.LayoutWrappingEncoder.doEncode(LayoutWrappingEncoder.java:134) ~[ch.qos.logback.core_1.0.7.v20121108-1250.jar:na]
at ch.qos.logback.core.OutputStreamAppender.writeOut(OutputStreamAppender.java:188) ~[ch.qos.logback.core_1.0.7.v20121108-1250.jar:na]
at ch.qos.logback.core.FileAppender.writeOut(FileAppender.java:206) ~[ch.qos.logback.core_1.0.7.v20121108-1250.jar:na]
at ch.qos.logback.core.OutputStreamAppender.subAppend(OutputStreamAppender.java:212) ~[ch.qos.logback.core_1.0.7.v20121108-1250.jar:na]
at ch.qos.logback.core.rolling.RollingFileAppender.subAppend(RollingFileAppender.java:148) ~[ch.qos.logback.core_1.0.7.v20121108-1250.jar:na]
at ch.qos.logback.core.OutputStreamAppender.append(OutputStreamAppender.java:103) ~[ch.qos.logback.core_1.0.7.v20121108-1250.jar:na]
at ch.qos.logback.core.UnsynchronizedAppenderBase.doAppend(UnsynchronizedAppenderBase.java:88) ~[ch.qos.logback.core_1.0.7.v20121108-1250.jar:na]
at ch.qos.logback.core.spi.AppenderAttachableImpl.appendLoopOnAppenders(AppenderAttachableImpl.java:48) ~[ch.qos.logback.core_1.0.7.v20121108-1250.jar:na]
at ch.qos.logback.classic.Logger.appendLoopOnAppenders(Logger.java:280) ~[ch.qos.logback.classic_1.0.7.v20121108-1250.jar:na]
at ch.qos.logback.classic.Logger.callAppenders(Logger.java:267) ~[ch.qos.logback.classic_1.0.7.v20121108-1250.jar:na]
at ch.qos.logback.classic.Logger.buildLoggingEventAndAppend(Logger.java:449) ~[ch.qos.logback.classic_1.0.7.v20121108-1250.jar:na]
at ch.qos.logback.classic.Logger.filterAndLog_0_Or3Plus(Logger.java:403) ~[ch.qos.logback.classic_1.0.7.v20121108-1250.jar:na]
at ch.qos.logback.classic.Logger.error(Logger.java:566) ~[ch.qos.logback.classic_1.0.7.v20121108-1250.jar:na]
at org.openhab.io.caldav.internal.OAuthUtil.requestAccess(OAuthUtil.java:50) ~[na:na]
at org.openhab.io.caldav.internal.OAuthUtil.getCalendars(OAuthUtil.java:131) ~[na:na]
at org.openhab.io.caldav.internal.OAuthUtil.getCalendars(OAuthUtil.java:142) ~[na:na]
at org.openhab.io.caldav.internal.OAuthUtil.getCalendars(OAuthUtil.java:142) ~[na:na]
at org.openhab.io.caldav.internal.OAuthUtil.getCalendars(OAuthUtil.java:142) ~[na:na]
at org.openhab.io.caldav.internal.OAuthUtil.getCalendars(OAuthUtil.java:142) ~[na:na]
2016-05-10 21:18:31.652 [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.requestAccess(OAuthUtil.java:51) ~[na:na]
at org.openhab.io.caldav.internal.OAuthUtil.getCalendars(OAuthUtil.java:142) ~[na:na]
… 1023 times
Caused by: java.net.SocketException: Broken pipe
at java.net.SocketOutputStream.socketWrite0(Native Method) ~[na:1.8.0_92]
at java.net.SocketOutputStream.socketWrite(SocketOutputStream.java:109) ~[na:1.8.0_92]
at java.net.SocketOutputStream.write(SocketOutputStream.java:153) ~[na:1.8.0_92]
at sun.security.ssl.OutputRecord.writeBuffer(OutputRecord.java:431) ~[na:1.8.0_92]
at sun.security.ssl.OutputRecord.write(OutputRecord.java:417) ~[na:1.8.0_92]
at sun.security.ssl.SSLSocketImpl.writeRecordInternal(SSLSocketImpl.java:876) ~[na:1.8.0_92]
at sun.security.ssl.SSLSocketImpl.writeRecord(SSLSocketImpl.java:847) ~[na:1.8.0_92]
at sun.security.ssl.SSLSocketImpl.writeRecord(SSLSocketImpl.java:717) ~[na:1.8.0_92]
at sun.security.ssl.Handshaker.sendChangeCipherSpec(Handshaker.java:1077) ~[na:1.8.0_92]
at sun.security.ssl.ClientHandshaker.sendChangeCipherAndFinish(ClientHandshaker.java:1222) ~[na:1.8.0_92]
at sun.security.ssl.ClientHandshaker.serverHelloDone(ClientHandshaker.java:1134) ~[na:1.8.0_92]
at sun.security.ssl.ClientHandshaker.processMessage(ClientHandshaker.java:348) ~[na:1.8.0_92]
at sun.security.ssl.Handshaker.processLoop(Handshaker.java:979) ~[na:1.8.0_92]
at sun.security.ssl.Handshaker.process_record(Handshaker.java:914) ~[na:1.8.0_92]
at sun.security.ssl.SSLSocketImpl.readRecord(SSLSocketImpl.java:1062) ~[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.requestAccess(OAuthUtil.java:34) ~[na:na]
at org.openhab.io.caldav.internal.OAuthUtil.getCalendars(OAuthUtil.java:131) ~[na:na]
… 992 common frames omitted
2016-05-10 21:18:31.700 [DEBUG] [o.o.b.c.internal.CalDavBinding] - calendar reloaded: openhab_tasks

Tried it also with caldavio:openhab_tasks:disableCertificateVerification=false which results in a Java heap space exception

How many events do you have in your calendar? 100? 1000? 10000?
The error occurs after 5 minutes and you are reloading every 5 minutes? So the error occurs after the first reload?

It was only 1 event.
I newly created the calendar for OpenHab purposes.
Obviously you’re right. It seems that the first loading event does nothing whreas the second does anything but the intended.

Hi querdenker2k, thanks for your help
Please look at my logs, It’s enough, or I can do some more to clarify better my problem?

Can you please check if your first event does not have an uid or a summary?
Or have you not set TRACE logging for caldavio?

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

implementation is ongoing… needs some time…

1 Like

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