mg2d: track the time spent initializing the levels

1 files changed, 14 insertions, 2 deletions

diff --git a/mg2d.c b/mg2d.c
index d0469e1..03a1759 100644
--- a/mg2d.c
+++ b/mg2d.c
@@ -74,6 +74,8 @@ struct MG2DInternal {
 
     int64_t time_solve;
     int64_t count_solve;
+    int64_t time_levels_init;
+    int64_t count_levels_init;
 };
 
 static void log_callback(MG2DLogger *log, int level, const char *fmt, va_list vl)
@@ -469,7 +471,7 @@ int mg2d_solve(MG2DContext *ctx)
     MG2DInternal *priv = ctx->priv;
     MG2DLevel    *root;
     EGSContext *s_root;
-    int64_t time_start;
+    int64_t time_start, start;
     double res_orig, res_prev, res_cur;
     int ret;
 
@@ -490,10 +492,15 @@ int mg2d_solve(MG2DContext *ctx)
 
     time_start = gettime();
 
+    start = gettime();
+
     ret = mg_levels_init(ctx);
     if (ret < 0)
         return ret;
 
+    priv->time_levels_init += gettime() - start;
+    priv->count_levels_init++;
+
     ret = mg2di_egs_init(s_root, 0);
     if (ret < 0)
         return ret;
@@ -832,7 +839,12 @@ void mg2d_print_stats(MG2DContext *ctx, const char *prefix)
         level = level->child;
     }
 
-    other = priv->time_solve - levels_total;
+    mg2di_log(&priv->logger, MG2D_LOG_VERBOSE,
+              "%s%2.2f%% levels init %g s total time %g ms avg per call\n",
+              prefix, priv->time_levels_init * 100.0 / priv->time_solve,
+              priv->time_levels_init / 1e6, priv->time_levels_init / 1e3 / priv->count_levels_init);
+
+    other = priv->time_solve - levels_total - priv->time_levels_init;
     mg2di_log(&priv->logger, MG2D_LOG_VERBOSE,
               "%s%2.2f%% other %g s total time %g ms avg per call\n",
               prefix, other * 100.0 / priv->time_solve,