GNOME.org
 

[tracker/miner-paranoid-logs] libtracker-miner, miner-fs: Add some paranoid debug logs

commit 9361622e1382554c6d298d866a2a22542e9c6f51
Author: Aleksander Morgado <aleksander lanedo com>
Date:   Thu Jul 22 17:09:37 2010 +0200

    libtracker-miner, miner-fs: Add some paranoid debug logs

 src/libtracker-miner/tracker-miner-fs.c |  119 +++++++++++++++++++++++++++++-
 src/miners/fs/tracker-miner-files.c     |   48 ++++++++++++
 2 files changed, 163 insertions(+), 4 deletions(-)
---
diff --git a/src/libtracker-miner/tracker-miner-fs.c b/src/libtracker-miner/tracker-miner-fs.c
index a14ec4a..a81023f 100644
--- a/src/libtracker-miner/tracker-miner-fs.c
+++ b/src/libtracker-miner/tracker-miner-fs.c
@@ -34,9 +34,21 @@
 /* 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 */
-#undef PRINT_IRI_CACHE_CONTENTS
+#define PRINT_IRI_CACHE_CONTENTS 1
 /* If defined will print contents of populated mtime cache while running */
-#undef PRINT_MTIME_CACHE_CONTENTS
+#define PRINT_MTIME_CACHE_CONTENTS 1
+/* If defined, will dump paranoid debug logs */
+#define PARANOID_DEBUG 1
+
+
+#ifdef PARANOID_DEBUG
+#define paranoid_debug(message, ...)	  \
+	g_debug ("***PARANOID***:%s:%d: " message, \
+	         __FILE__, __LINE__, ##__VA_ARGS__)
+#else
+#define paranoid_debug(...)
+#endif /* PARANOID_DEBUG */
+
 
 /**
  * SECTION:tracker-miner-fs
@@ -596,6 +608,19 @@ process_data_new (GFile                *file,
 		data->builder = g_object_ref (builder);
 	}
 
+#ifdef PARANOID_DEBUG
+	{
+		gchar *uri = g_file_get_uri (file);
+
+		paranoid_debug ("Created data to process %p, for URI '%s' with urn '%s', parent_urn '%s'",
+		                data,
+		                uri,
+		                urn ? urn : "unknown",
+		                parent_urn ? parent_urn : "unknown");
+		g_free (uri);
+	}
+#endif /* PARANOID_DEBUG */
+
 	return data;
 }
 
@@ -634,16 +659,18 @@ process_data_find (TrackerMinerFS *fs,
 			 * same GFile object that's being passed, so we check for
 			 * pointer equality here, rather than doing path comparisons
 			 */
-			if(data->file == file)
+			if(data->file == file) {
 				return data;
+			}
 		} else {
 			/* Note that if there are different GFiles being
 			 * processed for the same file path, we are actually
 			 * returning the first one found, If you want exactly
 			 * the same GFile as the one as input, use the
 			 * process_data_find() method instead */
-			if (g_file_equal (data->file, file))
+			if (g_file_equal (data->file, file)) {
 				return data;
+			}
 		}
 	}
 
@@ -1034,6 +1061,14 @@ sparql_update_cb (GObject      *object,
 	priv = fs->private;
 	data = user_data;
 
+#ifdef PARANOID_DEBUG
+	{
+		gchar *uri = g_file_get_uri (data->file);
+		paranoid_debug ("Finished BATCH UPDATE for '%s'", uri);
+		g_free (uri);
+	}
+#endif
+
 	if (error) {
 		g_critical ("Could not execute sparql: %s", error->message);
 		priv->total_files_notified_error++;
@@ -1054,6 +1089,29 @@ sparql_update_cb (GObject      *object,
 			 * .gvfs mounts also!) */
 			parent = g_file_get_parent (data->file);
 
+#ifdef PARANOID_DEBUG
+			{
+				gchar *parent_uri;
+				gchar *iri_cache_parent_uri;
+				gboolean equal;
+				gboolean found;
+
+				parent_uri = parent ? g_file_get_uri (parent) : NULL;
+				iri_cache_parent_uri = g_file_get_uri (fs->private->current_iri_cache_parent);
+				equal = g_file_equal (parent, fs->private->current_iri_cache_parent);
+				found = (equal ?
+				         (g_hash_table_lookup (fs->private->iri_cache, data->file) ? TRUE : FALSE) :
+				         FALSE);
+				paranoid_debug ("[%s] [%s] Parent URI: %s, IRI cache URI: %s",
+				                equal ? "SAME" : "DIFFERENT",
+				                found ? "FOUND" : "NOT FOUND",
+				                parent_uri,
+				                iri_cache_parent_uri);
+				g_free (parent_uri);
+				g_free (iri_cache_parent_uri);
+			}
+#endif
+
 			if (parent) {
 				if (g_file_equal (parent, fs->private->current_iri_cache_parent) &&
 				    g_hash_table_lookup (fs->private->iri_cache, data->file) == NULL) {
@@ -1067,6 +1125,8 @@ sparql_update_cb (GObject      *object,
 
 				g_object_unref (parent);
 			}
+		} else {
+			paranoid_debug ("EMPTY IRI CACHE");
 		}
 	}
 
@@ -1159,6 +1219,11 @@ item_query_exists (TrackerMinerFS  *miner,
 
 	g_main_loop_unref (data.main_loop);
 
+	paranoid_debug ("ITEM '%s' was %s FOUND in store (iri: %s)",
+	                uri,
+	                result ? " " : "NOT",
+	                data.iri ? data.iri : "none");
+
 	if (iri) {
 		*iri = data.iri;
 	} else {
@@ -1495,6 +1560,8 @@ item_add_or_update_cb (TrackerMinerFS *fs,
 			full_sparql = g_strdup (tracker_sparql_builder_get_result (data->builder));
 		}
 
+		paranoid_debug ("BATCH UPDATE (CREATE|UPDATE) for file '%s'", uri);
+
 		tracker_miner_execute_batch_update (TRACKER_MINER (fs),
 		                                    full_sparql,
 		                                    NULL,
@@ -1560,9 +1627,38 @@ item_add_or_update (TrackerMinerFS *fs,
 
 	urn = iri_cache_lookup (fs, file);
 
+	/* Check if we are trying to update/create a file where its parent still
+	 * doesn't exist */
+	if (parent && !parent_urn) {
+		gchar *uri;
+		gchar *parent_uri;
+
+		uri = g_file_get_uri (file);
+		parent_uri = g_file_get_uri (parent);
+
+		g_warning ("Adding to process item '%s' where parent '%s' still "
+		           "doesn't exist in store...", uri, parent_uri);
+		g_free (uri);
+		g_free (parent_uri);
+	}
+
 	data = process_data_new (file, urn, parent_urn, cancellable, sparql);
 	priv->processing_pool = g_list_prepend (priv->processing_pool, data);
 
+#ifdef PARANOID_DEBUG
+	{
+		gchar *uri = g_file_get_uri (file);
+
+		paranoid_debug ("New processing data added (%p) for file '%s' with "
+		                "urn '%s' and parent_urn '%s'",
+		                data,
+		                uri,
+		                urn ? urn : "unknown",
+		                parent_urn ? parent_urn : "unknown");
+		g_free (uri);
+	}
+#endif /* PARANOID_DEBUG */
+
 	if (do_process_file (fs, data)) {
 		guint length;
 
@@ -1632,6 +1728,8 @@ item_remove (TrackerMinerFS *fs,
 	data = process_data_new (file, NULL, NULL, NULL, NULL);
 	fs->private->processing_pool = g_list_prepend (fs->private->processing_pool, data);
 
+	paranoid_debug ("BATCH UPDATE (DELETE) for file '%s'", uri);
+
 	tracker_miner_execute_batch_update (TRACKER_MINER (fs),
 	                                    sparql->str,
 	                                    NULL,
@@ -1939,6 +2037,8 @@ item_move (TrackerMinerFS *fs,
 	data = process_data_new (file, NULL, NULL, NULL, NULL);
 	fs->private->processing_pool = g_list_prepend (fs->private->processing_pool, data);
 
+	paranoid_debug ("BATCH UPDATE (MOVE) for file '%s->%s'", source_uri, uri);
+
 	tracker_miner_execute_batch_update (TRACKER_MINER (fs),
 	                                    sparql->str,
 	                                    NULL,
@@ -3598,6 +3698,17 @@ tracker_miner_fs_file_notify (TrackerMinerFS *fs,
 		return;
 	}
 
+#ifdef PARANOID_DEBUG
+	{
+		gchar *uri = g_file_get_uri (file);
+
+		paranoid_debug ("NOTIFY for file '%s' received (urn: %s)",
+		                uri,
+		                data->urn ? data->urn : "unknown");
+		g_free (uri);
+	}
+#endif /* PARANOID_DEBUG */
+
 	item_add_or_update_cb (fs, data, error);
 }
 
diff --git a/src/miners/fs/tracker-miner-files.c b/src/miners/fs/tracker-miner-files.c
index b8d83eb..c46c11e 100644
--- a/src/miners/fs/tracker-miner-files.c
+++ b/src/miners/fs/tracker-miner-files.c
@@ -61,6 +61,19 @@
 /* Default DBus timeout to be used in requests to extractor (milliseconds) */
 #define EXTRACTOR_DBUS_TIMEOUT 60000
 
+/* If defined, will dump paranoid debug logs */
+#define PARANOID_DEBUG 1
+
+
+#ifdef PARANOID_DEBUG
+#define paranoid_debug(message, ...)	  \
+	g_debug ("***PARANOID***:%s:%d: " message, \
+	         __FILE__, __LINE__, ##__VA_ARGS__)
+#else
+#define paranoid_debug(...)
+#endif /* PARANOID_DEBUG */
+
+
 #define TRACKER_MINER_FILES_GET_PRIVATE(o) (G_TYPE_INSTANCE_GET_PRIVATE ((o), TRACKER_TYPE_MINER_FILES, TrackerMinerFilesPrivate))
 
 static GQuark miner_files_error_quark = 0;
@@ -1892,6 +1905,14 @@ extractor_get_embedded_metadata_cb (DBusGProxy *proxy,
 		return;
 	}
 
+#ifdef PARANOID_DEBUG
+	{
+		gchar *uri = g_file_get_uri (data->file);
+		paranoid_debug ("<----- Finished asynchronous query for METADATA of '%s'", uri);
+		g_free (uri);
+	}
+#endif
+
 	if (sparql && *sparql) {
 		gboolean is_iri;
 		const gchar *urn;
@@ -1955,9 +1976,25 @@ extractor_get_embedded_metadata_cb (DBusGProxy *proxy,
 		g_free (uri);
 	}
 
+#ifdef PARANOID_DEBUG
+	{
+		gchar *uri = g_file_get_uri (data->file);
+		paranoid_debug ("-----> Notify Success for '%s'", uri);
+		g_free (uri);
+	}
+#endif
+
 	/* Notify about the success */
 	tracker_miner_fs_file_notify (TRACKER_MINER_FS (data->miner), data->file, NULL);
 
+#ifdef PARANOID_DEBUG
+	{
+		gchar *uri = g_file_get_uri (data->file);
+		paranoid_debug ("-----> Finished notification of success for '%s'", uri);
+		g_free (uri);
+	}
+#endif
+
 	process_file_data_free (data);
 #ifndef HAVE_DBUS_FD_PASSING
 	/* When using DBus FD passing, we let the caller free */
@@ -2196,6 +2233,9 @@ process_file_cb (GObject      *object,
 
 	miner_files_add_to_datasource (data->miner, file, sparql);
 
+	paranoid_debug ("<----- Finished asynchronous query for info of '%s'", uri);
+	paranoid_debug ("-----> Asynchronously querying for METADATA of '%s'", uri);
+
 	/* Next step, getting embedded metadata */
 	extractor_get_embedded_metadata (data, uri, mime_type);
 
@@ -2225,6 +2265,14 @@ miner_files_process_file (TrackerMinerFS       *fs,
 		G_FILE_ATTRIBUTE_TIME_MODIFIED ","
 		G_FILE_ATTRIBUTE_TIME_ACCESS;
 
+#ifdef PARANOID_DEBUG
+	{
+		gchar *uri = g_file_get_uri (file);
+		paranoid_debug ("-----> Asynchronously querying for info of '%s'", uri);
+		g_free (uri);
+	}
+#endif
+
 	g_file_query_info_async (file,
 	                         attrs,
 	                         G_FILE_QUERY_INFO_NOFOLLOW_SYMLINKS,
[Date Prev][Date Next]   [Thread Prev][Thread Next]   [Thread Index] [Date Index] [Author Index]