Changeset 3170 for trunk/src/kmk/kmkbuiltin.c

Timestamp:

Mar 21, 2018, 1:32:27 PM (7 years ago)

Author:

bird

Message:

kmkbuiltin: stats

File:

• trunk/src/kmk/kmkbuiltin.c (modified) (8 diffs)

trunk/src/kmk/kmkbuiltin.c

@@ -36 +36 @@
 # include <io.h>
 #endif
+
+#include "makeint.h"
+#include "job.h"
 #if defined(KBUILD_OS_WINDOWS) && defined(CONFIG_NEW_WIN_CHILDREN)
-# include "makeint.h"
-# include "job.h"
 # include "w32/winchildren.h"
 #endif
@@ -231 +232 @@
  * kmk built command.
  */
-static const KMKBUILTINENTRY g_aBuiltins[] =
+static const KMKBUILTINENTRY g_aBuiltIns[] =
 {
 #define BUILTIN_ENTRY(a_fn, a_sz, a_uFnSignature, fMpSafe, fNeedEnv) \
@@ -266 +267 @@
 };
 
+#ifdef CONFIG_WITH_KMK_BUILTIN_STATS
+/** Statistics running in parallel to g_aBuiltIns. */
+struct
+{
+    big_int         cNs;
+    unsigned        cTimes;
+    unsigned        cAsyncTimes;
+} g_aBuiltInStats[sizeof(g_aBuiltIns) / sizeof(g_aBuiltIns[0])];
+#endif
+
 
 int kmk_builtin_command_parsed(int argc, char **argv, struct child *pChild, char ***ppapszArgvToSpawn, pid_t *pPidSpawned)
@@ -325 +336 @@
          * Look up the builtin command in the table.
          */
-        pEntry  = &g_aBuiltins[0];
-        cLeft   = sizeof(g_aBuiltins) / sizeof(g_aBuiltins[0]);
+        pEntry  = &g_aBuiltIns[0];
+        cLeft   = sizeof(g_aBuiltIns) / sizeof(g_aBuiltIns[0]);
         while (cLeft-- > 0)
             if (   pEntry->uName.cchAndStart != cchAndStart
@@ -340 +351 @@
 #if defined(KBUILD_OS_WINDOWS) && defined(CONFIG_NEW_WIN_CHILDREN)
                 if (pEntry->fMpSafe)
+                {
                     rc = MkWinChildCreateBuiltIn(pEntry, argc, argv, pEntry->fNeedEnv ? pChild->environment : NULL,
                                                  pChild, pPidSpawned);
+# ifdef CONFIG_WITH_KMK_BUILTIN_STATS
+                    g_aBuiltInStats[pEntry - &g_aBuiltIns[0]].cAsyncTimes++;
+# endif
+                }
                 else
 #endif
@@ -350 +366 @@
                      * Call the worker function, making sure to preserve umask.
                      */
+#ifdef CONFIG_WITH_KMK_BUILTIN_STATS
+                    big_int nsStart = nano_timestamp();
+#endif
                     int const iUmask = umask(0);        /* save umask */
                     umask(iUmask);
@@ -386 +405 @@
                     else
                         rc = 99;
+
                     g_progname = "kmk";                 /* paranoia, make sure it's not pointing at a freed argv[0]. */
                     umask(iUmask);                      /* restore it */
+
+#ifdef CONFIG_WITH_KMK_BUILTIN_STATS
+                    g_aBuiltInStats[pEntry - &g_aBuiltIns[0]].cTimes++;
+                    g_aBuiltInStats[pEntry - &g_aBuiltIns[0]].cNs += nano_timestamp() - nsStart;
+#endif
                 }
                 return rc;
@@ -411 +436 @@
 #endif
 
+#ifdef CONFIG_WITH_KMK_BUILTIN_STATS
+/**
+ * Prints the statistiscs to the given output stream.
+ */
+int kmk_builtin_print_stats(FILE *pOutput, const char *pszPrefix)
+{
+    const unsigned  cEntries = sizeof(g_aBuiltInStats) / sizeof(g_aBuiltInStats[0]);
+    unsigned i;
+    fprintf(pOutput, "\n%skmk built-in command statistics:\n", pszPrefix);
+    for (i = 0; i < cEntries; i++)
+        if (g_aBuiltInStats[i].cTimes > 0)
+        {
+            char szTotal[64];
+            char szAvg[64];
+            format_elapsed_nano(szTotal, sizeof(szTotal), g_aBuiltInStats[i].cNs);
+            format_elapsed_nano(szAvg, sizeof(szAvg), g_aBuiltInStats[i].cNs / g_aBuiltInStats[i].cTimes);
+            fprintf(pOutput, "%s kmk_builtin_%-9s: %4lu times, %9s total, %9s/call\n",
+                    pszPrefix, g_aBuiltIns[i].uName.s.sz, g_aBuiltInStats[i].cTimes, szTotal, szAvg);
+        }
+        else if (g_aBuiltInStats[i].cAsyncTimes > 0)
+            fprintf(pOutput, "%s kmk_builtin_%-9s: %4lu times in worker thread\n",
+                    pszPrefix, g_aBuiltIns[i].uName.s.sz, g_aBuiltInStats[i].cAsyncTimes);
+}
+#endif
+