Duplicate calendar events

AdamPS

Hi,
My Android Calendar database has duplicate events.

Android 6.0.1 Nexus 5X
DAVDroid 1.3-ose
Server: OwnCloud 9.1.0

I have opened calendar.db in an sqlite browser, and I see two rows that are identical, except for a different _id. For example, I have two rows with _sync_id = "a6b497f6-d828-4c53-ae91-3ba3d2184fd1.ics". In total I have approx 10-20% of my entries duplicated.
I have looked on the server and in clients on other platforms and there is only one entry.
When I sync, the matching entries in the log file are (full URLs replaced with XXXXXX for privacy):
2016-10-02 17:06:52 38 [syncadapter.SyncManager] Found local resource: a6b497f6-d828-4c53-ae91-3ba3d2184fd1.ics
2016-10-02 17:06:52 38 [syncadapter.SyncManager] Found local resource: a6b497f6-d828-4c53-ae91-3ba3d2184fd1.ics
<d:href>/XXXXXX/a6b497f6-d828-4c53-ae91-3ba3d2184fd1.ics</d:href>
2016-10-02 17:06:53 38 [dav4android.DavResource] Received <response> for XXXXXX/a6b497f6-d828-4c53-ae91-3ba3d2184fd1.ics
2016-10-02 17:06:53 38 [syncadapter.CalendarSyncManager] Found remote VEVENT: a6b497f6-d828-4c53-ae91-3ba3d2184fd1.ics
Net result of sync is that I still have two entries even though there is only one response in the log.
I don't have any knowledge of how the duplicate occurred in the first place, and I can't necessarily reproduce it. However I can sync as many times as I like and the duplicate entries remain. I guess that anyone else wanting to reproduce could hack their database.db to contain a duplicate.

Next steps:

It would be great if DAVdroid could be fixed automatically remove duplicate entries. Duplicates are characterised by a) identical ID b) only 1 response from server although 2 local entries.
I suspect my problem will go away if I can force a drop of the local database and complete reload. However I don't want to accidentally destroy all events on the server in the process. Please can anyone advise how to safely force a full sync?

Many thanks.

AdamPS

In the course of my testing I have accidentally discovered how to safely force a full sync.

I opened the DAVdroid app and clicked on my account. I unselected the calendar that had the bug, and then clicked to synchronize. I reselected the calendar and synchronized again.

This is a workaround rather than a proper fix. It would be great if DAVdroid could be fixed automatically remove duplicate entries.

rfc2822

@AdamPS Duplicate rows should never occur. It would be important to identity the circumstances which led to duplicate rows. I don't think handling duplicate rows is a good idea, because this would just hide other problems (which lead to duplication).

If you can reproduce the duplication in any way, please let us know.

AdamPS

Thanks for the reply.

OK I have some extra information for the duplicate events. My phone has two accounts set up with different names, but pointing to exactly the same account on the server. The reason for this set up is that it was the recommended way to connect to more than one CardDAV address book on the account.

On the second account, I disabled all the CalDAV calendars. However I expect that there was briefly a time when both accounts had the calendars enabled.

I have just tested enabling CalDAV on the second account also. I do see all the events twice in the database. The _sync_id is the same but the calendar ID is different. When I disable the CalDAV on the second account, the duplicates go away again. So this isn't a full explanation. However I suspect that the double account is a part of the cause of my duplicates.

I will post again if I see duplicates in future.

rfc2822

@AdamPS said in Duplicate calendar events:

I have just tested enabling CalDAV on the second account also. I do see all the events twice in the database. The _sync_id is the same but the calendar ID is different. When I disable the CalDAV on the second account, the duplicates go away again.

When the calendar ID is different, there's no problem, because the events are not really duplicate, but the CalDAV collection is just synchronized two times into different local calendars. Problems only occur in case of really duplicate entries, i.e when everything except the _id is identical.

cgogolin

I am experiencing the very same symptoms with davdroid and owncloud under LineageOS even though there was never more than one account setup in davdroid. I would like to examine the calendar.db, as AdamPS has done, to see whether I the duplicate entries also have the same ids in my case.

How can I get he calendar.db? I tried adb pull with debug mode enabled but get the following error:

$ adb pull /data/data/com.android.providers.calendar/databases/calendar.db calendar.db
adb: error: remote object '/data/data/com.android.providers.calendar/databases/calendar.db' does not exist

Maybe this is not the right location?

On top of this I can share some additional observations, which however only make the issue more mysterious, I fear:

We have two Samsung s4mini running the same version of LineageOS, both are synced to exactly one account on the same Owncloud server. The accounts are different, and each have their own calendars and also share some calendars. Only one of the devices is experiencing the issue. The issue persists even after Davdroid was completely uninstalled and reinstalled. For one of the shared calendars one of the devices shows duplicated entries, but on the other the very same entries appear only once.
Shortly before we switched both devices to LinearOS we already had the same issue on the device wich is not again experiencing it. We didn't bother too much because we knew we would anyway reinstall the whole system.
The Owncloud account of the device that has the issue is also synced to Thunderbird/lightning via Sogo connector, the one of the device without issues is synced to Evolution mail and another Android device. At first this seems to indicate a connection with Sogo connector, but then the observation with the shared calendar described above invalidates that conjecture. Only on the one affected s4mini are some entries duplicated, on all other devices (the second s4min, Evolution, and Thunderbird) the entries appear only once.
Unselecting the calendar, synchronizing, reselecting the calendar and synchronizing again does not solve the problem (neither does reinstalling Davdroid).

rfc2822

@cgogolin Did you do adb root before? It's only accessible as root user.

cgogolin

@rfc2822 Thanks! That worked. Now I have the file. As I am not an experienced sqlite user I made a dump and then searched the dump for one of the duplicate entries in the shared calendar (this is the most mysterious one).
I find the entry:

INSERT INTO "Events" VALUES(2681,'f2f58de4-83fc-4b5e-b03f-0513f0abceab.ics',0,NULL,0,9,'XXX',NULL,'XXX
XXX',NULL,NULL,NULL,0,1499830200000,1499880600000,'Europe/Madrid',NULL,0,0,0,0,0,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,1499880600000,1,0,1,1,'mail@manuelagogolin.net',NULL,0,'Europe/Madrid',NULL,NULL,'f2f58de4-83fc-4b5e-b03f-0513f0abceab','893767d7fe177c9eeb8524e7544071e4',NULL,'0',NULL,NULL,NULL,NULL,NULL,NULL,NULL);

and a little bit further down the almost identical entry

INSERT INTO "Events" VALUES(2761,'f2f58de4-83fc-4b5e-b03f-0513f0abceab.ics',0,NULL,0,9,'XXX',NULL,'XXX
XXX',NULL,NULL,NULL,0,1499830200000,1499880600000,'Europe/Madrid',NULL,0,0,0,0,0,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,1499880600000,1,0,1,1,'mail@manuelagogolin.net',NULL,0,'Europe/Madrid',NULL,NULL,'f2f58de4-83fc-4b5e-b03f-0513f0abceab','893767d7fe177c9eeb8524e7544071e4',NULL,'0',NULL,NULL,NULL,NULL,NULL,NULL,NULL);

As far as I can tell only the first entry in VALUES() differs.

rfc2822

@cgogolin Can you

unselect the calendar
sync again (so that everthing is gone)
then turn on verbose DAVdroid logging
select the calendar again
sync again and
then turn off the DAVdroid logs and post it here? If you don't want to anonymize your data, you can send it to play@bitfire.at (will be treated confidentially, PGP key on https://davdroid.bitfire.at) instead of posting it.

cgogolin

After the procedure You described other entries appear as duplicate (this was always the case, but I think I didn't mention this before). One entry that is now duplicated appears in the dump as

INSERT INTO "Events" VALUES(3161,'b133303f-f0d2-4cc9-a89b-cf4a49f5e003.ics',0,NULL,0,12,'XXX',NULL,NULL,NULL,NULL,NULL,0,1499709600000,1499727600000,'Europe/Madrid',NULL,0,0,0,0,0,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,1499727600000,1,0,1,1,'xxx@xxx.net',NULL,0,'Europe/Madrid',NULL,NULL,'b133303f-f0d2-4cc9-a89b-cf4a49f5e003','8165fd52278e63746e3da1f257ab6a2e',NULL,'0',NULL,NULL,NULL,NULL,NULL,NULL,NULL);

and then further down with the first entry in VALUES() equal to 3177 instead of 3161.

The logging produced three pairs of log files, davdroid-26440-20170828-114615.txt, davdroid-26476-20170828-114615.txt, and davdroid-27951-20170828-115853.txt, each with an accompanying and empty .txt.lck file.

The first file, davdroid-26440-20170828-114615.txt, simply contains:

2017-08-28 11:46:18 1789 [AccountSettings] Account xxx@xxx.net has version 6, current version: 6
2017-08-28 11:59:25 1 [log.Logger] Verbose logging: false

The last file, davdroid-27951-20170828-115853.txt, is attached (anonymized)
as 0_1503916650335_davdroid-27951-20170828-115853.txt .

The second file is huge (8.6MB) and contains all(?) the clear text content of the calendar entries. I am not comfortable sharing this with anyone and not sure how to a anonymize it. The duplicate entry quoted above appears in three places in that file, here

END:VEVENT
END:VCALENDAR
</cal:calendar-data></d:prop><d:status>HTTP/1.1 200 OK</d:status></d:propstat></d:response><d:response><d:href>/owncloud/remote.php/dav/calendars/user1/username2_username1_shared_by_user2/b133303f-f0d2-4cc9-a89b-cf4a49f5e003.ics</d:href><d:propstat><d:prop><d:getcontenttype>text/calendar; charset=utf-8; component=vevent</d:getcontenttype><d:getetag>&quot;8165fd52278e63746e3da1f257ab6a2e&quot;</d:getetag><cal:calendar-data>BEGIN:VCALENDAR
PRODID:-//Mozilla.org/NONSGML Mozilla Calendar V1.1//EN
VERSION:2.0
BEGIN:VTIMEZONE
TZID:Europe/Madrid
BEGIN:DAYLIGHT
TZOFFSETFROM:+0100
TZOFFSETTO:+0200
TZNAME:CEST
DTSTART:19700329T020000
RRULE:FREQ=YEARLY;BYDAY=-1SU;BYMONTH=3
END:DAYLIGHT
BEGIN:STANDARD
TZOFFSETFROM:+0200
TZOFFSETTO:+0100
TZNAME:CET
DTSTART:19701025T030000
RRULE:FREQ=YEARLY;BYDAY=-1SU;BYMONTH=10
END:STANDARD
END:VTIMEZONE
BEGIN:VEVENT
CREATED:20170713T103641Z
LAST-MODIFIED:20170713T103720Z
DTSTAMP:20170713T103720Z
UID:b133303f-f0d2-4cc9-a89b-cf4a49f5e003
SUMMARY:XXX
DTSTART;TZID=Europe/Madrid:20170710T200000
DTEND;TZID=Europe/Madrid:20170711T010000
TRANSP:OPAQUE
END:VEVENT
END:VCALENDAR
</cal:calendar-data></d:prop><d:status>HTTP/1.1 200 OK</d:status></d:propstat></d:response><d:response><d:href>/owncloud/remote.php/dav/calendars/user1/username2_username1_shared_by_user2/df4c82ed-d3fd-4845-8b38-e235036ec850.ics</d:href><d:propstat><d:prop><d:getcontenttype>text/calendar; charset=utf-8; component=vevent</d:getcontenttype><d:getetag>&quot;34d173fb52668249e9234571382be094&quot;</d:getetag><cal:calendar-data>BEGIN:VCALENDAR
PRODID:-//Mozilla.org/NONSGML Mozilla Calendar V1.1//EN
VERSION:2.0
BEGIN:VEVENT

here

2017-08-28 11:49:40 1807 [net.fortuna.ical4j.data.CalendarParserImpl:464] [58]
2017-08-28 11:49:40 1807 [net.fortuna.ical4j.data.CalendarParserImpl:464] [-3]
2017-08-28 11:49:40 1807 [net.fortuna.ical4j.data.CalendarParserImpl:464] [10]
2017-08-28 11:49:40 1809 [dav4android.DavResource] Received <response> for https://xxx.xxx.org:8080/owncloud/remote.php/dav/calendars/user1/username2_username1_shared_by_user2/b133303f-f0d2-4cc9-a89b-cf4a49f5e003.ics
	PARAMETER #0 = [calendar-data(urn:ietf:params:xml:ns:caldav): CalendarData(iCalendar=BEGIN:VCALENDAR
PRODID:-//Mozilla.org/NONSGML Mozilla Calendar V1.1//EN
VERSION:2.0
BEGIN:VTIMEZONE
TZID:Europe/Madrid
BEGIN:DAYLIGHT
TZOFFSETFROM:+0100
TZOFFSETTO:+0200
TZNAME:CEST
DTSTART:19700329T020000
RRULE:FREQ=YEARLY;BYDAY=-1SU;BYMONTH=3
END:DAYLIGHT
BEGIN:STANDARD
TZOFFSETFROM:+0200
TZOFFSETTO:+0100
TZNAME:CET
DTSTART:19701025T030000
RRULE:FREQ=YEARLY;BYDAY=-1SU;BYMONTH=10
END:STANDARD
END:VTIMEZONE
BEGIN:VEVENT
CREATED:20170713T103641Z
LAST-MODIFIED:20170713T103720Z
DTSTAMP:20170713T103720Z
UID:b133303f-f0d2-4cc9-a89b-cf4a49f5e003
SUMMARY:XXX
DTSTART;TZID=Europe/Madrid:20170710T200000
DTEND;TZID=Europe/Madrid:20170711T010000
TRANSP:OPAQUE
END:VEVENT
END:VCALENDAR
), getcontenttype(DAV:): GetContentType(type=text/calendar; charset=utf-8; component=vevent), getetag(DAV:): 8165fd52278e63746e3da1f257ab6a2e]
2017-08-28 11:49:40 1807 [net.fortuna.ical4j.data.CalendarParserImpl:464] [-3]
2017-08-28 11:49:40 1807 [net.fortuna.ical4j.data.CalendarParserImpl$PropertyParser:240] Property [CREATED]

and here

2017-08-28 11:49:38 1807 [net.fortuna.ical4j.data.CalendarParserImpl:464] [58]
2017-08-28 11:49:38 1807 [net.fortuna.ical4j.data.CalendarParserImpl:464] [-3]
2017-08-28 11:49:38 1807 [net.fortuna.ical4j.data.CalendarParserImpl:520] [VCALENDAR]
2017-08-28 11:49:38 1809 [dav4android.DavResource] Received <response> for https://xxx.xxx.org:8080/owncloud/remote.php/dav/calendars/user1/username2_username1_shared_by_user2/20170629T094205Z-8f48612dd2dfaecf.ics
	PARAMETER #0 = [getetag(DAV:): dcef88b8223886602f2bef7e3ec3730a]
2017-08-28 11:49:38 1807 [ical4android.Event] Assigning exceptions to master events
2017-08-28 11:49:38 1807 [syncadapter.CalendarSyncManager] Adding b133303f-f0d2-4cc9-a89b-cf4a49f5e003.ics to local calendar
2017-08-28 11:49:38 1807 [ical4android.AndroidEvent] Built event object
	PARAMETER #0 = mType: 1, mUri: content://com.android.calendar/events?account_name=xxx%40xxx.net&account_type=bitfire.at.davdroid&caller_is_syncadapter=true&account_name=xxx%40xxx.net&account_type=bitfire.at.davdroid&caller_is_syncadapter=true, mSelection: null, mExpectedCount: null, mYieldAllowed: false, mValues: eventTimezone=Europe/Madrid title=XXX availability=0 allDay=0 hasAttendeeData=1 dtend=1499727600000 dtstart=1499709600000 calendar_id=12 eventEndTimezone=Europe/Madrid, mValuesBackReferences: null, mSelectionArgsBackReferences: null
2017-08-28 11:49:38 1809 [dav4android.DavResource] Received <response> for https://xxx.xxx.org:8080/owncloud/remote.php/dav/calendars/user1/username2_username1_shared_by_user2/20170703T113241Z-8f48612dd2dfaecf.ics
	PARAMETER #0 = [getetag(DAV:): 9b6762ffddff825aa2681d464dddb6e8]

I am happy to send you more snippets from that file, if you tell me what you need.

rfc2822

@cgogolin Looks good to me and I can't see why this event is added again. However, I'd really need to look at the whole sync process. Maybe you can just replace all SUMMARY, LOCATION, DESCRIPTION, DTSTART, DTEND values with XXX to anonymize it and send it to play@bitfire.at?

cgogolin

@rfc2822 The problem is that many of these fields have values that extend over several lines. For the fields you mentioned I can remove with emacs regexp-replace and regular experssions of the type

DESCRIPTION:.*\(
 .*\)*

because all the following lines start in with a white space. But the descriptions also appear in lines such as

2017-08-28 11:52:51 1809 [ical4android.AndroidEvent] Built event object
	PARAMETER #0 = mType: 1, mUri: content://com.android.calendar/events?account_name=xxx%40xxx.net[...]description=THE DESCRIPTION
HERE EXTENDS
OVER SEVERAL LINES title=[...]

Here I get a "Stack overflow in regexp matcher" if I try to match them with a regexp of the type

description=\(?:.\|
\)+title=

I know I am asking for much, but do you have any idea how to remove them? At the same time it is not really my fault that the logs are printed in a format that is so difficult o annonymize...

cgogolin

I used grep to extract all lines that contain the string b133303f-f0d2-4cc9-a89b-cf4a49f5e003.ics from davdroid-26476-20170828-114615.txt. Maybe that contains already enough information for you to see what is going on? 0_1503928139665_davdroid-26476-20170828-114615.txt.greped

rfc2822

@cgogolin No, I'd need the context. It's already hard enough to look through real logs, but only a few grepped lines for a bug that I can't reproduce … maybe we can wait until this problem occurs more often so that it can finally be reproduced.

cgogolin

In the end I removed all the title= and description= parts manually. I just sent you the file via email to play@bitfire.at. Hope you will see something in there...

rfc2822

@cgogolin Thanks for the logs. Unfortunately, I just can see that at some time, there are some new entries which appear on the server (e.g. https://xxx.xxx.org:8080/owncloud/remote.php/dav/calendars/user1/username2_username1_shared_by_user2/540c319d-3a76-4726-a013-b2b479220051.ics) and then are downloaded and added to the calendar by DAVdroid. Don't know if those events are the "duplicated" ones or just newly added events, but the whole DAVdroid processing seems correct to me.

Maybe it's related to the shared calendars… are you using the latest version of OwnCloud and it's calendar app?

cgogolin

Thanks for your analysis. The entry 540c319d-3a76-4726-a013-b2b479220051.ics you mention is in the database dump only once and appears as

INSERT INTO "Events" VALUES(3135,'540c319d-3a76-4726-a013-b2b479220051.ics',0,NULL,0,12,'XXX ',NULL,NULL,NULL,NULL,1,0,1506272400000,1506286800000,'Europe/Madrid',NULL,0,0,0,1,0,NULL,NULL,NULL,NULL,NULL,NULL,NULL,NULL,1506286800000,1,0,1,1,'xxx@xxx.net',NULL,0,'Europe/Madrid',NULL,NULL,'540c319d-3a76-4726-a013-b2b479220051','f006d92e71f6a52db9ec59b99089428a',NULL,'0',NULL,NULL,NULL,NULL,NULL,NULL,NULL);

on the contrary, the duplicate entry I described above b133303f-f0d2-4cc9-a89b-cf4a49f5e003 is not among those that appear after a New resources have been found on the server entry in the log file. I don't know where these New resources come from, but I would conjecture that they have nothing to do with the duplicate entry issue.

The shared calendar was just an example. The same thing happens also for calendars only synced between the phone, ownclound, and thunderbird/lightning with sogo connector. I am using an up-to-date owncloud. Since the dav backend has been moved into the core I am no longer using the calendar app there.

I have now also verified that the duplicate entries are only once in the owncloud database, which also explains why they only appear once in thunderbird and on the other phone that syncs the very same shared calendar via a different owncloud account. This is also consistent with the fact that every time I do a re-sync (with the procedure described above) other entries end up appearing twice. As a side remark: I have never seen an entry more than once.

To me it really looks like a problem between davdroid and the android calendar database.

rfc2822

@cgogolin Well as I see it, DAVdroid doesn't insert those events, so maybe something else inserts them. This could explain why it's not reproducible here… Are there any other apps installed which could edit/insert events?

If you have another suggestion on what I could do, please let me know.

cgogolin

I just checked with https://play.google.com/store/apps/details?id=org.androidsoft.app.permission which apps have calendar read or write permissions. These are: DAVdroid, Tasker, and Signal. All three are also installed on the other device that does not show the duplicate entries. Tasker has a few profiles to switch wifi on and off, but nothing with relation to calendar entries. I really don't understand what is going on... This is one of the issues I wouldn't even have dared to report, but then I saw that some else had the same problem so I had hope I could help resolve it...
If you have any suggestions for what I can do, please let me know. I keep you posted in case we observe anything else that might be useful for you.

cgogolin

The last DAVdroid update on Google Play states under WHAT'S NEW

prevent multiple syncs to be run at the same time for the same account and authority (hopefully fixes duplicate entries – if you have duplicate entries, please uninstall DAVdroid and try with 1.9.1 again)

and indeed, the problems reported above seem to have disappeared after I uninstalled and reinstalled the new version. Thanks for fixing it and making this App even more awesome!