Re: [MM] [PATCH v2] modem: log time taken for succeeded operations

2013-01-22 Thread Aleksander Morgado
On 22/01/13 06:10, Ben Chan wrote:
> This patch logs the time taken for succeeded initialization, enabling,
> disabling, connection, and disconnection operations, which helps
> evaluate how to optimize modem plugins.
> ---

> +
> +gdouble
> +mm_utils_subtract_time (const GTimeVal *end_time, const GTimeVal *start_time)
> +{
> +return (end_time->tv_sec - start_time->tv_sec) +
> +   (end_time->tv_usec - start_time->tv_usec) / 1.0e6;
> +}


If you want to log how long it takes, better use a GTimer instead of two
GTimeVals:

http://developer.gnome.org/glib/unstable/glib-Timers.html

-- 
Aleksander
___
networkmanager-list mailing list
networkmanager-list@gnome.org
https://mail.gnome.org/mailman/listinfo/networkmanager-list


[MM] [PATCH v2] modem: log time taken for succeeded operations

2013-01-21 Thread Ben Chan
This patch logs the time taken for succeeded initialization, enabling,
disabling, connection, and disconnection operations, which helps
evaluate how to optimize modem plugins.
---
 libmm-glib/mm-common-helpers.c |7 +++
 libmm-glib/mm-common-helpers.h |2 ++
 src/mm-broadband-modem.c   |   22 ++
 src/mm-iface-modem-simple.c|   17 +
 src/mm-iface-modem.c   |   24 
 5 files changed, 72 insertions(+), 0 deletions(-)

diff --git a/libmm-glib/mm-common-helpers.c b/libmm-glib/mm-common-helpers.c
index 3f100b6..406a99a 100644
--- a/libmm-glib/mm-common-helpers.c
+++ b/libmm-glib/mm-common-helpers.c
@@ -960,3 +960,10 @@ mm_utils_check_for_single_value (guint32 value)
 
 return TRUE;
 }
+
+gdouble
+mm_utils_subtract_time (const GTimeVal *end_time, const GTimeVal *start_time)
+{
+return (end_time->tv_sec - start_time->tv_sec) +
+   (end_time->tv_usec - start_time->tv_usec) / 1.0e6;
+}
diff --git a/libmm-glib/mm-common-helpers.h b/libmm-glib/mm-common-helpers.h
index 6155b58..42bbe20 100644
--- a/libmm-glib/mm-common-helpers.h
+++ b/libmm-glib/mm-common-helpers.h
@@ -102,4 +102,6 @@ gchar*mm_utils_bin2hexstr (const guint8 *bin, gsize 
len);
 
 gboolean  mm_utils_check_for_single_value (guint32 value);
 
+gdouble mm_utils_subtract_time (const GTimeVal *end_time, const GTimeVal 
*start_time);
+
 #endif /* MM_COMMON_HELPERS_H */
diff --git a/src/mm-broadband-modem.c b/src/mm-broadband-modem.c
index 0a7af2c..135e725 100644
--- a/src/mm-broadband-modem.c
+++ b/src/mm-broadband-modem.c
@@ -7460,6 +7460,7 @@ typedef struct {
 DisablingStep step;
 MMModemState previous_state;
 gboolean disabled;
+GTimeVal start_time;
 } DisablingContext;
 
 static void disabling_step (DisablingContext *ctx);
@@ -7618,6 +7619,8 @@ disabling_wait_for_final_state_ready (MMIfaceModem *self,
 static void
 disabling_step (DisablingContext *ctx)
 {
+GTimeVal end_time;
+
 /* Don't run new steps if we're cancelled */
 if (disabling_context_complete_and_free_if_cancelled (ctx))
 return;
@@ -7746,6 +7749,9 @@ disabling_step (DisablingContext *ctx)
 case DISABLING_STEP_LAST:
 mm_info ("Modem fully disabled...");
 ctx->disabled = TRUE;
+g_get_current_time (&end_time);
+mm_info ("Modem disabling steps took %.3f second(s).",
+ mm_utils_subtract_time (&end_time, &ctx->start_time));
 /* All disabled without errors! */
 g_simple_async_result_set_op_res_gboolean (G_SIMPLE_ASYNC_RESULT 
(ctx->result), TRUE);
 disabling_context_complete_and_free (ctx);
@@ -7768,6 +7774,7 @@ disable (MMBaseModem *self,
 ctx->result = g_simple_async_result_new (G_OBJECT (self), callback, 
user_data, disable);
 ctx->cancellable = (cancellable ? g_object_ref (cancellable) : NULL);
 ctx->step = DISABLING_STEP_FIRST;
+g_get_current_time (&ctx->start_time);
 
 disabling_step (ctx);
 }
@@ -7798,6 +7805,7 @@ typedef struct {
 EnablingStep step;
 MMModemState previous_state;
 gboolean enabled;
+GTimeVal start_time;
 } EnablingContext;
 
 static void enabling_step (EnablingContext *ctx);
@@ -7940,6 +7948,8 @@ enabling_wait_for_final_state_ready (MMIfaceModem *self,
 static void
 enabling_step (EnablingContext *ctx)
 {
+GTimeVal end_time;
+
 /* Don't run new steps if we're cancelled */
 if (enabling_context_complete_and_free_if_cancelled (ctx))
 return;
@@ -8068,6 +8078,9 @@ enabling_step (EnablingContext *ctx)
 case ENABLING_STEP_LAST:
 mm_info ("Modem fully enabled...");
 ctx->enabled = TRUE;
+g_get_current_time (&end_time);
+mm_info ("Modem enabling steps took %.3f second(s).",
+ mm_utils_subtract_time (&end_time, &ctx->start_time));
 /* All enabled without errors! */
 g_simple_async_result_set_op_res_gboolean (G_SIMPLE_ASYNC_RESULT 
(ctx->result), TRUE);
 enabling_context_complete_and_free (ctx);
@@ -8118,6 +8131,7 @@ enable (MMBaseModem *self,
 ctx->result = result;
 ctx->cancellable = g_object_ref (cancellable);
 ctx->step = ENABLING_STEP_FIRST;
+g_get_current_time (&ctx->start_time);
 enabling_step (ctx);
 return;
 }
@@ -8179,6 +8193,7 @@ typedef struct {
 GSimpleAsyncResult *result;
 InitializeStep step;
 gpointer ports_ctx;
+GTimeVal start_time;
 } InitializeContext;
 
 static void initialize_step (InitializeContext *ctx);
@@ -8356,6 +8371,8 @@ INTERFACE_INIT_READY_FN (iface_modem_firmware,  
MM_IFACE_MODEM_FIRMWARE,  FALSE)
 static void
 initialize_step (InitializeContext *ctx)
 {
+GTimeVal end_time;
+
 /* Don't run new steps if we're cancelled */
 if (initialize_context_complete_and_free_if_cancelled (ctx))
 return;
@@ -8523,6 +8540,10 @@ initialize_step (InitializeContext *ctx)
 
 mm_info ("Modem fully initialized");
 
+g_get_current