[tracker/index-profile] Some indexing strace-profiling markers added. See "Federico's performance scripts" for how to use.



commit 3084c9bd26d7918c781cf1b49a3dd9b8b25be20a
Author: Mikael Ottela <mikael ottela ixonos com>
Date:   Mon Aug 9 00:14:15 2010 +0300

    Some indexing strace-profiling markers added. See "Federico's performance
    scripts" for how to use.

 src/libtracker-miner/tracker-miner-fs.c     |   41 ++++++++++++++++++++++++++-
 src/libtracker-miner/tracker-miner-object.c |   19 ++++++++++++
 src/miners/fs/tracker-miner-files.c         |   38 +++++++++++++++++++++++++
 src/tracker-store/tracker-resources.c       |   29 +++++++++++++++++++
 src/tracker-store/tracker-store.c           |   21 ++++++++++++++
 5 files changed, 147 insertions(+), 1 deletions(-)
---
diff --git a/src/libtracker-miner/tracker-miner-fs.c b/src/libtracker-miner/tracker-miner-fs.c
index a14ec4a..9c42f82 100644
--- a/src/libtracker-miner/tracker-miner-fs.c
+++ b/src/libtracker-miner/tracker-miner-fs.c
@@ -31,6 +31,23 @@
 #include "tracker-utils.h"
 #include "tracker-thumbnailer.h"
 
+static void
+program_log (const char *format, ...)
+{
+        va_list args;
+        char *formatted, *str;
+
+        va_start (args, format);
+        formatted = g_strdup_vprintf (format, args);
+        va_end (args);
+
+        str = g_strdup_printf ("MARK: %s: %s", g_get_prgname(), formatted);
+        g_free (formatted);
+
+        access (str, F_OK);
+        g_free (str);
+}
+
 /* If defined will print the tree from GNode while running */
 #undef ENABLE_TREE_DEBUGGING
 /* If defined will print contents of populated IRI cache while running */
@@ -954,6 +971,8 @@ commit_cb (GObject      *object,
 	TrackerMiner *miner = TRACKER_MINER (object);
 	GError *error = NULL;
 
+	program_log ("commit_cb: Last tracker_miner_commit is done.");
+
 	tracker_miner_commit_finish (miner, result, &error);
 
 	if (error) {
@@ -1028,6 +1047,8 @@ sparql_update_cb (GObject      *object,
 	ProcessData *data;
 	GError *error = NULL;
 
+	program_log ("sparql_update_cb");
+
 	tracker_miner_execute_update_finish (TRACKER_MINER (object), result, &error);
 
 	fs = TRACKER_MINER_FS (object);
@@ -1074,6 +1095,8 @@ sparql_update_cb (GObject      *object,
 	process_data_free (data);
 
 	item_queue_handlers_set_up (fs);
+
+	program_log ("sparql_update_cb done");
 }
 
 static void
@@ -1443,6 +1466,8 @@ item_add_or_update_cb (TrackerMinerFS *fs,
 
 	uri = g_file_get_uri (data->file);
 
+	program_log ("item_add_or_update_cb for %s", uri);
+
 	if (error) {
 		ProcessData *first_item_data;
 		GList *last;
@@ -1503,6 +1528,8 @@ item_add_or_update_cb (TrackerMinerFS *fs,
 		g_free (full_sparql);
 	}
 
+	program_log ("item_add_or_update_cb done");
+
 	g_free (uri);
 }
 
@@ -1522,6 +1549,8 @@ item_add_or_update (TrackerMinerFS *fs,
 	priv = fs->private;
 	retval = TRUE;
 
+	program_log ("item_add_or_update for %s", g_file_get_uri (file));
+
 	cancellable = g_cancellable_new ();
 	sparql = tracker_sparql_builder_new_update ();
 	g_object_ref (file);
@@ -1579,6 +1608,8 @@ item_add_or_update (TrackerMinerFS *fs,
 	g_object_unref (cancellable);
 	g_object_unref (sparql);
 
+	program_log ("item_add_or_update done");
+
 	return retval;
 }
 
@@ -2226,6 +2257,8 @@ item_queue_handlers_cb (gpointer user_data)
 	static GTimeVal time_last = { 0 };
 	gboolean keep_processing = TRUE;
 
+	program_log ("item_queue_handlers_cb");
+
 	fs = user_data;
 	queue = item_queue_get_next_file (fs, &file, &source_file);
 
@@ -2236,6 +2269,7 @@ item_queue_handlers_cb (gpointer user_data)
 		 * the next directories batch.
 		 */
 		fs->private->item_queues_handler_id = 0;
+		program_log ("QUEUE_WAIT");
 		return FALSE;
 	}
 
@@ -2247,7 +2281,7 @@ item_queue_handlers_cb (gpointer user_data)
 		if (source_file) {
 			g_object_unref (source_file);
 		}
-
+		program_log ("QUEUE_DELETED");
 		return TRUE;
 	}
 
@@ -2337,6 +2371,8 @@ item_queue_handlers_cb (gpointer user_data)
 		g_object_unref (source_file);
 	}
 
+	program_log ("item_queue_handlers_cb done");
+
 	if (!keep_processing) {
 		fs->private->item_queues_handler_id = 0;
 		return FALSE;
@@ -2350,6 +2386,7 @@ item_queue_handlers_cb (gpointer user_data)
 
 		return TRUE;
 	}
+
 }
 
 static guint
@@ -2400,6 +2437,8 @@ item_queue_handlers_set_up (TrackerMinerFS *fs)
 		_tracker_idle_add (fs,
 		                   item_queue_handlers_cb,
 		                   fs);
+
+	program_log ("item_queue_handlers_set_up");
 }
 
 static gboolean
diff --git a/src/libtracker-miner/tracker-miner-object.c b/src/libtracker-miner/tracker-miner-object.c
index 96a8d94..5bc10f9 100644
--- a/src/libtracker-miner/tracker-miner-object.c
+++ b/src/libtracker-miner/tracker-miner-object.c
@@ -28,6 +28,23 @@
 #include "tracker-miner-glue.h"
 #include "tracker-dbus.h"
 
+static void
+program_log (const char *format, ...)
+{
+        va_list args;
+        char *formatted, *str;
+
+        va_start (args, format);
+        formatted = g_strdup_vprintf (format, args);
+        va_end (args);
+
+        str = g_strdup_printf ("MARK: %s: %s", g_get_prgname(), formatted);
+        g_free (formatted);
+
+        access (str, F_OK);
+        g_free (str);
+}
+
 /**
  * SECTION:tracker-miner
  * @short_description: Abstract base class for data miners
@@ -972,6 +989,8 @@ tracker_miner_commit (TrackerMiner        *miner,
 {
 	AsyncCallData *data;
 
+	program_log ("tracker_miner_commit");
+
 	g_return_if_fail (TRACKER_IS_MINER (miner));
 	g_return_if_fail (!cancellable || G_IS_CANCELLABLE (cancellable));
 
diff --git a/src/miners/fs/tracker-miner-files.c b/src/miners/fs/tracker-miner-files.c
index b8d83eb..2e87e4d 100644
--- a/src/miners/fs/tracker-miner-files.c
+++ b/src/miners/fs/tracker-miner-files.c
@@ -63,6 +63,23 @@
 
 #define TRACKER_MINER_FILES_GET_PRIVATE(o) (G_TYPE_INSTANCE_GET_PRIVATE ((o), TRACKER_TYPE_MINER_FILES, TrackerMinerFilesPrivate))
 
+static void
+program_log (const char *format, ...)
+{
+        va_list args;
+        char *formatted, *str;
+
+        va_start (args, format);
+        formatted = g_strdup_vprintf (format, args);
+        va_end (args);
+
+        str = g_strdup_printf ("MARK: %s: %s", g_get_prgname(), formatted);
+        g_free (formatted);
+
+        access (str, F_OK);
+        g_free (str);
+}
+
 static GQuark miner_files_error_quark = 0;
 
 typedef struct ProcessFileData ProcessFileData;
@@ -1882,6 +1899,8 @@ extractor_get_embedded_metadata_cb (DBusGProxy *proxy,
 	ProcessFileData *data = user_data;
 	const gchar *uuid;
 
+	program_log ("extractor_get_embedded_metadata_cb for %s", g_file_get_uri (data->file));
+
 	if (error) {
 		/* Something bad happened, notify about the error */
 		tracker_miner_fs_file_notify (TRACKER_MINER_FS (data->miner), data->file, error);
@@ -1964,6 +1983,8 @@ extractor_get_embedded_metadata_cb (DBusGProxy *proxy,
 	g_free (preupdate);
 	g_free (sparql);
 #endif /* HAVE_DBUS_FD_PASSING */
+
+	program_log ("embedded_metadata_cd done");
 }
 
 static void
@@ -2091,6 +2112,9 @@ extractor_get_embedded_metadata (ProcessFileData *data,
                                  const gchar     *uri,
                                  const gchar     *mime_type)
 {
+
+	program_log ("extractor_get_embedded_metadata for %s. Calling extractor.", uri);
+
 #ifdef HAVE_DBUS_FD_PASSING
 	get_metadata_fast_async (dbus_g_connection_get_connection (data->miner->private->connection),
 	                         uri,
@@ -2125,6 +2149,8 @@ process_file_cb (GObject      *object,
 	GError *error = NULL;
 	gboolean is_iri;
 
+	program_log ("process_file_cb");
+
 	data = user_data;
 	file = G_FILE (object);
 	sparql = data->sparql;
@@ -2142,6 +2168,8 @@ process_file_cb (GObject      *object,
 	mime_type = g_file_info_get_content_type (file_info);
 	urn = miner_files_get_file_urn (TRACKER_MINER_FILES (data->miner), file, &is_iri);
 
+	program_log ("process_file_cb for %s. Starting to build sparql", uri);
+
 	tracker_sparql_builder_insert_silent_open (sparql, TRACKER_MINER_FS_GRAPH_URN);
 
 	if (is_iri) {
@@ -2201,6 +2229,8 @@ process_file_cb (GObject      *object,
 
 	g_object_unref (file_info);
 	g_free (uri);
+
+	program_log ("process_file_cb done");
 }
 
 static gboolean
@@ -2212,6 +2242,8 @@ miner_files_process_file (TrackerMinerFS       *fs,
 	ProcessFileData *data;
 	const gchar *attrs;
 
+	program_log ("miner_files_process_file for %s", g_file_get_uri (file));
+
 	data = g_slice_new0 (ProcessFileData);
 	data->miner = g_object_ref (fs);
 	data->cancellable = g_object_ref (cancellable);
@@ -2233,6 +2265,8 @@ miner_files_process_file (TrackerMinerFS       *fs,
 	                         process_file_cb,
 	                         data);
 
+	program_log ("miner_files_process_file done");
+
 	return TRUE;
 }
 
@@ -2373,6 +2407,8 @@ tracker_miner_files_check_file (GFile  *file,
 	gchar *path;
 	gboolean should_process;
 
+	program_log ("tracker_miner_files_check_file for %s", g_file_get_uri (file));
+
 	file_info = NULL;
 	should_process = FALSE;
 	basename = NULL;
@@ -2432,6 +2468,8 @@ tracker_miner_files_check_directory (GFile  *file,
 	gboolean should_process;
 	gboolean is_hidden;
 
+	program_log ("tracker_miner_files_check_directory for %s", g_file_get_uri (file));
+
 	should_process = FALSE;
 	basename = NULL;
 
diff --git a/src/tracker-store/tracker-resources.c b/src/tracker-store/tracker-resources.c
index 3d33bb0..31792f0 100644
--- a/src/tracker-store/tracker-resources.c
+++ b/src/tracker-store/tracker-resources.c
@@ -45,6 +45,23 @@
 #define RDF_PREFIX TRACKER_RDF_PREFIX
 #define RDF_TYPE RDF_PREFIX "type"
 
+static void
+program_log (const char *format, ...)
+{
+        va_list args;
+        char *formatted, *str;
+
+        va_start (args, format);
+        formatted = g_strdup_vprintf (format, args);
+        va_end (args);
+
+        str = g_strdup_printf ("MARK: %s: %s", g_get_prgname(), formatted);
+        g_free (formatted);
+
+        access (str, F_OK);
+        g_free (str);
+}
+
 /* I *know* that this is some arbitrary number that doesn't seem to
  * resemble anything. In fact it's what I experimentally measured to
  * be a good value on a default Debian testing which has
@@ -355,6 +372,8 @@ update_callback (GError *error, gpointer user_data)
 {
 	TrackerDBusMethodInfo *info = user_data;
 
+	program_log ("update_callback");
+
 	if (error) {
 		tracker_dbus_request_failed (info->request_id,
 		                             info->context,
@@ -379,6 +398,8 @@ tracker_resources_sparql_update (TrackerResources        *self,
 	guint                 request_id;
 	gchar                 *sender;
 
+	program_log ("tracker_resources_sparql_update");
+
 	request_id = tracker_dbus_get_next_request_id ();
 
 	tracker_dbus_async_return_if_fail (update != NULL, context);
@@ -408,6 +429,8 @@ update_blank_callback (GPtrArray *blank_nodes, GError *error, gpointer user_data
 {
 	TrackerDBusMethodInfo *info = user_data;
 
+	program_log ("tracker_resources_sparql_update_blank");
+
 	if (error) {
 		tracker_dbus_request_failed (info->request_id,
 		                             info->context,
@@ -486,6 +509,8 @@ tracker_resources_batch_sparql_update (TrackerResources          *self,
 	guint                 request_id;
 	gchar                 *sender;
 
+	program_log ("tracker_resources_batch_sparql_update");
+
 	request_id = tracker_dbus_get_next_request_id ();
 
 	tracker_dbus_async_return_if_fail (update != NULL, context);
@@ -515,6 +540,8 @@ batch_commit_callback (gpointer user_data)
 {
 	TrackerDBusMethodInfo *info = user_data;
 
+	program_log ("batch_commit_callback");
+
 	tracker_data_sync ();
 
 	tracker_dbus_request_success (info->request_id,
@@ -532,6 +559,8 @@ tracker_resources_batch_commit (TrackerResources         *self,
 	guint                 request_id;
 	gchar                 *sender;
 
+	program_log ("tracker_resources_batch_commit");
+
 	request_id = tracker_dbus_get_next_request_id ();
 
 	tracker_dbus_request_new (request_id,
diff --git a/src/tracker-store/tracker-store.c b/src/tracker-store/tracker-store.c
index 889af32..9368d11 100644
--- a/src/tracker-store/tracker-store.c
+++ b/src/tracker-store/tracker-store.c
@@ -47,6 +47,23 @@
 #define TRACKER_STORE_QUERY_WATCHDOG_TIMEOUT 10
 #define TRACKER_STORE_MAX_TASK_TIME          30
 
+static void
+program_log (const char *format, ...)
+{
+        va_list args;
+        char *formatted, *str;
+
+        va_start (args, format);
+        formatted = g_strdup_vprintf (format, args);
+        va_end (args);
+
+        str = g_strdup_printf ("MARK: %s: %s", g_get_prgname(), formatted);
+        g_free (formatted);
+
+        access (str, F_OK);
+        g_free (str);
+}
+
 typedef struct {
 	gboolean     have_handler, have_sync_handler;
 	gboolean     batch_mode, start_log;
@@ -464,6 +481,8 @@ pool_dispatch_cb (gpointer data,
 	TrackerStorePrivate *private;
 	TrackerStoreTask *task;
 
+	program_log ("pool_dispatch_cb");
+
 #ifdef __USE_GNU
 	/* special task, only ever sent to main pool */
 	if (GPOINTER_TO_INT (data) == 1) {
@@ -559,6 +578,8 @@ pool_dispatch_cb (gpointer data,
 		end_batch (private);
 	}
 
+	program_log ("pool_dispatch_cb done");
+
 	g_idle_add (task_finish_cb, task);
 }
 



[Date Prev][Date Next]   [Thread Prev][Thread Next]   [Thread Index] [Date Index] [Author Index]