[caldav] Binding always uses old entries from Google calender

Bredmich · January 3, 2019, 3:46pm

Yes, i already tried that.
Is there any beta version for a newer caldav binding?
The bindings i have installed are version 1.12.0.

H102 · January 3, 2019, 3:50pm

There is a 1.14.0 for caldav personal.
https://openhab.jfrog.io/openhab/libs-pullrequest-local/org/openhab/binding/org.openhab.binding.caldav-personal/

And caldev command 1.14.0 here.
https://openhab.jfrog.io/openhab/libs-pullrequest-local/org/openhab/binding/org.openhab.binding.caldav-command/

Bredmich · January 3, 2019, 4:00pm

Ok that seems to be a solution!

Uninstall caldav bindings through PapierUI
Stop openHAB service -> sudo service openhab2 stop
Clean the cache -> sudo openhab-cli clean-cache
Place the 1.14.0 bindings in the addons folder
Start openHAB again -> sudo service openhab2 start

The caldav binding needs the caldavio to work!
org.openhab.io.caldav
org.openhab.binding.caldav-command

After reloading every entry the correct entry for 05.01.2019 was choosed and is now correctly displayed.

@H102 Is there any central newsfeed to check if a new version for a binding is released as stable or snapshot?

kind regards
Michael

H102 · January 3, 2019, 4:09pm

Glad you got it working again.

If there is I’m not aware of it.

Bredmich · January 3, 2019, 10:28pm

I checked the source in Github and the 1.14.0 bindings doesn´t have any changes (atleast the one i´m using) and it´s just a preparation for the next development cycle.
The only way seems to set a watch on Github

H102 · January 5, 2019, 4:38pm

@Bredmich while reading a new topic I remembered your question above and thought I would share the info.

Bredmich · January 6, 2019, 3:37pm

Ok and it´s still hanging at the old entry for the 05.01.2019 instead of the new entry for 09.01.2019…

H102 · January 6, 2019, 3:43pm

Try removing the binding, cleaning the cache, and restarting OH without the binding installed. Also check to make sure there are no caldev.cfg file that still exist. Then stop OH and re-install the new jar.

Bredmich · January 6, 2019, 3:51pm

This will help but i don´t know if it´s help for the next event.
It´s not a nice workaround to always reinstall the binding just to get the new entry.

Anyway, i´ll try it later.

H102 · January 6, 2019, 3:53pm

Agreed.

If the old info is still lingering then as a last ditch attempt you can delete /var/lib/openhab2/config/org/openhab/addons.config so it is regenerated with correct content to see if that helps.

Bredmich · January 6, 2019, 6:48pm

I stopped openHAB, deleted the addons.config and started openHAB again.

addons.config before:

action="telegram,mail"
binding="astro,exec,fritzboxtr0641,http1,icloud,ntp,tado,yamahareceiver,zwave,homematic,expire1,weather1,hue"
legacy=B"true"
misc="restdocs,openhabcloud"
package="expert"
persistence=",jdbc-mysql"
remote=B"true"
service.pid="org.openhab.addons"
transformation="map,regex,xslt,exec,javascript,scale,xpath,jsonpath"
ui="classic,basic,paper,habpanel,habmin"

addons.config now:

package="expert"
service.pid="org.openhab.addons"

caldav is still using the old entry…

Bredmich · January 6, 2019, 10:26pm

I had another look at the logs and the caldav bindings imports every event in the calender.
I had the understanding that preloadTime=14400 will only import events that are due in the next 10 days.

@namraccr as @H102 already asked you in another thread.
Do you have any idea how to fix my caldav configuration?

kind regards
Michael

namraccr · January 6, 2019, 11:21pm

As far as I can tell, your config is fine. Have you tried deleting the cached calendar file?

Bredmich · January 6, 2019, 11:36pm

Yes i deleted single entries and the whole folder.
Currently the binding doesn‘t load any event into the items.

Bredmich · January 7, 2019, 12:21pm

Now caldav is throwing some exceptions…

2019-01-07 12:21:24.978 [ERROR] [org.quartz.core.JobRunShell         ] - Job event-reloader.Abfall threw an unhandled Exception: 
java.util.ServiceConfigurationError: net.fortuna.ical4j.model.PropertyFactory: Provider net.fortuna.ical4j.model.property.Action$Factory not a subtype
	at java.util.ServiceLoader.fail(ServiceLoader.java:239) ~[?:?]
	at java.util.ServiceLoader.access$300(ServiceLoader.java:185) ~[?:?]
	at java.util.ServiceLoader$LazyIterator.nextService(ServiceLoader.java:376) ~[?:?]
	at java.util.ServiceLoader$LazyIterator.access$700(ServiceLoader.java:323) ~[?:?]
	at java.util.ServiceLoader$LazyIterator$2.run(ServiceLoader.java:407) ~[?:?]
	at java.security.AccessController.doPrivileged(Native Method) ~[?:?]
	at java.util.ServiceLoader$LazyIterator.next(ServiceLoader.java:409) ~[?:?]
	at java.util.ServiceLoader$1.next(ServiceLoader.java:480) ~[?:?]
	at net.fortuna.ical4j.model.AbstractContentFactory.getFactory(AbstractContentFactory.java:85) ~[?:?]
	at net.fortuna.ical4j.model.PropertyFactoryImpl.createProperty(PropertyFactoryImpl.java:78) ~[?:?]
	at net.fortuna.ical4j.data.CalendarBuilder$ContentHandlerImpl.startProperty(CalendarBuilder.java:326) ~[?:?]
	at net.fortuna.ical4j.data.CalendarParserImpl$PropertyParser.parse(CalendarParserImpl.java:206) ~[?:?]
	at net.fortuna.ical4j.data.CalendarParserImpl$PropertyParser.access$1100(CalendarParserImpl.java:190) ~[?:?]
	at net.fortuna.ical4j.data.CalendarParserImpl$PropertyListParser.parse(CalendarParserImpl.java:173) ~[?:?]
	at net.fortuna.ical4j.data.CalendarParserImpl.parse(CalendarParserImpl.java:122) ~[?:?]
	at net.fortuna.ical4j.data.CalendarBuilder.build(CalendarBuilder.java:198) ~[?:?]
	at org.openhab.io.caldav.internal.job.EventReloaderJob.loadEvents(EventReloaderJob.java:339) ~[?:?]
	at org.openhab.io.caldav.internal.job.EventReloaderJob.loadEvents(EventReloaderJob.java:320) ~[?:?]
	at org.openhab.io.caldav.internal.job.EventReloaderJob.execute(EventReloaderJob.java:137) ~[?:?]
	at org.quartz.core.JobRunShell.run(JobRunShell.java:202) [107:org.eclipse.smarthome.core.scheduler:0.10.0.oh240]
	at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:573) [107:org.eclipse.smarthome.core.scheduler:0.10.0.oh240]
2019-01-07 12:21:25.047 [ERROR] [org.quartz.core.ErrorLogger         ] - Job (event-reloader.Abfall threw an exception.
org.quartz.SchedulerException: Job threw an unhandled exception.
	at org.quartz.core.JobRunShell.run(JobRunShell.java:213) [107:org.eclipse.smarthome.core.scheduler:0.10.0.oh240]
	at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:573) [107:org.eclipse.smarthome.core.scheduler:0.10.0.oh240]
Caused by: java.util.ServiceConfigurationError: net.fortuna.ical4j.model.PropertyFactory: Provider net.fortuna.ical4j.model.property.Action$Factory not a subtype
	at java.util.ServiceLoader.fail(ServiceLoader.java:239) ~[?:?]
	at java.util.ServiceLoader.access$300(ServiceLoader.java:185) ~[?:?]
	at java.util.ServiceLoader$LazyIterator.nextService(ServiceLoader.java:376) ~[?:?]
	at java.util.ServiceLoader$LazyIterator.access$700(ServiceLoader.java:323) ~[?:?]
	at java.util.ServiceLoader$LazyIterator$2.run(ServiceLoader.java:407) ~[?:?]
	at java.security.AccessController.doPrivileged(Native Method) ~[?:?]
	at java.util.ServiceLoader$LazyIterator.next(ServiceLoader.java:409) ~[?:?]
	at java.util.ServiceLoader$1.next(ServiceLoader.java:480) ~[?:?]
	at net.fortuna.ical4j.model.AbstractContentFactory.getFactory(AbstractContentFactory.java:85) ~[?:?]
	at net.fortuna.ical4j.model.PropertyFactoryImpl.createProperty(PropertyFactoryImpl.java:78) ~[?:?]
	at net.fortuna.ical4j.data.CalendarBuilder$ContentHandlerImpl.startProperty(CalendarBuilder.java:326) ~[?:?]
	at net.fortuna.ical4j.data.CalendarParserImpl$PropertyParser.parse(CalendarParserImpl.java:206) ~[?:?]
	at net.fortuna.ical4j.data.CalendarParserImpl$PropertyParser.access$1100(CalendarParserImpl.java:190) ~[?:?]
	at net.fortuna.ical4j.data.CalendarParserImpl$PropertyListParser.parse(CalendarParserImpl.java:173) ~[?:?]
	at net.fortuna.ical4j.data.CalendarParserImpl.parse(CalendarParserImpl.java:122) ~[?:?]
	at net.fortuna.ical4j.data.CalendarBuilder.build(CalendarBuilder.java:198) ~[?:?]
	at org.openhab.io.caldav.internal.job.EventReloaderJob.loadEvents(EventReloaderJob.java:339) ~[?:?]
	at org.openhab.io.caldav.internal.job.EventReloaderJob.loadEvents(EventReloaderJob.java:320) ~[?:?]
	at org.openhab.io.caldav.internal.job.EventReloaderJob.execute(EventReloaderJob.java:137) ~[?:?]
	at org.quartz.core.JobRunShell.run(JobRunShell.java:202) ~[?:?]
	... 1 more

This was and is a very bad idea!
If you installed all bindings through PaperUI, they get uninstalled when deleting the addons.config

Looks like there was an issue two years ago!

I´ve got no idea what the binding is doing…
Now it´s trying to find entries between now and null…

2019-01-07 14:03:14.331 [TRACE] [.io.caldav.internal.CalDavLoaderImpl] - Querying events for filter: CalDavQuery [calendarIds=[Abfall], from=2019-01-07T14:03:14.326+01:00, to=null, sort=ASCENDING, filterName=null]
2019-01-07 14:03:14.345 [DEBUG] [.io.caldav.internal.CalDavLoaderImpl] - return event list for CalDavQuery [calendarIds=[Abfall], from=2019-01-07T14:03:14.326+01:00, to=null, sort=ASCENDING, filterName=null] with 0 entries

Bredmich · January 7, 2019, 3:52pm

I played around with the console and figured out that the two bindings personal and command are not working together.
The io.caldav always started without a problem but then personal or command couldn´t start and printed a ton of errors.
The bindings were stuck in Waiting and doesn´t really started.
After stopping and uninstalling the caldav-command binding the caldav-personal started and directly worked through all events.
This solved the problem and the caldav-personal was able to choose the correct calender entry.

Now i´m waiting for the switch to the next entry…

namraccr · January 8, 2019, 12:53am

This is the usual behaviour.

namraccr · January 8, 2019, 3:24am

For example:

21:17:27.161 [TRACE] [b.io.caldav.internal.CalDavLoaderImpl] - Querying events for filter: CalDavQuery [calendarIds=[myCalendar], from=2019-01-07T21:17:27.161-05:00, to=null, sort=ASCENDING, filterName=null]
21:17:27.161 [TRACE] [b.io.caldav.internal.CalDavLoaderImpl] - processing filter category
21:17:27.161 [TRACE] [b.io.caldav.internal.CalDavLoaderImpl] - processing event category
21:17:27.161 [TRACE] [b.io.caldav.internal.CalDavLoaderImpl] - filter-category encountered
21:17:27.161 [DEBUG] [b.io.caldav.internal.CalDavLoaderImpl] - return event list for CalDavQuery [calendarIds=[myCalendar], from=2019-01-07T21:17:27.161-05:00, to=null, sort=ASCENDING, filterName=null] with 1 entries
21:17:27.161 [DEBUG] [.caldav.internal.job.EventReloaderJob] - jobs scheduled :
21:17:27.161 [DEBUG] [.caldav.internal.job.EventReloaderJob] - [job] : event-end-31irki5pjm939066eg0rm2m5d7@google.com(God Rest Ye Merry Gentlemen@08.01.2019/13:00-08.01.2019/13:30)-0 - [groupName] : event-end - Tue Jan 08 13:30:00 EST 2019
21:17:27.161 [DEBUG] [.caldav.internal.job.EventReloaderJob] - [job] : myCalendar - [groupName] : event-reloader - Mon Jan 07 23:17:19 EST 2019
21:17:27.161 [DEBUG] [.caldav.internal.job.EventReloaderJob] - [job] : event-start-31irki5pjm939066eg0rm2m5d7@google.com(God Rest Ye Merry Gentlemen@08.01.2019/13:00-08.01.2019/13:30)-0 - [groupName] : event-start - Tue Jan 08 13:00:00 EST 2019

Bredmich · January 8, 2019, 8:51am

Ok good to know.
I thought there should be a range of 10 days (for my configuration with 10 days preloadTime).

Could you may answer some questions/correct my assumptions regarding how the binding works.

The binding import all events from a given calender (past and future)
Afterwards it´s checking for events that are between now and the preloadTime
The first events will be stored and marked as eventNr:1
reloadInterval is the time between checks if there´s a new entry that wasn´t imported yet
How does the binding decide when to change the item to a new entry?
Then last thing is what´s currently not working as i think it should. The item is still at an old entry and the binding doesn´t load the next one as eventNr:1

kind regards
Michael

namraccr · January 8, 2019, 12:56pm

Based on what I’ve seen from using the binding, the first 4 bullets are true.
Generally I think past events are not loaded, but processed and skipped as historic.

The default preloadTime is 24 hours.

As an example, this refresh occurred at 23:17, and loaded events from 23:17 to 24 hours later:

2019-01-06 23:17:23.834 [DEBUG] [caldav.internal.job.EventReloaderJob] - loading events from file : etc\caldav\myCalendar\040000008200E00074C5B7101A82E0080000000050FA8BBB6CF1D101000000000000000010000000E7F6B6DF4F745149822E52A6B3266926.ics
2019-01-06 23:17:23.934 [TRACE] [caldav.internal.job.EventReloaderJob] - loadFrom = 2019-01-06T23:17:23.934-05:00
2019-01-06 23:17:23.934 [TRACE] [caldav.internal.job.EventReloaderJob] - loadTo = 2019-01-07T23:17:23.934-05:00

As to bullet 5, items should change when the scheduled event jobs are fired:

2019-01-06 23:17:30.377 [DEBUG] [.io.caldav.internal.CalDavLoaderImpl] - begin timer scheduled for event '50b9kr6mu1cqjtpkm9rofl6srt@google.com(We 3 kings@07.01.2019/10:00-07.01.2019/10:30)' @ Mon Jan 07 10:00:00 EST 2019

So an event should become current when it’s begin timer job runs.