There may be better ways to collect this kind of performance data than outputting them to ModemManager log. Is there a commonly used method for ModemManager to report performance metrics in a way that other tools can collect and analyze them?
- Ben On Mon, Jan 21, 2013 at 8:30 PM, Ben Chan <[email protected]> wrote: > 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-iface-modem-simple.c | 18 +++++++++++++++++- > src/mm-iface-modem.c | 24 ++++++++++++++++++++++++ > 4 files changed, 50 insertions(+), 1 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-iface-modem-simple.c b/src/mm-iface-modem-simple.c > index 12aa152..b0bcf46 100644 > --- a/src/mm-iface-modem-simple.c > +++ b/src/mm-iface-modem-simple.c > @@ -196,6 +196,8 @@ typedef struct { > > /* Results to set */ > MMBearer *bearer; > + > + GTimeVal start_time; > } ConnectionContext; > > static void > @@ -203,7 +205,6 @@ connection_context_free (ConnectionContext *ctx) > { > g_assert (ctx->state_changed_id == 0); > g_assert (ctx->state_changed_wait_id == 0); > - > g_variant_unref (ctx->dictionary); > if (ctx->properties) > g_object_unref (ctx->properties); > @@ -516,6 +517,8 @@ bearer_list_find_disconnected (MMBearer *bearer, > static void > connection_step (ConnectionContext *ctx) > { > + GTimeVal end_time; > + > switch (ctx->step) { > case CONNECTION_STEP_FIRST: > /* Fall down to next step */ > @@ -738,6 +741,9 @@ connection_step (ConnectionContext *ctx) > case CONNECTION_STEP_LAST: > mm_info ("Simple connect state (%d/%d): All done", > ctx->step, CONNECTION_STEP_LAST); > + g_get_current_time (&end_time); > + mm_info ("Connection steps took %.3f second(s).", > + mm_utils_subtract_time (&end_time, &ctx->start_time)); > /* All done, yey! */ > mm_gdbus_modem_simple_complete_connect ( > ctx->skeleton, > @@ -828,6 +834,7 @@ handle_connect (MmGdbusModemSimple *skeleton, > ctx->invocation = g_object_ref (invocation); > ctx->self = g_object_ref (self); > ctx->dictionary = g_variant_ref (dictionary); > + g_get_current_time (&ctx->start_time); > > mm_base_modem_authorize (MM_BASE_MODEM (self), > invocation, > @@ -846,6 +853,7 @@ typedef struct { > gchar *bearer_path; > GList *bearers; > MMBearer *current; > + GTimeVal start_time; > } DisconnectionContext; > > static void > @@ -887,6 +895,12 @@ disconnect_next_bearer (DisconnectionContext *ctx) > > /* No more bearers? all done! */ > if (!ctx->bearers) { > + GTimeVal end_time; > + > + g_get_current_time (&end_time); > + mm_info ("Disconnection steps took %.3f second(s).", > + mm_utils_subtract_time (&end_time, &ctx->start_time)); > + > mm_gdbus_modem_simple_complete_disconnect (ctx->skeleton, > ctx->invocation); > disconnection_context_free (ctx); > @@ -977,6 +991,8 @@ handle_disconnect (MmGdbusModemSimple *skeleton, > ctx->bearer_path = g_strdup (ctx->bearer_path); > } > > + g_get_current_time (&ctx->start_time); > + > mm_base_modem_authorize (MM_BASE_MODEM (self), > invocation, > MM_AUTHORIZATION_DEVICE_CONTROL, > diff --git a/src/mm-iface-modem.c b/src/mm-iface-modem.c > index 6b812e2..2edbcf4 100644 > --- a/src/mm-iface-modem.c > +++ b/src/mm-iface-modem.c > @@ -2911,6 +2911,7 @@ struct _DisablingContext { > MMModemState previous_state; > GSimpleAsyncResult *result; > MmGdbusModem *skeleton; > + GTimeVal start_time; > }; > > static void > @@ -2935,6 +2936,8 @@ mm_iface_modem_disable_finish (MMIfaceModem *self, > static void > interface_disabling_step (DisablingContext *ctx) > { > + GTimeVal end_time; > + > switch (ctx->step) { > case DISABLING_STEP_FIRST: > /* Fall down to next step */ > @@ -2954,6 +2957,10 @@ interface_disabling_step (DisablingContext *ctx) > ctx->step++; > > case DISABLING_STEP_LAST: > + g_get_current_time (&end_time); > + mm_info ("Disabling steps took %.3f second(s).", > + mm_utils_subtract_time (&end_time, &ctx->start_time)); > + > /* We are done without errors! */ > g_simple_async_result_set_op_res_gboolean (ctx->result, TRUE); > disabling_context_complete_and_free (ctx); > @@ -2977,6 +2984,7 @@ mm_iface_modem_disable (MMIfaceModem *self, > user_data, > mm_iface_modem_disable); > ctx->step = DISABLING_STEP_FIRST; > + g_get_current_time (&ctx->start_time); > g_object_get (ctx->self, > MM_IFACE_MODEM_DBUS_SKELETON, &ctx->skeleton, > MM_IFACE_MODEM_STATE, &ctx->previous_state, > @@ -3019,6 +3027,7 @@ struct _EnablingContext { > GSimpleAsyncResult *result; > GCancellable *cancellable; > MmGdbusModem *skeleton; > + GTimeVal start_time; > }; > > static void > @@ -3220,6 +3229,8 @@ static const MMModemCharset best_charsets[] = { > static void > interface_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; > @@ -3345,6 +3356,10 @@ interface_enabling_step (EnablingContext *ctx) > ctx->step++; > > case ENABLING_STEP_LAST: > + g_get_current_time (&end_time); > + mm_info ("Enabling steps took %.3f second(s).", > + mm_utils_subtract_time (&end_time, &ctx->start_time)); > + > /* We are done without errors! */ > g_simple_async_result_set_op_res_gboolean (ctx->result, TRUE); > enabling_context_complete_and_free (ctx); > @@ -3370,6 +3385,7 @@ mm_iface_modem_enable (MMIfaceModem *self, > user_data, > mm_iface_modem_enable); > ctx->step = ENABLING_STEP_FIRST; > + g_get_current_time (&ctx->start_time); > g_object_get (ctx->self, > MM_IFACE_MODEM_DBUS_SKELETON, &ctx->skeleton, > NULL); > @@ -3417,6 +3433,7 @@ struct _InitializationContext { > GCancellable *cancellable; > MmGdbusModem *skeleton; > GError *fatal_error; > + GTimeVal start_time; > }; > > static void > @@ -4000,6 +4017,12 @@ interface_initialization_step > (InitializationContext *ctx) > g_simple_async_result_take_error (ctx->result, > ctx->fatal_error); > ctx->fatal_error = NULL; > } else { > + GTimeVal end_time; > + > + g_get_current_time (&end_time); > + mm_info ("Initialization steps took %.3f second(s).", > + mm_utils_subtract_time (&end_time, > &ctx->start_time)); > + > /* We are done without errors! > * Handle method invocations */ > g_signal_connect (ctx->skeleton, > @@ -4127,6 +4150,7 @@ mm_iface_modem_initialize (MMIfaceModem *self, > mm_iface_modem_initialize); > ctx->step = INITIALIZATION_STEP_FIRST; > ctx->skeleton = skeleton; > + g_get_current_time (&ctx->start_time); > > interface_initialization_step (ctx); > } > -- > 1.7.7.3 > >
_______________________________________________ networkmanager-list mailing list [email protected] https://mail.gnome.org/mailman/listinfo/networkmanager-list
