From d86a89c9d471883d9f1d87679848bf5bd2281008 Mon Sep 17 00:00:00 2001 From: Simon McVittie 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