GNOME Bugzilla – Bug 702165
Empathy crash when enabling/disabling accounts repeatidly
Last modified: 2018-09-21 16:02:52 UTC
Steps: 1) configure a salut and gtalk accounts, put them online and open empathy contact list. 2) disable then enable salut account 3) disable then enable gtalk account 4) repeat 2 & 3 until empathy crash. It can take a while... Here is the backtrace:
+ Trace 232041
Here is a more complete backtrance:
+ Trace 232059
What I understand so far is that for some reason, when an account connects it will add its self persona. The aggregator then link it with another persona that comes from a disposed store.
Here is another crash which seems to be related. (lt-empathy:28315): telepathy-DEBUG: tpf-persona-store.vala:1210: contact list changed: 0 added, 1 removed (lt-empathy:28315): telepathy-DEBUG: tpf-persona-store.vala:1087: Remove persona 0x8ebb120 with uid telepathy:/org/freedesktop/Telepathy/Account/salut/local_xmpp/account0:xclaesse@X230 (lt-empathy:28315): folks-DEBUG: individual-aggregator.vala:1488: Removing Personas: (lt-empathy:28315): folks-DEBUG: individual-aggregator.vala:1492: telepathy:/org/freedesktop/Telepathy/Account/salut/local_xmpp/account0:xclaesse@X230 (is user: no, IID: local-xmpp:xclaesse@X230) (lt-empathy:28315): folks-DEBUG: individual-aggregator.vala:1516: Removing Individuals due to removed links: (lt-empathy:28315): folks-DEBUG: individual-aggregator.vala:1523: 50dc7cf77b81a088a063d487aa3ace088288762b (lt-empathy:28315): folks-DEBUG: individual-aggregator.vala:1442: Removing Individual '50dc7cf77b81a088a063d487aa3ace088288762b' from the link map. (lt-empathy:28315): folks-DEBUG: individual-aggregator.vala:1455: local-xmpp:xclaesse@X230 → 50dc7cf77b81a088a063d487aa3ace088288762b (0x7479a10) (lt-empathy:28315): folks-DEBUG: individual-aggregator.vala:1545: Adding Personas: (lt-empathy:28315): folks-DEBUG: individual-aggregator.vala:1561: Relinking Personas: (lt-empathy:28315): folks-DEBUG: individual-aggregator.vala:1037: Emitting individuals-changed-detailed with 1 mappings: (lt-empathy:28315): folks-DEBUG: individual-aggregator.vala:1047: 50dc7cf77b81a088a063d487aa3ace088288762b (0x7479a10) → ((nil)) (lt-empathy:28315): folks-DEBUG: individual-aggregator.vala:1054: Removed individual's personas: (lt-empathy:28315): folks-DEBUG: individual-aggregator.vala:1639: Replacing Individuals due to linking: (lt-empathy:28315): folks-DEBUG: individual.vala:1183: Destroying Individual '50dc7cf77b81a088a063d487aa3ace088288762b': 0x7479a10 (lt-empathy:28315): telepathy-DEBUG: tpf-persona-store.vala:1210: contact list changed: 0 added, 1 removed (lt-empathy:28315): telepathy-DEBUG: tpf-persona-store.vala:1108: Weak notify for TpContact xclaesse@X230 (lt-empathy:28315): telepathy-DEBUG: tpf-persona.vala:1236: Destroying Tpf.Persona 'telepathy:/org/freedesktop/Telepathy/Account/salut/local_xmpp/account0:xclaesse@X230': 0x8ebb120 (lt-empathy:28315): telepathy-DEBUG: tpf-persona.vala:606: TpContact 0x8fc2000 destroyed; setting ._contact = null in Persona 0x8ebb120 (lt-empathy:28315): GLib-GObject-CRITICAL **: g_object_notify: assertion `G_IS_OBJECT (object)' failed Program received signal SIGTRAP, Trace/breakpoint trap. 0x00007ffff08f5982 in g_logv (log_domain=0x7ffff0c2d0cf "GLib-GObject", log_level=G_LOG_LEVEL_CRITICAL, format=0x7ffff097cfec "%s: assertion `%s' failed", args=0x7fffffffcdd8) at gmessages.c:974 974 G_BREAKPOINT (); (gdb) bt
+ Trace 232250
Ok so here is how I understand this Guillaume's crash (I hope other crash are related): a) TpfPersonaStore takes a weak_ref on the TpContact b) TpfPersona creates a GWeakRef for its this._contact c) TpfPersona takes a weak_ref on the TpContact as well When a TpContact is disposed, here what happens: 1) From the code of g_object_unref() we can learn than GWeakRef is the first to be set to NULL when an object's ref count hit 0, before weak notify callbacks 2) TpfPersonaStore's _contact_weak_notify_cb() is called first and it drops its strong ref on the TpfPersona. Sometimes it can happen that this was the last ref on the TpfPersona... 3) ... so ~Persona is called and does this._contact.get() which returns NULL because of step 1 so TpfPersona's weak ref on the TpContact is NOT removed! 4) _contact_weak_notify_cb() is called on TpfPersona, after it has been finalized => crash. Now the question is how to avoid that ?
This bug is probably introduced by the fix of bug #680335.
Created attachment 249393 [details] [review] TpfPersona: Manage the TpContact weak ref ourself instead of using GWeakRef See https://bugzilla.gnome.org/show_bug.cgi?id=702165#c3 for an explaination.
Review of attachment 249393 [details] [review]: Looks good to me but may be best to ask Philip's advice as well as he wrote the original hack.
Review of attachment 249393 [details] [review]: Actually this is not working. What happens now when a TpContact dies: 1) TpfPersonaStore::_contact_weak_notify_cb() is called first and unref the persona 2) The TpfPersona dies and does this._contact.weak_unref() which raise a warning because we cannot weak_unref() an object from within the weak_notify of step1 3) If it's not running with fatal-warnings then TpfPersona::_contact_weak_notify_cb() gets called on finalized persona => crash.
Created attachment 249396 [details] [review] TpfPersona: Manage the TpContact weak ref ourself instead of using GWeakRef
That really fix crash from comment #2, but I still get the crash from comment #1.
Review of attachment 249396 [details] [review]: Looks good. Please commit. ::: backends/telepathy/lib/tpf-persona-store.vala @@ +1105,3 @@ } + persona._contact_weak_notify(); Need a space before the ‘()’.
Thanks, pushed to both master and 0.8 branch. I'm not closing this bug since the initial crash is still reproducible.
I have been able to reproduce the crash in comment #1 with folks 0.9.1 and folks 0.9.2, empathy 3.8.3. I haven't been able to reproduce it with folks master after trying for a while, but given how hard it is to reproduce... In individual.vala:2512 we have: /* Increment the Persona count for this PersonaStore */ var store = p.store; That translates into: _tmp25_ = p; _tmp26_ = folks_persona_get_store (_tmp25_); _tmp27_ = _tmp26_; _tmp28_ = _g_object_ref0 (_tmp27_); store = _tmp28_; and it asserts in _g_object_ref0 because store is not an object. I don't know whether p is a valid object at this stage. folks_persona_get_store(persona) only checks for `persona != NULL', not for IS_PERSONA(persona). Same for folks_persona_get_is_user() which is called a few lines before. So I'm not sure yet where the bug really.
I had a brief look at this a while ago, and my immediate thought was that Folks seems to be relying on last-unref as having some sort of semantic meaning. That's not right, particularly if you're binding into JavaScript (which has GC, not refcounting, which means extra refs can lurk for an arbitrarily long time). If there is an external event that means "this PersonaStore is dead, stop referring to its Personas" or something, then there should be a flag/signal for that instead, like Telepathy's TpProxy::invalidated. Doing things in response to a weak ref being released is always a little precarious: you're dealing with a "near-death" object which might already have released the state you need in order to do cleanup. g_object_weak_ref() and g_object_add_weak_pointer() are worse than GWeakRef for this, because they only "go off" during GObjectClass.dispose (at which point the dying object is probably already unusable), whereas a GWeakRef is released before the dying object's dispose callback and can't call into arbitrary user-supplied code.
From the other bug: > 1. The TpContact is finalised, triggering its weak notifications. > ... > 2. _contact_weak_notify_cb() in Tpf.PersonaStore is called first, > and it removes the Persona (corresponding to the TpContact) from > various maps. Is this relying on the fact that a disconnected TpConnection unrefs the list of TpContacts that it would return from tp_connection_dup_contact_list()? That seems unreliable. Shouldn't it listen for TpConnection::invalidated instead, and clear all this stuff out in response to that?
(In reply to comment #14) > From the other bug: > > > 1. The TpContact is finalised, triggering its weak notifications. > > ... > > 2. _contact_weak_notify_cb() in Tpf.PersonaStore is called first, > > and it removes the Persona (corresponding to the TpContact) from > > various maps. > > Is this relying on the fact that a disconnected TpConnection unrefs the list of > TpContacts that it would return from tp_connection_dup_contact_list()? That > seems unreliable. Shouldn't it listen for TpConnection::invalidated instead, > and clear all this stuff out in response to that? I haven’t had a chance to look closely, but what you say does sound about right. Will the ::invalidated signals and associated machinery in Telepathy change for Telepathy 1.0? Is it worthwhile spending time fixing this now, or waiting for the Tp 1.0 branch to get merged into folks?
(In reply to comment #15) > I haven’t had a chance to look closely, but what you say does sound about > right. Will the ::invalidated signals and associated machinery in Telepathy > change for Telepathy 1.0? The one change I've considered is this: at the moment, TpProxy's dispose() emits TpProxy::invalidated; but as part of the principle I alluded to above ("last-unref shouldn't have side-effects") I've considered removing that. If I do, getting the full effect of Telepathy 0.x's ::invalidated would require both a weak-ref and an ::invalidated listener. I think it might be too late for that at this point, though, if we want Telepathy 1 to reach a somewhat stable state within the next 2 weeks (which it has to, really, if we want it to go in GNOME 3.14 rather than slipping yet another 6 months). Semantic changes that don't break compilation are annoying.
-- GitLab Migration Automatic Message -- This bug has been migrated to GNOME's GitLab instance and has been closed from further activity. You can subscribe and participate further through the new bug through this link to our GitLab instance: https://gitlab.gnome.org/GNOME/folks/issues/63.