make -C tests/<dir> <test name>.gdb
Then use gdb as normal.
+
+Profiling folks
+===============
+
+Folks has various profiling points throughout its startup code, in order to be
+able to profile the startup process. In order to use this:
+ 1. Compile folks with --enable-profiling.
+ 2. strace -ttt -f -o /tmp/logfile folks-inspect # or some other folks program
+ 3. python plot-timeline.py -o output.png /tmp/logfile
+ 4. Examine output.png for obvious problems
+
+This is based on Federico Mena Quintero’s plot-timeline.py, described on:
+http://people.gnome.org/~federico/news-2006-03.html#timeline-tools. The Python
+script itself can be downloaded from
+http://gitorious.org/projects/performance-scripts.
• Bug 678474 — potential-match should be smarter with accents
• Bug 678781 — memory leak in e-d-s backend
• Bug 678811 — Fix eds backend unit tests
+• Bug 678734 — Add profiling API
API changes:
eds_deps = \
folks \
+ folks-internal \
folks-eds \
gee-1.0 \
gio-2.0 \
$(AM_LIBADD) \
$(top_builddir)/backends/eds/lib/libfolks-eds.la \
$(top_builddir)/folks/libfolks.la \
+ $(top_builddir)/folks/libfolks-internal.la \
$(GIO_LIBS) \
$(GLIB_LIBS) \
$(GEE_LIBS) \
*/
public override async void prepare () throws GLib.Error
{
+ Internal.profiling_start ("preparing Eds.Backend");
+
lock (this._is_prepared)
{
if (this._is_prepared || this._prepare_pending)
this._prepare_pending = false;
}
}
+
+ Internal.profiling_end ("preparing Eds.Backend");
}
/**
*/
public override async void prepare () throws PersonaStoreError
{
+ Internal.profiling_start ("preparing Edsf.PersonaStore (ID: %s)",
+ this.id);
+
/* FIXME: https://bugzilla.gnome.org/show_bug.cgi?id=652637 */
lock (this._is_prepared)
{
* addressbook.open() will fail if we don't. */
this._source_registry = yield create_source_registry ();
+ Internal.profiling_point ("created SourceRegistry in " +
+ "Edsf.PersonaStore (ID: %s)", this.id);
+
/* We know _source_registry != null because otherwise
* create_source_registry() would've thrown an error. */
((!) this._source_registry).source_removed.connect (
debug ("Successfully finished opening address book %p for " +
"persona store ‘%s’ (%p).", this._addressbook, this.id, this);
+ Internal.profiling_point ("opened address book in " +
+ "Edsf.PersonaStore (ID: %s)", this.id);
+
this._notify_if_default ();
this._update_trust_level ();
}
yield ((!) this._addressbook).get_backend_property (
"supported-fields", null, out supported_fields);
+ Internal.profiling_point ("got supported fields in " +
+ "Edsf.PersonaStore (ID: %s)", this.id);
+
var prop_set = new HashSet<string> ();
/* We get a comma-separated list of fields back. */
yield ((!) this._addressbook).get_backend_property (
"capabilities", null, out capabilities);
+ Internal.profiling_point ("got capabilities in " +
+ "Edsf.PersonaStore (ID: %s)", this.id);
+
if (capabilities != null)
{
string[] caps = ((!) capabilities).split (",");
got_view = yield ((!) this._addressbook).get_view (
this._query_str, null, out this._ebookview);
+ Internal.profiling_point ("opened book view in " +
+ "Edsf.PersonaStore (ID: %s)", this.id);
+
if (got_view == false)
{
throw new PersonaStoreError.INVALID_ARGUMENT (
this.notify_property ("is-quiescent");
}
}
+
+ Internal.profiling_end ("preparing Edsf.PersonaStore");
}
/* Temporaries for _open_address_book(). See the complaint below. */
warning ("Error in address book view query: %s", err.message);
}
+ Internal.profiling_point ("initial query complete in " +
+ "Edsf.PersonaStore (ID: %s)", this.id);
+
/* The initial query is complete, so signal that we've reached
* quiescence (even if there was an error). */
if (this._is_quiescent == false)
--vapidir=. \
--vapidir=$(top_srcdir)/folks \
--pkg folks \
+ --pkg folks-internal \
--pkg gee-1.0 \
--pkg gio-2.0 \
--pkg gobject-2.0 \
$(GLIB_LIBS) \
$(GEE_LIBS) \
$(top_builddir)/folks/libfolks.la \
+ $(top_builddir)/folks/libfolks-internal.la \
$(NULL)
key_file_la_LDFLAGS = \
*/
public override async void prepare () throws GLib.Error
{
+ Internal.profiling_start ("preparing Kf.Backend");
+
lock (this._is_prepared)
{
if (this._is_prepared || this._prepare_pending)
this._prepare_pending = false;
}
}
+
+ Internal.profiling_end ("preparing Kf.Backend");
}
/**
*/
public override async void prepare ()
{
+ Internal.profiling_start ("preparing Kf.PersonaStore (ID: %s)", this.id);
+
lock (this._is_prepared)
{
if (this._is_prepared || this._prepare_pending)
null);
unowned string contents_s = (string) contents;
+ Internal.profiling_point ("loaded file in " +
+ "Kf.PersonaStore (ID: %s)", this.id);
+
if (contents_s.length > 0)
{
this._key_file.load_from_data (contents_s,
contents_s.length,
KeyFileFlags.KEEP_COMMENTS);
+
+ Internal.profiling_point ("parsed data in " +
+ "Kf.PersonaStore (ID: %s)", this.id);
}
break;
}
this._prepare_pending = false;
}
}
+
+ Internal.profiling_end ("preparing Kf.PersonaStore (ID: %s)", this.id);
}
/**
libsocialweb_deps = \
folks \
+ folks-internal \
folks-libsocialweb \
gee-1.0 \
gio-2.0 \
$(GLIB_LIBS) \
$(GEE_LIBS) \
$(top_builddir)/folks/libfolks.la \
+ $(top_builddir)/folks/libfolks-internal.la \
$(SW_CLIENT_LIBS) \
lib/libfolks-libsocialweb.la \
$(NULL)
*/
public override async void prepare () throws GLib.Error
{
+ Internal.profiling_start ("preparing Swf.PersonaStore (ID: %s)", this.id);
+
lock (this._is_prepared)
{
if (!this._is_prepared && !this._prepare_pending)
{
caps = yield this._get_static_capabilities ();
+ Internal.profiling_point ("got capabilities in " +
+ "Swf.PersonaStore (ID: %s)", this.id);
+
if (caps == null)
{
throw new PersonaStoreError.INVALID_ARGUMENT (
new HashTable<weak string, weak string> (str_hash,
str_equal));
+ Internal.profiling_point ("opened view in Swf.PersonaStore " +
+ "(ID: %s)", this.id);
+
/* Propagate errors from the contacts_query_open_view()
* callback. */
if (contact_view == null)
this._contact_view.start ();
}
}
+
+ Internal.profiling_end ("preparing Swf.PersonaStore (ID: %s)", this.id);
}
private void contacts_added_cb (GLib.List<unowned Contact> contacts)
*/
public override async void prepare () throws GLib.Error
{
+ Internal.profiling_start ("preparing Sw.Backend");
+
lock (this._is_prepared)
{
if (!this._is_prepared && !this._prepare_pending)
});
}
}
+
+ Internal.profiling_end ("preparing Sw.Backend");
}
/**
telepathy_deps = \
folks \
+ folks-internal \
folks-telepathy \
gee-1.0 \
gio-2.0 \
$(GLIB_LIBS) \
$(GEE_LIBS) \
$(top_builddir)/folks/libfolks.la \
+ $(top_builddir)/folks/libfolks-internal.la \
$(TP_GLIB_LIBS) \
lib/libfolks-telepathy.la \
$(NULL)
*/
public override async void prepare () throws GLib.Error
{
+ Internal.profiling_start ("preparing Tpf.PersonaStore (ID: %s)", this.id);
+
lock (this._is_prepared)
{
if (this._is_prepared || this._prepare_pending)
}
});
+ Internal.profiling_point ("created account manager in " +
+ "Tpf.PersonaStore (ID: %s)", this.id);
+
this._favourite_ids.clear ();
this._logger = new Logger (this.id);
this._logger.invalidated.connect (
this._logger_invalidated_cb);
this._logger.favourite_contacts_changed.connect (
this._favourite_contacts_changed_cb);
+ Internal.profiling_start ("initialising favourite contacts in " +
+ "Tpf.PersonaStore (ID: %s)", this.id);
this._initialise_favourite_contacts.begin ((o, r) =>
{
- debug ("FAVOURITE INIT DONE");
try
{
this._initialise_favourite_contacts.end (r);
+ Internal.profiling_end ("initialising favourite " +
+ "contacts in Tpf.PersonaStore (ID: %s)", this.id);
}
catch (GLib.Error e)
{
}
});
+ Internal.profiling_point ("created logger in Tpf.PersonaStore " +
+ "(ID: %s)", this.id);
+
this.account.notify["connection"].connect (
this._notify_connection_cb);
this._force_quiescent ();
}
+ Internal.profiling_point ("loaded cache in Tpf.PersonaStore " +
+ "(ID: %s)", this.id);
+
this._is_prepared = true;
this.notify_property ("is-prepared");
}
this._prepare_pending = false;
}
}
+
+ Internal.profiling_end ("preparing Tpf.PersonaStore (ID: %s)", this.id);
}
private void _account_manager_invalidated_cb (uint domain, int code,
debug ("_notify_connection_cb_async() for Tpf.PersonaStore %p ('%s').",
this, this.id);
+ Internal.profiling_start ("notify connection for Tpf.PersonaStore " +
+ "(ID: %s)", this.id);
+
/* Ensure the connection is prepared as necessary. */
yield this.account.connection.prepare_async ({
TelepathyGLib.Connection.get_feature_quark_contact_list (),
this._conn.notify["contact-list-state"].connect (this._contact_list_state_changed_cb);
this._contact_list_state_changed_cb (this._conn, null);
+
+ Internal.profiling_end ("notify connection for Tpf.PersonaStore " +
+ "(ID: %s)", this.id);
}
private void _marshall_supported_fields ()
*/
public override async void prepare () throws GLib.Error
{
+ Internal.profiling_start ("preparing Tp.Backend");
+
lock (this._is_prepared)
{
if (this._is_prepared || this._prepare_pending)
this._prepare_pending = false;
}
}
+
+ Internal.profiling_end ("preparing Tp.Backend");
}
/**
tracker_deps = \
folks \
+ folks-internal \
folks-tracker \
gee-1.0 \
gio-2.0 \
$(GLIB_LIBS) \
$(GEE_LIBS) \
$(top_builddir)/folks/libfolks.la \
+ $(top_builddir)/folks/libfolks-internal.la \
$(TRACKER_SPARQL_LIBS) \
$(top_builddir)/backends/tracker/lib/libfolks-tracker.la \
$(NULL)
--vapidir=. \
--vapidir=$(top_srcdir)/folks \
--pkg folks \
+ --pkg folks-internal \
--pkg gobject-2.0 \
--pkg gio-2.0 \
--pkg gee-1.0 \
$(GLIB_LIBS) \
$(GEE_LIBS) \
$(top_builddir)/folks/libfolks.la \
+ $(top_builddir)/folks/libfolks-internal.la \
$(TRACKER_SPARQL_LIBS) \
$(NULL)
*/
public override async void prepare () throws GLib.Error
{
+ Internal.profiling_start ("preparing Trf.PersonaStore (ID: %s)", this.id);
+
lock (this._is_prepared)
{
if (this._is_prepared || this._prepare_pending)
this._connection =
yield Tracker.Sparql.Connection.get_async ();
+ Internal.profiling_point ("got connection in " +
+ "Trf.PersonaStore (ID: %s)", this.id);
+
yield this._build_predicates_table ();
+
+ Internal.profiling_point ("build predicates table in " +
+ "Trf.PersonaStore (ID: %s)", this.id);
+
yield this._do_add_contacts (this._INITIAL_QUERY.printf (""));
+ Internal.profiling_point ("added contacts in " +
+ "Trf.PersonaStore (ID: %s)", this.id);
+
/* Don't add a match rule for all signals from Tracker but
* only for GraphUpdated with the specific class we need. We
* don't want to be woken up for irrelevent updates on the
Trf.OntologyDefs.PERSON_CLASS, GLib.DBusSignalFlags.NONE,
this._graph_updated_cb);
+ Internal.profiling_point ("got resources proxy in " +
+ "Trf.PersonaStore (ID: %s)", this.id);
+
this._is_prepared = true;
this.notify_property ("is-prepared");
this._prepare_pending = false;
}
}
+
+ Internal.profiling_end ("preparing Trf.PersonaStore (ID: %s)", this.id);
}
public int get_favorite_id ()
*/
public override async void prepare () throws GLib.Error
{
+ Internal.profiling_start ("preparing Tr.Backend");
+
lock (this._is_prepared)
{
if (this._is_prepared || this._prepare_pending)
this._prepare_pending = false;
}
}
+
+ Internal.profiling_end ("preparing Tr.Backend");
}
/**
AC_SUBST([ERROR_VALAFLAGS])
# -----------------------------------------------------------
+# Profiling
+# -----------------------------------------------------------
+
+AC_ARG_ENABLE([profiling],
+ AS_HELP_STRING([--enable-profiling],
+ [Enable building profiling points]),
+ [enable_profiling=$enableval],
+ [enable_profiling=no])
+AM_CONDITIONAL([ENABLE_PROFILING], [test "$enable_profiling" = "yes"])
+
+# -----------------------------------------------------------
# Final output
# -----------------------------------------------------------
--library=folks-internal \
--vapidir=. \
--pkg gobject-2.0 \
+ --pkg gio-2.0 \
--pkg gee-1.0 \
+ --pkg posix \
--vapi folks-internal.vapi \
-H folks-internal.h \
$(NULL)
+if ENABLE_PROFILING
+libfolks_internal_la_VALAFLAGS += --define=ENABLE_PROFILING
+endif
libfolks_internal_la_CFLAGS = \
$(AM_CFLAGS) \
*/
public async void prepare ()
{
+ Internal.profiling_start ("preparing BackendStore");
+
/* (re-)load the list of disabled backends */
yield this._load_disabled_backend_names ();
- if (this._is_prepared == true)
- return;
- this._is_prepared = true;
+ if (this._is_prepared == false)
+ {
+ this._is_prepared = true;
+ this.notify_property ("is-prepared");
+ }
- this.notify_property ("is-prepared");
+ Internal.profiling_end ("preparing BackendStore");
}
/**
{
assert (Module.supported());
+ Internal.profiling_start ("loading backends in BackendStore");
+
yield this.prepare ();
/* unload backends that have been disabled since they were loaded */
yield this._backend_unload_if_needed (backend_existing);
}
+ Internal.profiling_point ("unloaded backends in BackendStore");
+
string? _path = Environment.get_variable ("FOLKS_BACKEND_PATH");
string path;
}
}
+ Internal.profiling_point ("found modules in BackendStore");
+
/* this will load any new modules found in the backends dir and will
* prepare and unprepare backends such that they match the state in the
* backend store key file */
foreach (var module in modules.values)
this._load_module_from_file (module);
+ Internal.profiling_point ("loaded modules in BackendStore");
+
/* this is populated indirectly from _load_module_from_file(), above */
+ var backends_remaining = 1;
foreach (var backend in this._backend_hash.values)
- yield this._backend_load_if_needed (backend);
+ {
+ backends_remaining++;
+ this._backend_load_if_needed.begin (backend, (o, r) =>
+ {
+ this._backend_load_if_needed.end (r);
+ backends_remaining--;
+
+ if (backends_remaining == 0)
+ {
+ this.load_backends.callback ();
+ }
+ });
+ }
+ backends_remaining--;
+ if (backends_remaining > 0)
+ {
+ yield;
+ }
+
+ Internal.profiling_end ("loading backends in BackendStore");
}
private async void _backend_load_if_needed (Backend backend)
*/
public async void prepare () throws GLib.Error
{
+ Internal.profiling_start ("preparing IndividualAggregator");
+
/* Once this async function returns, all the {@link Backend}s will have
* been prepared (though no {@link PersonaStore}s are guaranteed to be
* available yet). This last guarantee is new as of version 0.2.0. */
this._prepare_pending = false;
}
}
+
+ Internal.profiling_end ("preparing IndividualAggregator");
}
/**
return;
}
+ Internal.profiling_point ("emitting " +
+ "IndividualAggregator::individuals-changed");
+
_added = (added != null) ? (!) added : new HashSet<Individual> ();
_removed = (removed != null) ? (!) removed : new HashSet<Individual> ();
this._configured_primary_store_id);
}
+ Internal.profiling_point ("reached quiescence in " +
+ "IndividualAggregator");
+
this._is_quiescent = true;
this.notify_property ("is-quiescent");
* Raul Gutierrez Segales <raul.gutierrez.segales@collabora.co.uk>
*/
+using GLib;
using Gee;
+using Posix;
namespace Folks.Internal
{
return true;
}
+
+#if ENABLE_PROFILING
+ /* See: http://people.gnome.org/~federico/news-2006-03.html#timeline-tools */
+ private static void profiling_markv (string format, va_list args)
+ {
+ var formatted = format.vprintf (args);
+ var str = "MARK: %s-%p: %s".printf (Environment.get_prgname (), Thread.self<void> (), formatted);
+ access (str, F_OK);
+ }
+#endif
+
+ /**
+ * Emit a profiling point.
+ *
+ * This emits a profiling point with the given message (printf-style), which
+ * can be picked up by profiling tools and timing information extracted.
+ *
+ * @param format printf-style message format
+ * @param ... message arguments
+ * @since UNRELEASED
+ */
+ public static void profiling_point (string format, ...)
+ {
+#if ENABLE_PROFILING
+ var args = va_list ();
+ Internal.profiling_markv (format, args);
+#endif
+ }
+
+ /**
+ * Start a profiling block.
+ *
+ * This emits a profiling start point with the given message (printf-style),
+ * which can be picked up by profiling tools and timing information extracted.
+ *
+ * This is typically used in a pair with {@link Internal.profiling_end} to
+ * delimit blocks of processing which need timing.
+ *
+ * @param format printf-style message format
+ * @param ... message arguments
+ * @since UNRELEASED
+ */
+ public static void profiling_start (string format, ...)
+ {
+#if ENABLE_PROFILING
+ var args = va_list ();
+ Internal.profiling_markv ("START: " + format, args);
+#endif
+ }
+
+ /**
+ * End a profiling block.
+ *
+ * This emits a profiling end point with the given message (printf-style),
+ * which can be picked up by profiling tools and timing information extracted.
+ *
+ * This is typically used in a pair with {@link Internal.profiling_start} to
+ * delimit blocks of processing which need timing.
+ *
+ * @param format printf-style message format
+ * @param ... message arguments
+ * @since UNRELEASED
+ */
+ public static void profiling_end (string format, ...)
+ {
+#if ENABLE_PROFILING
+ var args = va_list ();
+ Internal.profiling_markv ("END: " + format, args);
+#endif
+ }
}
_removed = new HashSet<Persona> ();
}
+ Internal.profiling_point ("emitting PersonaStore::personas-changed " +
+ "(ID: %s)", this.id);
+
// We've now guaranteed that both _added and _removed are non-null.
this.personas_changed (((!) _added).read_only_view,
((!) _removed).read_only_view, message, actor, reason);