traceback after Sugar startup

[erikos]

In Sugar 0.93.5 I see the following traceback after startup. The machine has been connected to an AP.

** (sugar-session:912): DEBUG: starting phase 1

** (sugar-session:912): DEBUG: ending phase 1

** (sugar-session:912): DEBUG: starting phase 2

** (sugar-session:912): DEBUG: ending phase 2

** (sugar-session:912): DEBUG: starting phase 3

** (sugar-session:912): DEBUG: ending phase 3

** (sugar-session:912): DEBUG: starting phase 4

** (sugar-session:912): DEBUG: ending phase 4

** (sugar-session:912): DEBUG: starting phase 5

** (sugar-session:912): DEBUG: ending phase 5

1316785771.509857 DEBUG root: STARTUP: Loading the desktop window
1316785771.520521 DEBUG root: STARTUP: Loading the home view
1316785771.521408 DEBUG root: STARTUP: Loading the favorites view
1316785771.681036 DEBUG root: FavoritesSetting layout 'ring-layout'
1316785771.682336 DEBUG root: Icon without fixed_position: <OwnerIcon object at 0x97beaa4 (SugarFavoritesOwnerIcon at 0x92140f8)>
1316785771.682966 DEBUG root: Icon without fixed_position: <CurrentActivityIcon object at 0x97bed9c (CanvasIcon at 0x9214170)>
1316785771.683565 DEBUG root: STARTUP: Loading the activities list
1316785771.868064 WARNING root: No gtk.AccelGroup in the top level window.
1316785771.884782 WARNING root: No gtk.AccelGroup in the top level window.
1316785771.886874 DEBUG root: STARTUP: Loading the group view
1316785772.597262 DEBUG root: STARTUP: Loading the mesh view
1316785772.718615 WARNING root: No gsm connection was set in GConf.
1316785772.830059 DEBUG root: Not an activity icon <OwnerIcon object at 0x97beaa4 (SugarFavoritesOwnerIcon at 0x92140f8)>
1316785772.856142 DEBUG root: Not an activity icon <CurrentActivityIcon object at 0x97bed9c (CanvasIcon at 0x9214170)>
1316785773.551604 ERROR dbus.connection: Exception in handler for D-Bus signal:
Traceback (most recent call last):
  File "/usr/lib/python2.7/site-packages/dbus/connection.py", line 214, in maybe_handle_message
    self._handler(*args, **kwargs)
  File "/usr/lib/python2.7/site-packages/jarabe/model/buddy.py", line 130, in __name_owner_changed_cb
    Connection(name, path, ready_handler=self.__connection_ready_cb)
  File "/usr/lib/python2.7/site-packages/telepathy/client/conn.py", line 49, in __init__
    object = self.bus.get_object(service_name, object_path)
  File "/usr/lib/python2.7/site-packages/dbus/bus.py", line 244, in get_object
    follow_name_owner_changes=follow_name_owner_changes)
  File "/usr/lib/python2.7/site-packages/dbus/proxies.py", line 241, in __init__
    self._named_service = conn.activate_name_owner(bus_name)
  File "/usr/lib/python2.7/site-packages/dbus/bus.py", line 183, in activate_name_owner
    self.start_service_by_name(bus_name)
  File "/usr/lib/python2.7/site-packages/dbus/bus.py", line 281, in start_service_by_name
    'su', (bus_name, flags)))
  File "/usr/lib/python2.7/site-packages/dbus/connection.py", line 630, in call_blocking
    message, timeout)
DBusException: org.freedesktop.DBus.Error.ServiceUnknown: The name org.freedesktop.Telepathy.Connection.gabble.jabber._352fbf7d4a2162582212a9d90bf47611c56438783_40schoolserver_2epennylane_2fsugar was not provided by any .service files
1316785773.575563 DEBUG root: Already have a Salut account
1316785773.583059 DEBUG root: _Account.enable /org/freedesktop/Telepathy/Account/salut/local_xmpp/account0
1316785773.587218 DEBUG root: Already have a Gabble account
1316785773.594739 DEBUG root: _Account.enable /org/freedesktop/Telepathy/Account/gabble/jabber/_352fbf7d4a2162582212a9d90bf47611c56438783_400
1316785773.621979 DEBUG root: _Account.__got_connection_cb dbus.ObjectPath('/', variant_level=1)

[erikos]

full log

[erikos]

The issue here is that we do not have a connection yet, when the name owner changes. It is safer to listen to the connection watcher when a connection is added.

diff --git a/src/jarabe/model/buddy.py b/src/jarabe/model/buddy.py
index 8f17d7e..67ab104 100644
--- a/src/jarabe/model/buddy.py
+++ b/src/jarabe/model/buddy.py
@@ -21,6 +21,7 @@ import gobject
 import gconf
 import dbus
 from telepathy.client import Connection
+
 from telepathy.interfaces import CONNECTION
 
 from sugar.graphics.xocolor import XoColor
@@ -107,27 +108,8 @@ class OwnerBuddyModel(BaseBuddyModel):
         self.connect('notify::nick', self.__property_changed_cb)
         self.connect('notify::color', self.__property_changed_cb)
 
-        bus = dbus.SessionBus()
-        bus.add_signal_receiver(
-                self.__name_owner_changed_cb,
-                signal_name='NameOwnerChanged',
-                dbus_interface='org.freedesktop.DBus')
-
-        bus_object = bus.get_object(dbus.BUS_DAEMON_NAME, dbus.BUS_DAEMON_PATH)
-        for service in bus_object.ListNames(
-                dbus_interface=dbus.BUS_DAEMON_IFACE):
-            if service.startswith(CONNECTION + '.'):
-                path = '/%s' % service.replace('.', '/')
-                Connection(service, path, bus,
-                           ready_handler=self.__connection_ready_cb)
-
-    def __connection_ready_cb(self, connection):
-        self._sync_properties_on_connection(connection)
-
-    def __name_owner_changed_cb(self, name, old, new):
-        if name.startswith(CONNECTION + '.') and not old and new:
-            path = '/' + name.replace('.', '/')
-            Connection(name, path, ready_handler=self.__connection_ready_cb)
+        conn_watcher = connection_watcher.get_instance()
+        conn_watcher.connect('connection-added', self.__connection_added_cb)
 
     def __property_changed_cb(self, buddy, pspec):
         self._sync_properties()

[erikos]

In neighborhood.py we have the same issue.

diff --git a/src/jarabe/model/neighborhood.py b/src/jarabe/model/neighborhood.py
index 828cb14..efbc695 100644
--- a/src/jarabe/model/neighborhood.py
+++ b/src/jarabe/model/neighborhood.py
@@ -159,6 +159,10 @@ class ActivityModel(gobject.GObject):
     current_buddies = gobject.property(type=object, getter=get_current_buddies)

 class _Account(gobject.GObject):
     __gsignals__ = {
         'activity-added': (gobject.SIGNAL_RUN_FIRST, gobject.TYPE_NONE,
@@ -251,7 +255,12 @@ class _Account(gobject.GObject):
             self._check_registration_error()
             self._connection = None
         elif self._connection is None:
-            self._prepare_connection(properties['Connection'])
+            if 'ConnectionStatus' not in properties:
+                return
+            if properties['ConnectionStatus'] == CONNECTION_STATUS_CONNECTED:
+                self._prepare_connection(properties['Connection'])

We can solve this by checking if the connection has been established already.

[erilyth]

Has this issue been resolved since its been a year almost. If not what exactly is the problem that needs to be addressed? Do we just need to check that a connection has been established before trying to use it?

[erilyth]

Has this been resolved? If not what exactly is the problem that needs to be fixed, Is it that we just need to check for the connection if it has been established before using it?

[quozl]

It hasn't been a year, it has been four years.

The problem is a traceback message in Sugar logs. There's no indication of any other symptom.

The change proposed in comment:3 for neighbourhood.py is not in git now.

It seems likely that the problem should still occur, but to prove it may require careful testing with fault injection.