feat: adding EXTERNAL_TOOL_DURATION key (#488)

CHANGELOG.md

@@ -21,6 +21,12 @@
   always off by the heartbeats interval - default 10 minutes.
   ([#487](https://github.com/crashappsec/chalk/pull/487))
 
+### New Features
+
+- `EXTERNAL_TOOL_DURATION` key which reports external tool duration
+  for each invocation.
+  ([#488](https://github.com/crashappsec/chalk/pull/488))
+
 ## 0.5.3
 
 **Feb 3, 2025**

src/configs/base_keyspecs.c4m

@@ -1499,6 +1499,22 @@ collecting this information.
 """
 }
 
+keyspec EXTERNAL_TOOL_DURATION {
+    kind:             ChalkTimeArtifact
+    type:             dict[string, dict[string, int]]
+    standard:         true
+    since:            "0.5.4"
+    shortdoc:         "Duration of each external tool invocation in ms"
+    doc:              """
+Duration how long in ms each external tool invocation took.
+The value is grouped by:
+
+* external tool name
+* execution context
+* duration
+"""
+}
+
 keyspec INFERRED_TECH_STACKS {
     kind:             ChalkTimeArtifact
     type:             `x

src/configs/base_report_templates.c4m

@@ -106,6 +106,7 @@ report and subtract from it.
   key.EMBEDDED_CHALK.use                      = true
   key.EMBEDDED_TMPDIR.use                     = true
   key.CLOUD_METADATA_WHEN_CHALKED.use         = true
+  key.EXTERNAL_TOOL_DURATION.use              = true
   key.SBOM.use                                = true
   key.SAST.use                                = true
   key.ERR_INFO.use                            = true
@@ -503,6 +504,7 @@ doc: """
   key.INJECTOR_ARGV.use                       = true
   key.INJECTOR_ENV.use                        = true
   key.TENANT_ID_WHEN_CHALKED.use              = true
+  key.EXTERNAL_TOOL_DURATION.use              = true
   key.SBOM.use                                = true
   key.SAST.use                                = true
   key._ACTION_ID.use                          = true
@@ -708,6 +710,7 @@ doc: """
   key.EMBEDDED_CHALK.use                      = true
   key.EMBEDDED_TMPDIR.use                     = true
   key.CLOUD_METADATA_WHEN_CHALKED.use         = true
+  key.EXTERNAL_TOOL_DURATION.use              = true
   key.SBOM.use                                = true
   key.SAST.use                                = true
   key.ERR_INFO.use                            = true
@@ -1011,6 +1014,7 @@ container.
   key.INJECTOR_ARGV.use                       = true
   key.INJECTOR_ENV.use                        = true
   key.TENANT_ID_WHEN_CHALKED.use              = true
+  key.EXTERNAL_TOOL_DURATION.use              = true
   key.SBOM.use                                = true
   key.SAST.use                                = true
 
@@ -1193,6 +1197,7 @@ container.
   key.EMBEDDED_CHALK.use                      = true
   key.EMBEDDED_TMPDIR.use                     = true
   key.CLOUD_METADATA_WHEN_CHALKED.use         = true
+  key.EXTERNAL_TOOL_DURATION.use              = true
   key.SBOM.use                                = true
   key.SAST.use                                = true
   key.ERR_INFO.use                            = true
@@ -1678,6 +1683,7 @@ and keep the run-time key.
   key.EMBEDDED_CHALK.use                      = true
   key.EMBEDDED_TMPDIR.use                     = true
   key.CLOUD_METADATA_WHEN_CHALKED.use         = true
+  key.EXTERNAL_TOOL_DURATION.use              = true
   key.SBOM.use                                = true
   key.SAST.use                                = true
   key.ERR_INFO.use                            = true

src/configs/crashoverride.c4m

@@ -222,6 +222,7 @@ This is mostly a copy of insert template however all keys are immutable.
   ~key.EMBEDDED_CHALK.use                      = true
   ~key.EMBEDDED_TMPDIR.use                     = true
   ~key.CLOUD_METADATA_WHEN_CHALKED.use         = true
+  ~key.EXTERNAL_TOOL_DURATION.use              = true
   ~key.SBOM.use                                = true
   ~key.SAST.use                                = true
   ~key.ERR_INFO.use                            = true

src/plugins/externalTool.nim

@@ -8,7 +8,7 @@
 ## This plugin uses information from the config file to set metadata
 ## keys.
 
-import std/[algorithm, sequtils, sets]
+import std/[algorithm, sequtils, sets, times]
 import ".."/[config, plugin_api, util]
 import "."/[vctlGit]
 
@@ -75,7 +75,7 @@ proc runOneTool(info: PIInfo, path: string): ChalkDict =
   alreadyRan.incl(key)
   return d
 
-template toolBase(path: string) {.dirty.} =
+proc toolBase(path: string): ChalkDict =
   let resolved = path.resolvePath()
   result = ChalkDict()
 
@@ -106,7 +106,8 @@ template toolBase(path: string) {.dirty.} =
   for k, v in toolInfo:
     for (ignore, info) in v.sorted():
       try:
-        let data = info.runOneTool(resolved)
+        withDuration():
+          let data = info.runOneTool(resolved)
         # merge multiple tools into a single structure
         # for example first tool returns:
         # { SBOM: { foo: {...} } }
@@ -115,6 +116,11 @@ template toolBase(path: string) {.dirty.} =
         # merged structure should be:
         # { SBOM: { foo: {...}, bar: {...} } }
         result.merge(data.nestWith(info.name))
+        let timing = ChalkDict()
+        timing["EXTERNAL_TOOL_DURATION"] = pack(duration.inMilliseconds())
+        # add duration with structure:
+        # { 'EXTERNAL_TOOL_DURATION': {'<tool>': {'<path>': duration_ms}}}
+        result.merge(timing.nestWith(resolved).nestWith(info.name), deep = true)
         if len(data) >= 0 and attrGet[bool]("tool." & info.name & ".stop_on_success"):
           break
       except AlreadyRanError:
@@ -131,22 +137,24 @@ proc getToolPath(path: string): string =
     return path
 
 proc toolGetChalkTimeHostInfo(self: Plugin): ChalkDict {.cdecl.} =
+  result = ChalkDict()
   for c in getContextDirectories():
-    toolBase(getToolPath(c))
+    result.merge(toolBase(getToolPath(c)))
     # only care about first context
     break
 
 proc toolGetChalkTimeArtifactInfo(self: Plugin, obj: ChalkObj):
                                  ChalkDict {.cdecl.} =
+  result = ChalkDict()
   if obj.fsRef != "":
-    toolBase(obj.fsRef)
+    result.merge(toolBase(obj.fsRef))
   elif getCommandName() == "build":
     for c in getContextDirectories():
-      toolBase(getToolPath(c))
+      result.merge(toolBase(getToolPath(c)))
       # only care about first context
       break
   else:
-    toolBase(obj.name)
+    result.merge(toolBase(obj.name))
 
 proc loadExternalTool*() =
   newPlugin("tool",

src/util.nim

@@ -587,7 +587,7 @@ proc update*(self: JsonNode, other: JsonNode): JsonNode {.discardable.} =
       self[k] = v
   return self
 
-proc merge*(self: ChalkDict, other: ChalkDict): ChalkDict {.discardable.} =
+proc merge*(self: ChalkDict, other: ChalkDict, deep = false): ChalkDict {.discardable.} =
   result = self
   for k, v in other:
     if k in self and self[k].kind == MkSeq and v.kind == MkSeq:
@@ -596,8 +596,11 @@ proc merge*(self: ChalkDict, other: ChalkDict): ChalkDict {.discardable.} =
       let
         mine   = unpack[ChalkDict](self[k])
         theirs = unpack[ChalkDict](v)
-      for kk, vv in theirs:
-        mine[kk] = vv
+      if deep:
+        mine.merge(theirs)
+      else:
+        for kk, vv in theirs:
+          mine[kk] = vv
       self[k] = pack(mine)
     else:
       self[k] = v
@@ -656,3 +659,11 @@ proc forReport*(t: DateTime): DateTime =
   # eventually we might add a config to specify in which TZ to report in
   # however for now normalize to local timezone for reading report output
   return t.local
+
+template withDuration*(c: untyped) =
+  let start = getMonoTime()
+  c
+  let
+    stop                = getMonoTime()
+    diff                = stop - start
+    duration {.inject.} = diff

tests/functional/data/configs/composable/valid/sast/enable_sast.c4m

@@ -7,9 +7,11 @@ report_template.terminal_insert.key.SAST.use: true
 
 # `chalk insert` uses the mark_default template.
 mark_template.mark_default.key.SAST.use: true
+mark_template.mark_default.key.EXTERNAL_TOOL_DURATION.use: true
 
 # `chalk docker build` uses the `minimal` template.
 mark_template.minimal.key.SAST.use: true
+mark_template.minimal.key.EXTERNAL_TOOL_DURATION.use: true
 
 tool.semgrep.semgrep_config_profile: "rule.yaml"
 

tests/functional/test_plugins.py

@@ -915,6 +915,11 @@ def test_semgrep(
 
     # expected sast output with custom rule
     report_sast_data = {
+        "EXTERNAL_TOOL_DURATION": {
+            "semgrep": {
+                str(tmp_data_dir): int,
+            },
+        },
         "SAST": {
             "semgrep": {
                 "runs": [
@@ -962,9 +967,14 @@ def test_semgrep(
                     }
                 ],
             }
-        }
+        },
     }
     mark_sast_data = {
+        "EXTERNAL_TOOL_DURATION": {
+            "semgrep": {
+                str(tmp_data_dir / "hello.sh"): int,
+            },
+        },
         "SAST": {
             "semgrep": {
                 "runs": [
@@ -984,7 +994,7 @@ def test_semgrep(
                     }
                 ],
             }
-        }
+        },
     }
 
     insert = chalk.insert(