GNOME Bugzilla – Bug 773011
empathy aggregates many different individuals into a single roster entry (Also spinning at 100% cpu for 20-60 seconds while it does it)
Last modified: 2016-11-14 08:48:23 UTC
I have a complicated bug that's somewhat hard to explain. Though I'm pretty sure it has something to do with libfolks persona aggregation. I'm just guessing on the evolution-eds component, the issue may be in the aggregation code, or the telepathy backend. When its triggered I end up with several different individuals IM accounts and avatars as well as all of my contacts phone numbers aggregated into a single individual in my empathy roster. (in the empathy context menu for the merged individual there is a long scroll showing scores of phone numbers and several different individuals IM accounts all in a single roster entry) I believe it started happening after I figured out how to load all of my contacts from my phone over a radical webdav server into evolution. In addition to the webdav account I also have a evolution-ews account conntected to office365. Individuals in my roster, in evolution, or in gnome contacts can have information from exchange, webdav, and telepathy. (or some combination of those) The merged individuals roster entry happened frequently when my "on this computer" evolution personal address book had duplicate individuals with incomplete IM persona information. I tried to merge them all together in the personal account and restarted evolution a few times and and it didn't seem to start merging individuals. Then I loaded gnome-contacts and in the evolution webdav addressbook I saw all of the contact records that were displayed get duplicated and in empathy individuals with all their personas and every phone number in my address book got merged into a single roster entry. (Then when I restarted evolution the list of address book was significantly smaller, until it managed to redownload the vcard file from my server) A possibly related behavior is when I open gnome-contacts and pick people who have information in both exchange it regularly offers to merge unrelated people together. I.e. I pick "Brian ..." and it asks do you want to merge "Ram ..." together? This seems to happen for contacts who have data in recipient cache regardless of having information in my webdav account. If I delete a person out of the exchange "recipient cache" gnome-contacts won't offer to merge them. Even though two of the people being offered to be merged in gnome-contacts also had records in webdav. Unfortunately as one of the individuals that gets merged in the empathy roster doesn't have any records in exchange, just webdav and telepathy, I don't think I can just blame exchange's recipient cache. If I launch empathy with either FOLKS_BACKENDS_DISABLED=eds or FOLKS_DISABLE_LINKING=true folks aggregation doesn't happen and unsurprisingly I don't end up with one roster entry with multiple individuals. I wish I could've written a more clear bug report, but the bug seems to have something to do with how gnome-contacts, empathy, and the two evolution accounts interact with each other.
Thanks for the detailed description. However, a description by itself is not going to help in debugging this issue. :-) Could you please install folks-inspect and run: folks-inspect individuals find one of the individuals which contains the wrong personas, and run folks-inspect individuals $individual_id where the $individual_id is a hex string taken from the `folks-inspect individuals` output. This should list the details of that individual and the personas in it. Could you also please grab the output of: folks-inspect debug which contains a huge amount of debug information about how the personas are linked. All of this information will contain personal information from your personas, so please do not attach it to this bug report directly. Either e-mail it to me (bugzilla@tecnocode.co.uk) and I will keep it completely confidential; or redact the personal data and attach it here. If you are redacting the personal data, please ensure you do it so that all the identifiers are still distinct from each other. Thanks.
The long story was due to me struggling trying to understand whats going on. I tried looking at the output of folks-inspect individuals looking for an overly aggregated individual but since upgrading to Debian's libfolks25 0.11.3 folks-inspect doesn't report anything unreasonably merged. I once saw an individual with 300 personas in folks-inspect, but I can't replicate that now. (So I'm not sure how useful sending you the output of folks-inspect individual & debug might be) I looked more carefully at the unexpected to me merging in gnome-contacts & folks-inspect, and discovered that I have two phone numbers that are shared between several people. Its those people with the shared phone number that gnome-contact is offering to merge, which makes sense now. This suggests there's a bug in empathy (or maybe telepathy) which isn't surprising since empathy doesn't really have any maintainers now. One of the things that made me think something up with libfolks was that sometimes empathy and empathy-chat will spin at 100% cpu. gdb attaching shows that empathy is busy processing persona set changing. backtraces from empathy & empathy-chat attached. In trying to figure out whats going on I hit the valac generated C and can't tell whats going on with the GeeHashSets. I'm going to try to get a log with G_MESSAGES_DEBUG=all empathy when it tries to merge too much
Created attachment 338040 [details] bt full of empthy spinning at 100% merging contacts
Created attachment 338041 [details] bt full of empathy-chat spinning at 100% cpu
(In reply to Diane Trout from comment #2) > The long story was due to me struggling trying to understand whats going on. Yeah, it’s always difficult to know where to start with debugging libfolks. :-) > I tried looking at the output of folks-inspect individuals looking for an > overly aggregated individual but since upgrading to Debian's libfolks25 > 0.11.3 folks-inspect doesn't report anything unreasonably merged. I once saw > an individual with 300 personas in folks-inspect, but I can't replicate that > now. (So I'm not sure how useful sending you the output of folks-inspect > individual & debug might be) If you can’t reproduce the bug with folks-inspect, then the bug does not lie in libfolks, and probably lies in Empathy or gnome-contacts. > I looked more carefully at the unexpected to me merging in gnome-contacts & > folks-inspect, and discovered that I have two phone numbers that are shared > between several people. Its those people with the shared phone number that > gnome-contact is offering to merge, which makes sense now. That does make sense. Do you think gnome-contacts could have made that more obvious in the UI? If so, perhaps it would make sense to file a bug against gnome-contacts asking for the UI to show which field is causing it to suggest two contacts are merged. > This suggests there's a bug in empathy (or maybe telepathy) which isn't > surprising since empathy doesn't really have any maintainers now. If there’s a bug, it would not be in Telepathy — libfolks sits on top of Telepathy, and Empathy sits on top of libfolks. > One of the things that made me think something up with libfolks was that > sometimes empathy and empathy-chat will spin at 100% cpu. gdb attaching > shows that empathy is busy processing persona set changing. That sounds like it could be a libfolks bug, but it’s not necessarily the same bug as over-linking — it could be that correctly linking your personas is sucking up too much CPU time. Generally the most useful debug data for investigating that kind of CPU usage is a G_MESSAGES_DEBUG=all log, rather than a backtrace, since a backtrace is just a snapshot of the process’ state rather than a trace of it over time.
Created attachment 338474 [details] filtered folks debugging output Ok the log file explodes so quickly.... I ran it for a minute or two and ended up about 450 MB of logs. So for this log I grabbed one the last aggregated version with just personas related to my identity, and then the first instance with someone else being added in. (and some hopefully relevant, but hard to understand messages that looks like pointers around the merged identity) I did some simple replaces on the email and jabber ids. One thing I notice is I see things like Aggregating persona 'eds:1469139166.8512.1@myrada:' on '1469139166.8512.1@myrada:'. somewhat frequently... it seems like some of the unique id got lost? I hope I managed to extract enough useful logs for you
> So for this log I grabbed one the last aggregated version with just personas > related to my identity, and then the first instance with someone else being > added in. The persona that shouldn't be added is the yahoo one. I forgot to mention that last night.
Sorry for the delayed response — I’ve been travelling. > (empathy:20439): eds-DEBUG: edsf-persona.vala:1012: Creating new Edsf.Persona with IID '1469139166.8512.1@myrada:' > (empathy:20439): eds-DEBUG: edsf-persona-store.vala:2510: Adding persona 0x2642420 from contact 1469139166.8512.1@myrada:. These lines are suspicious. The format for IIDS (internal IDs) for personas in the EDS backend in folks is: ‘store-ID:contact-ID’, and neither of those strings should be empty. For this contact, the contact-ID appears to be empty. If the contact-ID is empty for other contacts coming from that EDS address book, their IIDs would end up the same, and that would cause spurious over-linking. Do you know where those contacts are coming from? The radical webdav account, perhaps? Can you check whether the vCard file it’s exporting includes UID fields for its contacts? You should be able to find EDS’ cache of the webdav vCard file in ~/.cache/evolution/addressbook/$account_id/cache.xml.
I found something suspicious. on the evolution cache.xml I wanted to compare the number of VCARD entries to the number of UIDs so I tried: diane:~/.cache/evolution/addressbook$ grep -ci begin:vcard */cache.xml 1469139166.8512.1@myrada/cache.xml:15 1477332659.1706.15@amarana/cache.xml:25 ls -l */cache.xml 20439 Oct 15 22:00 1469139166.8512.1@myrada/cache.xml 119078 Nov 4 15:07 1477332659.1706.15@amarana/cache.xml but I know I have several hundred contacts, evolution even shows them... I then decided to check the vCard file on the Radicale server and found this: grep -ic 'begin:vcard' addressbook.vcf 278 diane$ grep -ic 'uid:' addressbook.vcf 15 Another odd observation, if I try right clicking on the addressbook.vcf resource in evolution and saving the address book I end up with a vCard file with 15 contacts in it. This suggests evolution has its own problems with contacts with no UID. Also it suggests a simple workaround of me just adding UIDs to the contacts on the Radicale server. Should this bug be moved to someone else or be closed? (Assuming adding UIDs works) Also whats the appropriate behavior in this case? Should the CardDAV server be adding UIDs? should DavDroid be creating UIDs when syncing? Should evolution add UIDs? or should it properly handle UID-less vCards?
(In reply to Diane Trout from comment #9) > I found something suspicious. > > on the evolution cache.xml I wanted to compare the number of VCARD entries > to the number of UIDs so I tried: > > diane:~/.cache/evolution/addressbook$ grep -ci begin:vcard */cache.xml > 1469139166.8512.1@myrada/cache.xml:15 > 1477332659.1706.15@amarana/cache.xml:25 > > ls -l */cache.xml > 20439 Oct 15 22:00 1469139166.8512.1@myrada/cache.xml > 119078 Nov 4 15:07 1477332659.1706.15@amarana/cache.xml > > but I know I have several hundred contacts, evolution even shows them... > > I then decided to check the vCard file on the Radicale server and found this: > > grep -ic 'begin:vcard' addressbook.vcf > 278 > diane$ grep -ic 'uid:' addressbook.vcf > 15 > > Another odd observation, if I try right clicking on the addressbook.vcf > resource in evolution and saving the address book I end up with a vCard file > with 15 contacts in it. > > This suggests evolution has its own problems with contacts with no UID. Indeed, I’ve just been taking a look through the EDS code, and there are various places where it assumes that a contact has the E_CONTACT_UID field. That’s a bit weird, because the vCard specification says that the UID field is optional — but in practice, there would be no way to keep the contacts from the server in sync with those in EDS if there is no UID field. The only way a server could be used would be read-only. > Also it suggests a simple workaround of me just adding UIDs to the contacts > on the Radicale server. I think that’s probably your best bet. Maybe file a bug against Radicale and suggest that they ensure every contact has a UID set (or generated) when exporting a vCard? > Should this bug be moved to someone else or be closed? (Assuming adding UIDs > works) I can make a few changes in folks which should make it more robust against personas from EDS which have no UIDs, but I can only do that by making folks ignore such personas. That’s definitely better than linking together a load of completely unrelated personas, but is obviously not the ideal behaviour. I don’t think it will be possible to support personas without UIDs, since then there’s no way to consistently identify the same persona across all libfolks instances or across restarts of the application. I’ll see if I can get those changes done in libfolks now. > Also whats the appropriate behavior in this case? Should the CardDAV server > be adding UIDs? should DavDroid be creating UIDs when syncing? Should > evolution add UIDs? or should it properly handle UID-less vCards? I suspect the appropriate behaviour is for the original source of the vCard (i.e. Radicale) to add a UID. I don’t know how you’re using DavDroid in your setup, but I suspect it should also need a UID on each contact in order to bi-directionally sync correctly.
Fixes pushed to git for folks. I’m going to close this for now. If you do any more investigation and think that further fixes should be in libfolks, or if you want to discuss further, please reopen it. Thanks for the really helpful bug report. :-) --- commit f56e1f7852c72575087c8ec0dfb239a7a07fc7e1 Author: Philip Withnall <philip@tecnocode.co.uk> Date: Mon Nov 14 00:10:43 2016 +0000 folks: Check UID components are non-empty When building a UID, check that the three components are non-empty. Add preconditions to build_uid() which check this. All of the existing callers of that method are guaranteed to not pass in empty strings, so this is not a behaviour change. https://bugzilla.gnome.org/show_bug.cgi?id=773011 commit d74996eb74cb31c93af66304a326e57364c876a5 Author: Philip Withnall <philip@tecnocode.co.uk> Date: Mon Nov 14 00:07:54 2016 +0000 eds: Ignore contacts with no UID set in their vCard This can happen with contacts from some CardDAV servers (like Radicale). Since we use the UID as part of the persona’s IID, this can result in non-unique IIDs within a single persona store, which the rest of the code in libfolks does not expect. This can result in those personas being linked together (due to sharing IIDs) incorrectly by the aggregator. Instead, ignore any contacts which have no UID set. This is not a perfect solution (since UIDs are optional in the vCard specification, which we would ideally handle), but the alternative is to invent an ID which we then potentially couldn’t propagate back to the server, so could not guarantee its stability over time. https://bugzilla.gnome.org/show_bug.cgi?id=773011
Thank you for all your help! Since I added UIDs to everything my contacts have all been reasonably merged and I haven't had Empathy running at 100% cpu. I went ahead and forwarded the question asking if radicale should add UIDs to their bugtracker. https://github.com/Kozea/Radicale/issues/537
(In reply to Diane Trout from comment #12) > Thank you for all your help! > > Since I added UIDs to everything my contacts have all been reasonably merged > and I haven't had Empathy running at 100% cpu. Excellent, that’s good to know.