Attachment 84400 Details for Bug 68390 – TpConnectionManager, TpProtocol: improve debug output

[patch] TpConnectionManager, TpProtocol: improve debug output

0001-TpConnectionManager-TpProtocol-improve-debug-output.patch (text/plain), 15.08 KB, created by Simon McVittie on 2013-08-21 17:28:28 UTC

(hide)

Description:

Filename:

MIME Type:

Creator: Simon McVittie

Created: 2013-08-21 17:28:28 UTC

Size: 15.08 KB

patch

obsolete

>From d86a89c9d471883d9f1d87679848bf5bd2281008 Mon Sep 17 00:00:00 2001
>From: Simon McVittie <simon.mcvittie@collabora.co.uk>
>Date: Tue, 20 Aug 2013 13:48:58 +0100
>Subject: [PATCH 1/3] TpConnectionManager, TpProtocol: improve debug output
>
>---
> telepathy-glib/connection-manager.c | 101 ++++++++++++++++++++++++++++--------
> telepathy-glib/protocol.c           |  23 ++++++--
> telepathy-glib/util-internal.h      |   1 +
> telepathy-glib/util.c               |  26 ++++++++++
> 4 files changed, 125 insertions(+), 26 deletions(-)
>
>diff --git a/telepathy-glib/connection-manager.c b/telepathy-glib/connection-manager.c
>index c816bfc..2dd1c4e 100644
>--- a/telepathy-glib/connection-manager.c
>+++ b/telepathy-glib/connection-manager.c
>@@ -600,10 +600,16 @@ tp_connection_manager_got_parameters (TpConnectionManager *self,
> 
>   if (error != NULL)
>     {
>-      DEBUG ("Error getting params for %s, skipping it", protocol);
>+      DEBUG ("%s/%s: error from legacy GetParameters, skipping protocol: "
>+          "%s #%d: %s",
>+          self->name, protocol,
>+          g_quark_to_string (error->domain), error->code, error->message);
>       goto out;
>     }
> 
>+  DEBUG ("%s/%s: legacy GetParameters() returned %d parameters",
>+      self->name, protocol, parameters->len);
>+
>   immutables = tp_asv_new (
>       TP_PROP_PROTOCOL_PARAMETERS, TP_ARRAY_TYPE_PARAM_SPEC_LIST, parameters,
>       NULL);
>@@ -661,7 +667,10 @@ tp_connection_manager_end_introspection (TpConnectionManager *self,
> {
>   tp_connection_manager_reset_introspection (self);
> 
>-  DEBUG ("End of introspection, info source %u", self->info_source);
>+  DEBUG ("%s: end of introspection, info source %s (%d)",
>+      self->name,
>+      _tp_enum_to_nick_nonnull (TP_TYPE_CM_INFO_SOURCE, self->info_source),
>+      self->info_source);
>   g_signal_emit (self, signals[SIGNAL_GOT_INFO], 0, self->info_source);
>   tp_connection_manager_ready_or_failed (self, error);
> }
>@@ -722,7 +731,8 @@ tp_connection_manager_get_all_cb (TpProxy *proxy,
>           GHashTableIter iter;
>           gpointer k, v;
> 
>-          DEBUG ("%u Protocols from D-Bus", g_hash_table_size (protocols));
>+          DEBUG ("%s: %u Protocols from GetAll()",
>+              self->name, g_hash_table_size (protocols));
> 
>           g_assert (self->priv->found_protocols == NULL);
>           self->priv->found_protocols = g_hash_table_new_full (g_str_hash,
>@@ -755,10 +765,17 @@ tp_connection_manager_get_all_cb (TpProxy *proxy,
>                 }
>             }
>         }
>+      else
>+        {
>+          DEBUG ("%s: no Protocols property in GetAll() (old CM?)",
>+              self->name);
>+        }
>     }
>   else
>     {
>-      DEBUG ("Ignoring error getting ConnectionManager properties: %s %d: %s",
>+      DEBUG ("%s: ignoring error getting CM properties (old CM?): "
>+          "%s %d: %s",
>+          self->name,
>           g_quark_to_string (error->domain), error->code, error->message);
>     }
> 
>@@ -776,9 +793,11 @@ tp_connection_manager_continue_introspection (TpConnectionManager *self)
> {
>   gchar *next_protocol;
> 
>+  DEBUG ("%s", self->name);
>+
>   if (self->priv->introspection_step == INTROSPECT_IDLE)
>     {
>-      DEBUG ("calling GetAll on CM");
>+      DEBUG ("%s: calling GetAll on CM", self->name);
>       self->priv->introspection_step = INTROSPECT_GETTING_PROPERTIES;
>       self->priv->introspection_call = tp_cli_dbus_properties_call_get_all (
>           self, -1, TP_IFACE_CONNECTION_MANAGER,
>@@ -792,7 +811,7 @@ tp_connection_manager_continue_introspection (TpConnectionManager *self)
> 
>       if (self->priv->found_protocols == NULL)
>         {
>-          DEBUG ("calling ListProtocols on CM");
>+          DEBUG ("%s: calling legacy ListProtocols on CM", self->name);
>           self->priv->introspection_step = INTROSPECT_LISTING_PROTOCOLS;
>           self->priv->introspection_call =
>             tp_cli_connection_manager_call_list_protocols (self, -1,
>@@ -832,6 +851,8 @@ tp_connection_manager_continue_introspection (TpConnectionManager *self)
>       next_protocol = g_ptr_array_remove_index_fast (
>           self->priv->pending_protocols, 0);
>       self->priv->introspection_step = INTROSPECT_GETTING_PARAMETERS;
>+      DEBUG ("%s/%s: calling legacy ListProtocols",
>+          self->name, next_protocol);
>       self->priv->introspection_call =
>           tp_cli_connection_manager_call_get_parameters (self, -1,
>               next_protocol, tp_connection_manager_got_parameters,
>@@ -854,12 +875,16 @@ tp_connection_manager_got_protocols (TpConnectionManager *self,
> 
>   if (error != NULL)
>     {
>-      DEBUG ("Failed: %s", error->message);
>+      DEBUG ("%s: legacy GetProtocols() failed: %s #%d: %s",
>+          self->name,
>+          g_quark_to_string (error->domain), error->code, error->message);
> 
>       if (!self->running)
>         {
>           /* ListProtocols failed to start it - we assume this is because
>            * activation failed */
>+          DEBUG ("%s: ListProtocols didn't start it: activation failure?",
>+              self->name);
>           g_signal_emit (self, signals[SIGNAL_EXITED], 0);
>         }
> 
>@@ -870,7 +895,7 @@ tp_connection_manager_got_protocols (TpConnectionManager *self,
>   for (iter = protocols; *iter != NULL; iter++)
>     i++;
> 
>-  DEBUG ("Succeeded with %u protocols", i);
>+  DEBUG ("%s: legacy GetProtocols() returned %u protocols", self->name, i);
> 
>   g_assert (self->priv->found_protocols == NULL);
>   self->priv->found_protocols = g_hash_table_new_full (g_str_hash,
>@@ -883,7 +908,7 @@ tp_connection_manager_got_protocols (TpConnectionManager *self,
>     {
>       if (!tp_connection_manager_check_valid_protocol_name (*iter, NULL))
>         {
>-          DEBUG ("Protocol %s has an invalid name", *iter);
>+          DEBUG ("%s: protocol %s has an invalid name", self->name, *iter);
>           continue;
>         }
> 
>@@ -943,13 +968,14 @@ tp_connection_manager_name_owner_changed_cb (TpDBusDaemon *bus,
>         {
>           if (self->priv->retried_introspection)
>             {
>-              DEBUG ("%s, twice: assuming fatal and not retrying", e.message);
>+              DEBUG ("%s: %s, twice: assuming fatal and not retrying",
>+                  self->name, e.message);
>               tp_connection_manager_end_introspection (self, &e);
>             }
>           else
>             {
>               self->priv->retried_introspection = TRUE;
>-              DEBUG ("%s: retrying", e.message);
>+              DEBUG ("%s: %s: retrying", self->name, e.message);
>               tp_connection_manager_reset_introspection (self);
>               tp_connection_manager_continue_introspection (self);
>             }
>@@ -959,6 +985,7 @@ tp_connection_manager_name_owner_changed_cb (TpDBusDaemon *bus,
>        * state, so we didn't *exit* as such. */
>       if (self->priv->name_known)
>         {
>+          DEBUG ("%s: exited", self->name);
>           g_signal_emit (self, signals[SIGNAL_EXITED], 0);
>         }
>     }
>@@ -967,8 +994,14 @@ tp_connection_manager_name_owner_changed_cb (TpDBusDaemon *bus,
>       /* represent an atomic change of ownership as if it was an exit and
>        * restart */
>       if (self->running)
>-        tp_connection_manager_name_owner_changed_cb (bus, name, "", self);
>+        {
>+          DEBUG ("%s: atomic name owner change, behaving as if it exited",
>+              self->name);
>+          tp_connection_manager_name_owner_changed_cb (bus, name, "", self);
>+          DEBUG ("%s: back to normal handling", self->name);
>+        }
> 
>+      DEBUG ("%s: is now running", self->name);
>       self->running = TRUE;
>       g_signal_emit (self, signals[SIGNAL_ACTIVATED], 0);
> 
>@@ -980,6 +1013,9 @@ tp_connection_manager_name_owner_changed_cb (TpDBusDaemon *bus,
>   /* if we haven't started introspecting yet, now would be a good time */
>   if (!self->priv->name_known)
>     {
>+      DEBUG ("%s: starting introspection now we know the name owner",
>+          self->name);
>+
>       g_assert (self->priv->manager_file_read_idle_id == 0);
> 
>       /* now we know whether we're running or not, we can try reading the
>@@ -989,6 +1025,9 @@ tp_connection_manager_name_owner_changed_cb (TpDBusDaemon *bus,
> 
>       if (self->priv->want_activation && self->priv->introspect_idle_id == 0)
>         {
>+          DEBUG ("%s: forcing introspection for its side-effect of "
>+              "activation",
>+              self->name);
>           /* ... but if activation was requested, we should also do that */
>           self->priv->introspect_idle_id = g_idle_add (
>               tp_connection_manager_idle_introspect, self);
>@@ -1087,14 +1126,16 @@ tp_connection_manager_idle_read_manager_file (gpointer data)
>           GHashTable *protocols;
>           GStrv interfaces = NULL;
> 
>-          DEBUG ("Reading %s", self->priv->manager_file);
>+          DEBUG ("%s: reading %s", self->name, self->priv->manager_file);
> 
>           if (!tp_connection_manager_read_file (
>               tp_proxy_get_dbus_daemon (self),
>               self->name, self->priv->manager_file, &protocols, &interfaces,
>               &error))
>             {
>-              DEBUG ("Failed to load %s: %s", self->priv->manager_file,
>+              DEBUG ("%s: failed to load %s: %s #%d: %s",
>+                  self->name, self->priv->manager_file,
>+                  g_quark_to_string (error->domain), error->code,
>                   error->message);
>               g_error_free (error);
>               error = NULL;
>@@ -1108,7 +1149,7 @@ tp_connection_manager_idle_read_manager_file (gpointer data)
>               self->priv->protocol_objects = protocols;
>               tp_connection_manager_update_protocol_structs (self);
> 
>-              DEBUG ("Got info from file");
>+              DEBUG ("%s: got info from file", self->name);
>               /* previously it must have been NONE */
>               self->info_source = TP_CM_INFO_SOURCE_FILE;
> 
>@@ -1126,15 +1167,21 @@ tp_connection_manager_idle_read_manager_file (gpointer data)
> 
>       if (self->priv->introspect_idle_id == 0)
>         {
>-          DEBUG ("no .manager file or failed to parse it, trying to activate "
>-              "CM instead");
>+          DEBUG ("%s: no .manager file or failed to parse it, trying to "
>+              "activate CM instead",
>+              self->name);
>           tp_connection_manager_idle_introspect (self);
>         }
>       else
>         {
>-          DEBUG ("no .manager file, but will activate CM soon anyway");
>+          DEBUG ("%s: no .manager file, but will activate CM soon anyway",
>+              self->name);
>         }
>-      /* else we're going to introspect soon anyway */
>+    }
>+  else
>+    {
>+      DEBUG ("%s: not reading manager file, %u protocols already discovered",
>+          self->name, g_hash_table_size (self->priv->protocol_objects));
>     }
> 
> out:
>@@ -1653,18 +1700,26 @@ tp_connection_manager_activate (TpConnectionManager *self)
>     {
>       if (self->running)
>         {
>-          DEBUG ("already running");
>+          DEBUG ("%s: already running", self->name);
>           return FALSE;
>         }
> 
>       if (self->priv->introspect_idle_id == 0)
>-        self->priv->introspect_idle_id = g_idle_add (
>-            tp_connection_manager_idle_introspect, self);
>+        {
>+          DEBUG ("%s: adding idle introspection", self->name);
>+          self->priv->introspect_idle_id = g_idle_add (
>+              tp_connection_manager_idle_introspect, self);
>+        }
>+      else
>+        {
>+          DEBUG ("%s: idle introspection already added", self->name);
>+        }
>     }
>   else
>     {
>       /* we'll activate later, when we know properly whether we're running */
>-      DEBUG ("queueing activation for when we know what's going on");
>+      DEBUG ("%s: queueing activation for when we know what's going on",
>+          self->name);
>       self->priv->want_activation = TRUE;
>     }
> 
>diff --git a/telepathy-glib/protocol.c b/telepathy-glib/protocol.c
>index e600059..b2935c0 100644
>--- a/telepathy-glib/protocol.c
>+++ b/telepathy-glib/protocol.c
>@@ -411,15 +411,22 @@ tp_protocol_check_for_core (TpProtocol *self)
>   value = tp_asv_lookup (props, TP_PROP_PROTOCOL_CONNECTION_INTERFACES);
> 
>   if (value == NULL || !G_VALUE_HOLDS (value, G_TYPE_STRV))
>-    return FALSE;
>+    {
>+      DEBUG ("Interfaces not found");
>+      return FALSE;
>+    }
> 
>   if (tp_asv_get_boxed (props, TP_PROP_PROTOCOL_REQUESTABLE_CHANNEL_CLASSES,
>         TP_ARRAY_TYPE_REQUESTABLE_CHANNEL_CLASS_LIST) == NULL)
>-    return FALSE;
>+    {
>+      DEBUG ("Requestable channel classes not found");
>+      return FALSE;
>+    }
> 
>   /* Interfaces has a sensible default, the empty list.
>    * VCardField, EnglishName and Icon have a sensible default, "". */
> 
>+  DEBUG ("Core feature ready");
>   return TRUE;
> }
> 
>@@ -464,12 +471,20 @@ tp_protocol_constructed (GObject *object)
> 
>   g_assert (self->priv->protocol_struct.name != NULL);
> 
>+  DEBUG ("%s/%s: new Protocol", self->priv->cm_name,
>+      self->priv->protocol_struct.name);
>+
>   if (self->priv->protocol_properties == NULL)
>     {
>+      DEBUG ("immutable properties not supplied");
>       had_immutables = FALSE;
>       self->priv->protocol_properties = g_hash_table_new_full (g_str_hash,
>           g_str_equal, g_free, (GDestroyNotify) tp_g_value_slice_free);
>     }
>+  else
>+    {
>+      DEBUG ("immutable properties already supplied");
>+    }
> 
>   self->priv->protocol_struct.params = tp_protocol_params_from_param_specs (
>         tp_asv_get_boxed (self->priv->protocol_properties,
>@@ -1529,10 +1544,12 @@ _tp_protocol_parse_manager_file (GKeyFile *file,
> 
>   if (!tp_connection_manager_check_valid_protocol_name (name, NULL))
>     {
>-      DEBUG ("Protocol '%s' has an invalid name", name);
>+      DEBUG ("%s: protocol '%s' has an invalid name", cm_debug_name, name);
>       return NULL;
>     }
> 
>+  DEBUG ("%s: reading protocol '%s' from manager file", cm_debug_name, name);
>+
>   keys = g_key_file_get_keys (file, group, NULL, NULL);
> 
>   i = 0;
>diff --git a/telepathy-glib/util-internal.h b/telepathy-glib/util-internal.h
>index 9410648..ec0e482 100644
>--- a/telepathy-glib/util-internal.h
>+++ b/telepathy-glib/util-internal.h
>@@ -49,6 +49,7 @@ GList * _tp_create_channel_request_list (TpSimpleClientFactory *factory,
> 
> gboolean _tp_enum_from_nick (GType enum_type, const gchar *nick, gint *value);
> const gchar *_tp_enum_to_nick (GType enum_type, gint value);
>+const gchar *_tp_enum_to_nick_nonnull (GType enum_type, gint value);
> 
> #define _tp_implement_finish_void(source, tag) \
>     if (g_simple_async_result_propagate_error (\
>diff --git a/telepathy-glib/util.c b/telepathy-glib/util.c
>index 91a42d5..932776c 100644
>--- a/telepathy-glib/util.c
>+++ b/telepathy-glib/util.c
>@@ -1747,6 +1747,32 @@ _tp_enum_to_nick (
>     return NULL;
> }
> 
>+/*
>+ * _tp_enum_to_nick_nonnull:
>+ *
>+ * The same as _tp_enum_to_nick, but always returns non-NULL.
>+ */
>+const gchar *
>+_tp_enum_to_nick_nonnull (
>+    GType enum_type,
>+    gint value)
>+{
>+  GEnumClass *klass = g_type_class_ref (enum_type);
>+  GEnumValue *enum_value;
>+
>+  g_return_val_if_fail (klass != NULL, "(incorrect class)");
>+
>+  enum_value = g_enum_get_value (klass, value);
>+  g_type_class_unref (klass);
>+
>+  if (enum_value == NULL)
>+    return "(out-of-range value)";
>+  else if (enum_value->value_nick == NULL)
>+    return "(value with no nickname)";
>+  else
>+    return enum_value->value_nick;
>+}
>+
> gboolean
> _tp_bind_connection_status_to_boolean (GBinding *binding,
>     const GValue *src_value,
>-- 
>1.8.4.rc3
>

Actions: View | Splinter Review

Attachments on bug 68390: 84400 | 84401 | 84402 | 86446

Use of freedesktop.org services, including Bugzilla, is subject to our Code of Conduct. How we collect and use information is described in our Privacy Policy.