GNOME.org
 

[tracker/extractor-controller-thread-0.10] tracker-extract: Cleaned up logging

commit dcc9340eda7ba49ae58818b3eb8a02d4cb9ce810
Author: Martyn Russell <martyn lanedo com>
Date:   Tue Apr 12 12:59:59 2011 +0100

    tracker-extract: Cleaned up logging
    
    Now all the thread tracing has to be turned on specifically with:
    
      -D THREAD_ENABLE_TRACE
    
    The MP3 extractor was also dumping all frame debugging, this has to be
    turned on with:
    
      -D FRAME_ENABLE_TRACE
    
    Some other sanity checking has been added to the logging so we know
    the max bytes from the config in the log.
    
    Things are more sane now with verbosity set to 2

 src/tracker-extract/tracker-controller.c  |   72 ++++++++++++++++++++++++-----
 src/tracker-extract/tracker-extract-mp3.c |    6 ++
 src/tracker-extract/tracker-extract.c     |   32 +++++++++----
 src/tracker-extract/tracker-main.c        |   22 ++++++++-
 4 files changed, 109 insertions(+), 23 deletions(-)
---
diff --git a/src/tracker-extract/tracker-controller.c b/src/tracker-extract/tracker-controller.c
index 03366bb..4224d55 100644
--- a/src/tracker-extract/tracker-controller.c
+++ b/src/tracker-extract/tracker-controller.c
@@ -29,6 +29,14 @@
 #include <libtracker-miner/tracker-miner.h>
 #include <gio/gio.h>
 
+#ifdef STAYALIVE_ENABLE_TRACE
+#warning Stayalive traces enabled
+#endif /* STAYALIVE_ENABLE_TRACE */
+
+#ifdef THREAD_ENABLE_TRACE
+#warning Controller thread traces enabled
+#endif /* THREAD_ENABLE_TRACE */
+
 typedef struct TrackerControllerPrivate TrackerControllerPrivate;
 typedef struct GetMetadataData GetMetadataData;
 
@@ -293,7 +301,11 @@ reset_shutdown_timeout_cb (gpointer user_data)
 {
 	TrackerControllerPrivate *priv;
 
-	g_message ("Extractor lifetime has expired");
+#ifdef STAYALIVE_ENABLE_TRACE
+	g_debug ("Stayalive --- time has expired");
+#endif /* STAYALIVE_ENABLE_TRACE */
+
+	g_message ("Shutting down due to no activity");
 
 	priv = TRACKER_CONTROLLER (user_data)->priv;
 	g_main_loop_quit (priv->main_loop);
@@ -313,7 +325,9 @@ reset_shutdown_timeout (TrackerController *controller)
 		return;
 	}
 
-	g_message ("(Re)setting shutdown timeout");
+#ifdef STAYALIVE_ENABLE_TRACE
+	g_debug ("Stayalive --- (Re)setting timeout");
+#endif /* STAYALIVE_ENABLE_TRACE */
 
 	if (priv->shutdown_source) {
 		g_source_destroy (priv->shutdown_source);
@@ -408,7 +422,12 @@ get_metadata_cb (GObject      *object,
 	} else {
 		GError *error = NULL;
 
-		g_message ("Controller thread (%p) got error back", g_thread_self ());
+
+#ifdef THREAD_ENABLE_TRACE
+		g_debug ("Thread:%p (Controller) --> Got error back",
+		         g_thread_self ());
+#endif /* THREAD_ENABLE_TRACE */
+
 		g_simple_async_result_propagate_error (G_SIMPLE_ASYNC_RESULT (res), &error);
 		tracker_dbus_request_end (data->request, error);
 		g_dbus_method_invocation_return_gerror (data->invocation, error);
@@ -460,7 +479,10 @@ get_metadata_fast_cb (GObject      *object,
 		GDataOutputStream *data_output_stream;
 		GError *error = NULL;
 
-		g_message ("Controller thread (%p) got metadata back", g_thread_self ());
+#ifdef THREAD_ENABLE_TRACE
+		g_debug ("Thread:%p (Controller) --> Got metadata back",
+		         g_thread_self ());
+#endif /* THREAD_ENABLE_TRACE */
 
 		unix_output_stream = g_unix_output_stream_new (data->fd, TRUE);
 		buffered_output_stream = g_buffered_output_stream_new_sized (unix_output_stream,
@@ -518,7 +540,11 @@ get_metadata_fast_cb (GObject      *object,
 	} else {
 		GError *error = NULL;
 
-		g_message ("Controller thread (%p) got error back", g_thread_self ());
+#ifdef THREAD_ENABLE_TRACE
+		g_debug ("Thread:%p (Controller) --> Got error back",
+		         g_thread_self ());
+#endif /* THREAD_ENABLE_TRACE */
+
 		g_simple_async_result_propagate_error (G_SIMPLE_ASYNC_RESULT (res), &error);
 		tracker_dbus_request_end (data->request, error);
 		g_dbus_method_invocation_return_gerror (data->invocation, error);
@@ -542,9 +568,6 @@ handle_method_call_get_metadata_fast (TrackerController	    *controller,
 	connection = g_dbus_method_invocation_get_connection (invocation);
 	method_message = g_dbus_method_invocation_get_message (invocation);
 
-	reset_shutdown_timeout (controller);
-	request = tracker_dbus_request_begin (NULL, "%s", __FUNCTION__);
-
 	if (g_dbus_connection_get_capabilities (connection) & G_DBUS_CAPABILITY_FLAGS_UNIX_FD_PASSING) {
 		TrackerControllerPrivate *priv;
 		GetMetadataData *data;
@@ -554,8 +577,17 @@ handle_method_call_get_metadata_fast (TrackerController	    *controller,
 		GError *error = NULL;
 
 		priv = controller->priv;
+
 		g_variant_get (parameters, "(&s&sh)", &uri, &mime, &index_fd);
 
+		request = tracker_dbus_request_begin (NULL,
+		                                      "%s (uri:'%s', mime:'%s', index_fd:%d)",
+		                                      __FUNCTION__,
+		                                      uri,
+		                                      mime,
+		                                      index_fd);
+		reset_shutdown_timeout (controller);
+
 		fd_list = g_dbus_message_get_unix_fd_list (method_message);
 
 		if ((fd = g_unix_fd_list_get (fd_list, index_fd, &error)) != -1) {
@@ -573,6 +605,10 @@ handle_method_call_get_metadata_fast (TrackerController	    *controller,
 			g_error_free (error);
 		}
 	} else {
+		request = tracker_dbus_request_begin (NULL,
+		                                      "%s (uri:'n/a', mime:'n/a', index_fd:unknown)",
+		                                      __FUNCTION__);
+		reset_shutdown_timeout (controller);
 		tracker_dbus_request_end (request, NULL);
 		g_dbus_method_invocation_return_dbus_error (invocation,
 		                                            TRACKER_EXTRACT_SERVICE ".GetMetadataFastError",
@@ -760,7 +796,10 @@ tracker_controller_thread_func (gpointer user_data)
 	TrackerControllerPrivate *priv;
 	GError *error = NULL;
 
-	g_message ("Controller thread '%p' created, dispatching...", g_thread_self ());
+#ifdef THREAD_ENABLE_TRACE
+	g_debug ("Thread:%p (Controller) --- Created, dispatching...",
+	         g_thread_self ());
+#endif /* THREAD_ENABLE_TRACE */
 
 	controller = user_data;
 	priv = controller->priv;
@@ -779,7 +818,10 @@ tracker_controller_thread_func (gpointer user_data)
 
 	g_main_loop_run (priv->main_loop);
 
-	g_message ("Shutting down...");
+#ifdef THREAD_ENABLE_TRACE
+	g_debug ("Thread:%p (Controller) --- Shutting down...",
+	         g_thread_self ());
+#endif /* THREAD_ENABLE_TRACE */
 
 	g_object_unref (controller);
 
@@ -804,7 +846,10 @@ tracker_controller_start (TrackerController  *controller,
 
 	priv = controller->priv;
 
-	g_message ("Waiting for controller thread to initialize...");
+#ifdef THREAD_ENABLE_TRACE
+	g_debug ("Thread:%p (Controller) --- Waiting for controller thread to initialize...",
+	         g_thread_self ());
+#endif /* THREAD_ENABLE_TRACE */
 
 	/* Wait for the controller thread to notify initialization */
 	g_mutex_lock (priv->initialization_mutex);
@@ -821,7 +866,10 @@ tracker_controller_start (TrackerController  *controller,
 		return FALSE;
 	}
 
-	g_message ("Controller thread initialized");
+#ifdef THREAD_ENABLE_TRACE
+	g_debug ("Thread:%p (Controller) --- Initialized",
+	         g_thread_self ());
+#endif /* THREAD_ENABLE_TRACE */
 
 	return TRUE;
 }
diff --git a/src/tracker-extract/tracker-extract-mp3.c b/src/tracker-extract/tracker-extract-mp3.c
index 1c8c043..0b31589 100644
--- a/src/tracker-extract/tracker-extract-mp3.c
+++ b/src/tracker-extract/tracker-extract-mp3.c
@@ -46,6 +46,10 @@
 
 #include "tracker-albumart.h"
 
+#ifdef FRAME_ENABLE_TRACE
+#warning Frame traces enabled
+#endif /* FRAME_ENABLE_TRACE */
+
 /* We mmap the beginning of the file and read separately the last 128
  * bytes for id3v1 tags. While these are probably cornercases the
  * rationale is that we don't want to fault a whole page for the last
@@ -1251,7 +1255,9 @@ get_id3v24_tags (id3v24frame           frame,
 			g_strstrip (word);
 		}
 
+#ifdef FRAME_ENABLE_TRACE
 		g_debug ("Frame is %d, word is %s", frame, word);
+#endif /* FRAME_ENABLE_TRACE */
 
 		switch (frame) {
 		case ID3V24_TALB:
diff --git a/src/tracker-extract/tracker-extract.c b/src/tracker-extract/tracker-extract.c
index 31a7741..21cdf99 100644
--- a/src/tracker-extract/tracker-extract.c
+++ b/src/tracker-extract/tracker-extract.c
@@ -43,6 +43,10 @@
 
 #define EXTRACT_FUNCTION "tracker_extract_get_data"
 
+#ifdef THREAD_ENABLE_TRACE
+#warning Main thread traces enabled
+#endif /* THREAD_ENABLE_TRACE */
+
 #define MAX_EXTRACT_TIME 10
 
 #define UNKNOWN_METHOD_MESSAGE "Method \"%s\" with signature \"%s\" on " \
@@ -638,7 +642,11 @@ get_metadata_cb (gpointer user_data)
 	TrackerExtractTask *task = user_data;
 	TrackerExtractInfo *info;
 
-	g_message ("Main thread (%p) got file to get metadata from: %s", g_thread_self (), task->file);
+#ifdef THREAD_ENABLE_TRACE
+	g_debug ("Thread:%p (Main) --> File:'%s' - Extracted",
+	         g_thread_self (),
+	         task->file);
+#endif /* THREAD_ENABLE_TRACE */
 
 	if (task->cancellable &&
 	    g_cancellable_is_cancelled (task->cancellable)) {
@@ -656,7 +664,8 @@ get_metadata_cb (gpointer user_data)
 	                       task->file, task->mimetype,
 	                       &info->preupdate,
 	                       &info->statements)) {
-		g_simple_async_result_set_op_res_gpointer ((GSimpleAsyncResult *) task->res, info,
+		g_simple_async_result_set_op_res_gpointer ((GSimpleAsyncResult *) task->res,
+		                                           info,
 		                                           (GDestroyNotify) tracker_extract_info_free);
 	} else {
 		g_simple_async_result_set_error ((GSimpleAsyncResult *) task->res,
@@ -688,11 +697,15 @@ tracker_extract_file (TrackerExtract      *extract,
 	g_return_if_fail (file != NULL);
 	g_return_if_fail (cb != NULL);
 
-	g_message ("Extract file on thread %p\n", g_thread_self ());
+#ifdef THREAD_ENABLE_TRACE
+	g_debug ("Thread:%p (Main) <-- File:'%s' - Extracting\n",
+	         g_thread_self (),
+	         file);
+#endif /* THREAD_ENABLE_TRACE */
+
 	res = g_simple_async_result_new (G_OBJECT (extract), cb, user_data, NULL);
 
-	task = extract_task_new (extract, file, mimetype, cancellable,
-	                         G_ASYNC_RESULT (res));
+	task = extract_task_new (extract, file, mimetype, cancellable, G_ASYNC_RESULT (res));
 	g_idle_add (get_metadata_cb, task);
 
 	/* task takes a ref */
@@ -712,8 +725,9 @@ tracker_extract_get_metadata_by_cmdline (TrackerExtract *object,
 
 	g_return_if_fail (uri != NULL);
 
-	if (get_file_metadata (object, uri, mime,
-			       &preupdate, &statements)) {
+	g_message ("Extracting...");
+
+	if (get_file_metadata (object, uri, mime, &preupdate, &statements)) {
 		const gchar *preupdate_str, *statements_str;
 
 		preupdate_str = statements_str = NULL;
@@ -726,9 +740,9 @@ tracker_extract_get_metadata_by_cmdline (TrackerExtract *object,
 			preupdate_str = tracker_sparql_builder_get_result (preupdate);
 		}
 
-		g_print ("Preupdate SPARQL:\n%s\n",
+		g_print ("SPARQL pre-update:\n%s\n",
 		         preupdate_str ? preupdate_str : "");
-		g_print ("Item SPARQL:\n%s\n",
+		g_print ("SPARQL item:\n%s\n",
 		         statements_str ? statements_str : "");
 
 		g_object_unref (statements);
diff --git a/src/tracker-extract/tracker-main.c b/src/tracker-extract/tracker-main.c
index e0adfc0..b2e1b01 100644
--- a/src/tracker-extract/tracker-main.c
+++ b/src/tracker-extract/tracker-main.c
@@ -54,6 +54,10 @@
 #include "tracker-extract.h"
 #include "tracker-controller.h"
 
+#ifdef THREAD_ENABLE_TRACE
+#warning Main thread traces enabled
+#endif /* THREAD_ENABLE_TRACE */
+
 #define ABOUT	  \
 	"Tracker " PACKAGE_VERSION "\n"
 
@@ -234,13 +238,22 @@ log_handler (const gchar    *domain,
 	}
 }
 
+static void
+sanity_check_option_values (TrackerConfig *config)
+{
+	g_message ("General options:");
+	g_message ("  Verbosity  ............................  %d",
+	           tracker_config_get_verbosity (config));
+	g_message ("  Max bytes (per file)  .................  %d",
+	           tracker_config_get_max_bytes (config));
+}
+
 TrackerConfig *
 tracker_main_get_config (void)
 {
 	return config;
 }
 
-
 static int
 run_standalone (void)
 {
@@ -377,6 +390,8 @@ main (int argc, char *argv[])
 	g_print ("Starting log:\n  File:'%s'\n", log_filename);
 	g_free (log_filename);
 
+	sanity_check_option_values (config);
+
 	/* This makes sure we don't steal all the system's resources */
 	initialize_priority ();
 	tracker_memory_setrlimits ();
@@ -410,7 +425,10 @@ main (int argc, char *argv[])
 		return EXIT_FAILURE;
         }
 
-	g_message ("Main thread (%p) waiting for extract requests...", g_thread_self ());
+#ifdef THREAD_ENABLE_TRACE
+        g_debug ("Thread:%p (Main) --- Waiting for extract requests...",
+                 g_thread_self ());
+#endif /* THREAD_ENABLE_TRACE */
 
 	tracker_locale_init ();
 	tracker_albumart_init ();
[Date Prev][Date Next]   [Thread Prev][Thread Next]   [Thread Index] [Date Index] [Author Index]