feat(analytics) print CPU and Memory usage in logs (#2379)

docs/configuration-file.md

@@ -70,7 +70,8 @@ KICS is able to infer the format without the need of file extension.
   "queries-path": "path to directory with queries (default ./assets/queries) (default './assets/queries')",
   "report-formats": "formats in which the results will be exported (json, sarif, html)",
   "type": "type of queries to use in the scan",
-  "verbose": true
+  "verbose": true,
+  "profiling": "enables performance profiler that prints resource consumption metrics in the logs during the execution (CPU, MEM)"
 }
 ```
 
@@ -96,6 +97,7 @@ queries-path: "path to directory with queries (default ./assets/queries) (defaul
 report-formats: "formats in which the results will be exported (json, sarif, html)"
 type: "type of queries to use in the scan"
 verbose: true
+profiling: "enables performance profiler that prints resource consumption metrics in the logs during the execution (CPU, MEM)"
 ```
 
 #### TOML Format
@@ -120,6 +122,7 @@ queries-path = "path to directory with queries (default ./assets/queries) (defau
 report-formats = "formats in which the results will be exported (json, sarif, html)"
 type = "type of queries to use in the scan"
 verbose = true
+profiling = "enables performance profiler that prints resource consumption metrics in the logs during the execution (CPU, MEM)"
 ```
 
 #### HCL Format
@@ -144,6 +147,7 @@ verbose = true
 "report-formats" = "formats in which the results will be exported (json, sarif, html)"
 "type" = "type of queries to use in the scan"
 "verbose" = true
+"profiling" = "enables performance profiler that prints resource consumption metrics in the logs during the execution (CPU, MEM)"
 ```
 
 ---

docs/performance.md

@@ -0,0 +1,92 @@
+## KICS Accuracy Benchmark
+
+The values below were obtained after scanning 150 open source projects with KICS (v1.2.0) covering
+the supported IaC technologies (c.f., Terraform, Ansible, Kubernetes, Docker, AWS Cloudformation).
+
+
+| IaC Technology    | Query Accuracy<sup>1</sup>    | Query Coverage<sup>2</sup> | Scanned IaC files​ | Number of Results​ | Average Scan Time​ (s) | Average Project Size (MB) |
+| :---              | :---     | :---    | :--- | :---     | :---| :---|
+| Terraform​         | 99.7%​    | 46%     | 1176​ | 709      | 6.6  | 33.4​ |
+| Docker​            | 98.8%​​    | 68%​     | 1017​ | 5109     | 11   | 0.7 |​
+| Kubernetes​        | 99.3%​​    | 88.7%​   | 6089​ | 21753    | 7    | 90 |​
+| CloudFormation​    | 95%​      | 73%​     | 1769​ | 5343     | 10.2 | 4.8 |​
+| Ansible ​          | 100%     |​ 54%​     | 3367​ | 1320     | 23.3 | 4.1 |​
+
+---
+
+<sup>1</sup> Query Accuracy = TP results / results
+
+<sup>2</sup> Query Coverage = Query with results / Queries
+
+---
+
+<br/>
+
+### Global Measures
+
+|Measure                        | Value  |
+| :---                          | :---   |
+| **Average Accuracy**          | 98.6%  |
+| **Total Number of Results**   | 34234  |
+| **Average Query Coverage**    | 66.4%  |
+| **Total Scanned IaC Files**   | 13418  |
+| **Average Scan Time (s)**     | 11.2   |
+| **Average Project Size (MB)** | 26.6   |
+
+---
+## KICS Profiling
+
+Running Kics with ```--profiling``` flag will log the CPU/MEM metrics used for:
+
+- Getting Queries
+- Parsing Files
+- Scanning Vulnerabilities
+- Generating Reports
+
+Keep in mind that profiling will periodically stop KICS to retrieve the wanted metrics, meaning KICS execution time will increase substantially.
+
+---
+
+### CPU Profiling
+
+Flag: ```--profiling CPU```
+
+```text
+9:43AM INF Scanning with Keeping Infrastructure as Code Secure dev
+9:43AM INF Total CPU usage for get_queries: 6.56s <-
+9:43AM INF Inspector initialized, number of queries=1385
+9:43AM INF Total CPU usage for get_sources: 200.00ms <-
+9:43AM INF Total CPU usage for inspect: 15.43s <-
+9:43AM INF Results saved to file results/results.json fileName=results.json
+9:43AM INF Results saved to file results/results.sarif fileName=results.sarif
+9:43AM INF Results saved to file results/results.html fileName=results.html
+9:43AM INF Total CPU usage for generate_report: 290.00ms <-
+9:43AM INF Files scanned: 221
+9:43AM INF Parsed files: 221
+9:43AM INF Queries loaded: 1385
+9:43AM INF Queries failed to execute: 0
+9:43AM INF Inspector stopped
+9:43AM INF Scan duration: 21.1476197s
+```
+---
+### MEM Profiling
+
+Flag: ```--profiling MEM```
+
+```text
+9:43AM INF Scanning with Keeping Infrastructure as Code Secure dev
+9:43AM INF Total MEM usage for get_queries: 237.96MB <-
+9:43AM INF Inspector initialized, number of queries=1385
+9:43AM INF Total MEM usage for get_sources: 280.53MB <-
+9:43AM INF Total MEM usage for inspect: 335.44MB <-
+9:43AM INF Results saved to file results/results.json fileName=results.json
+9:43AM INF Results saved to file results/results.sarif fileName=results.sarif
+9:43AM INF Results saved to file results/results.html fileName=results.html
+9:43AM INF Total MEM usage for generate_report: 333.38MB <-
+9:43AM INF Files scanned: 221
+9:43AM INF Parsed files: 221
+9:43AM INF Queries loaded: 1385
+9:43AM INF Queries failed to execute: 0
+9:43AM INF Inspector stopped
+9:43AM INF Scan duration: 21.1476197s
+```

docs/usage/commands.md

@@ -22,6 +22,7 @@ Flags:
       --log-level string    determines log level (TRACE,DEBUG,INFO,WARN,ERROR,FATAL) (default "INFO")
       --log-path string     path to log files, (defaults to ${PWD}/info.log)
       --no-color            disable CLI color output
+      --profiling string    enables performance profiler that prints resource consumption metrics in the logs during the execution (CPU, MEM)
   -s, --silent              silence stdout messages (mutually exclusive with verbose and ci)
   -v, --verbose             write logs to stdout too (mutually exclusive with silent)
 
@@ -74,6 +75,7 @@ Global Flags:
       --log-level string    determines log level (TRACE,DEBUG,INFO,WARN,ERROR,FATAL) (default "INFO")
       --log-path string     path to log files, (defaults to ${PWD}/info.log)
       --no-color            disable CLI color output
+      --profiling string    enables performance profiler that prints resource consumption metrics in the logs during the execution (CPU, MEM)
   -s, --silent              silence stdout messages (mutually exclusive with verbose and ci)
   -v, --verbose             write logs to stdout too (mutually exclusive with silent)
 ```

e2e/fixtures/E2E_CLI_001

@@ -17,6 +17,7 @@ Flags:
       --log-level string    determines log level (TRACE,DEBUG,INFO,WARN,ERROR,FATAL) (default "INFO")
       --log-path string     path to log files, (defaults to ${PWD}/info.log)
       --no-color            disable CLI color output
+      --profiling string    enables performance profiler that prints resource consumption metrics in the logs during the execution (CPU, MEM)
   -s, --silent              silence stdout messages (mutually exclusive with verbose and ci)
   -v, --verbose             write logs to stdout too (mutually exclusive with silent)
 

e2e/fixtures/E2E_CLI_002

@@ -41,5 +41,6 @@ Global Flags:
       --log-level string    determines log level (TRACE,DEBUG,INFO,WARN,ERROR,FATAL) (default "INFO")
       --log-path string     path to log files, (defaults to ${PWD}/info.log)
       --no-color            disable CLI color output
+      --profiling string    enables performance profiler that prints resource consumption metrics in the logs during the execution (CPU, MEM)
   -s, --silent              silence stdout messages (mutually exclusive with verbose and ci)
   -v, --verbose             write logs to stdout too (mutually exclusive with silent)

e2e/fixtures/E2E_CLI_003

@@ -40,6 +40,7 @@ Global Flags:
       --log-level string    determines log level (TRACE,DEBUG,INFO,WARN,ERROR,FATAL) (default "INFO")
       --log-path string     path to log files, (defaults to ${PWD}/info.log)
       --no-color            disable CLI color output
+      --profiling string    enables performance profiler that prints resource consumption metrics in the logs during the execution (CPU, MEM)
   -s, --silent              silence stdout messages (mutually exclusive with verbose and ci)
   -v, --verbose             write logs to stdout too (mutually exclusive with silent)
 

e2e/fixtures/E2E_CLI_004

@@ -40,6 +40,7 @@ Global Flags:
       --log-level string    determines log level (TRACE,DEBUG,INFO,WARN,ERROR,FATAL) (default "INFO")
       --log-path string     path to log files, (defaults to ${PWD}/info.log)
       --no-color            disable CLI color output
+      --profiling string    enables performance profiler that prints resource consumption metrics in the logs during the execution (CPU, MEM)
   -s, --silent              silence stdout messages (mutually exclusive with verbose and ci)
   -v, --verbose             write logs to stdout too (mutually exclusive with silent)
 

go.mod

@@ -10,6 +10,7 @@ require (
 	github.com/getsentry/sentry-go v0.10.0
 	github.com/golang/mock v1.5.0
 	github.com/google/go-cmp v0.5.4 // indirect
+	github.com/google/pprof v0.0.0-20210413054141-7c2eacd09c8d
 	github.com/google/uuid v1.2.0
 	github.com/gookit/color v1.4.2
 	github.com/gregjones/httpcache v0.0.0-20190611155906-901d90724c79 // indirect

go.sum

@@ -590,7 +590,10 @@ github.com/google/pprof v0.0.0-20190515194954-54271f7e092f/go.mod h1:zfwlbNMJ+OI
 github.com/google/pprof v0.0.0-20191218002539-d4f498aebedc/go.mod h1:ZgVRPoUq/hfqzAqh7sHMqb3I9Rq5C59dIz2SbBwJ4eM=
 github.com/google/pprof v0.0.0-20200212024743-f11f1df84d12/go.mod h1:ZgVRPoUq/hfqzAqh7sHMqb3I9Rq5C59dIz2SbBwJ4eM=
 github.com/google/pprof v0.0.0-20200229191704-1ebb73c60ed3/go.mod h1:ZgVRPoUq/hfqzAqh7sHMqb3I9Rq5C59dIz2SbBwJ4eM=
+github.com/google/pprof v0.0.0-20200430221834-fc25d7d30c6d h1:iaAPcMIY2f+gpk8tKf0BMW5sLrlhaASiYAnFmvVG5e0=
 github.com/google/pprof v0.0.0-20200430221834-fc25d7d30c6d/go.mod h1:ZgVRPoUq/hfqzAqh7sHMqb3I9Rq5C59dIz2SbBwJ4eM=
+github.com/google/pprof v0.0.0-20210413054141-7c2eacd09c8d h1:X4vWSRcXmxBANxWPGUsfWv291lZUjENBew0l1R/RVRk=
+github.com/google/pprof v0.0.0-20210413054141-7c2eacd09c8d/go.mod h1:kpwsk12EmLew5upagYY7GY0pfYCcupk39gWOCRROcvE=
 github.com/google/renameio v0.1.0/go.mod h1:KWCgfxg9yswjAJkECMjeO8J8rahYeXnNhOm40UhjYkI=
 github.com/google/rpmpack v0.0.0-20191226140753-aa36bfddb3a0/go.mod h1:RaTPr0KUf2K7fnZYLNDrr8rxAamWs3iNywJLtQ2AzBg=
 github.com/google/shlex v0.0.0-20191202100458-e7afc7fbc510/go.mod h1:pupxD2MaaD3pAXIBCelhxNneeOaAeabZDe5s4K6zSpQ=
@@ -691,7 +694,9 @@ github.com/hpcloud/tail v1.0.0/go.mod h1:ab1qPbhIpdTxEkNHXyeSf5vhxWSCs/tWer42PpO
 github.com/huandu/xstrings v1.3.1 h1:4jgBlKK6tLKFvO8u5pmYjG91cqytmDCDvGh7ECVFfFs=
 github.com/huandu/xstrings v1.3.1/go.mod h1:y5/lhBue+AyNmUVz9RLU9xbLR0o4KIIExikq4ovT0aE=
 github.com/hudl/fargo v1.3.0/go.mod h1:y3CKSmjA+wD2gak7sUSXTAoopbhU08POFhmITJgmKTg=
+github.com/ianlancetaylor/demangle v0.0.0-20181102032728-5e5cf60278f6 h1:UDMh68UUwekSh5iP2OMhRRZJiiBccgV7axzUG8vi56c=
 github.com/ianlancetaylor/demangle v0.0.0-20181102032728-5e5cf60278f6/go.mod h1:aSSvb/t6k1mPoxDqO4vJh6VOCGPwU4O0C2/Eqndh1Sc=
+github.com/ianlancetaylor/demangle v0.0.0-20200824232613-28f6c0f3b639/go.mod h1:aSSvb/t6k1mPoxDqO4vJh6VOCGPwU4O0C2/Eqndh1Sc=
 github.com/imdario/mergo v0.3.5/go.mod h1:2EnlNZ0deacrJVfApfmtdGgDfMuh/nq6Ok1EcJh5FfA=
 github.com/imdario/mergo v0.3.8/go.mod h1:2EnlNZ0deacrJVfApfmtdGgDfMuh/nq6Ok1EcJh5FfA=
 github.com/imdario/mergo v0.3.9/go.mod h1:2EnlNZ0deacrJVfApfmtdGgDfMuh/nq6Ok1EcJh5FfA=

internal/console/helpers/helpers.go

@@ -12,6 +12,7 @@ import (
 	"sync"
 
 	"github.com/BurntSushi/toml"
+	"github.com/Checkmarx/kics/internal/global"
 	"github.com/Checkmarx/kics/pkg/model"
 	"github.com/Checkmarx/kics/pkg/report"
 	"github.com/gookit/color"
@@ -244,13 +245,15 @@ func FileAnalyzer(path string) (string, error) {
 // GenerateReport execute each report function to generate report
 func GenerateReport(path, filename string, body interface{}, formats []string) error {
 	log.Debug().Msgf("helpers.GenerateReport()")
+	global.Metric.Start("generate_report")
 	var err error = nil
 	for _, format := range formats {
 		if err = reportGenerators[format](path, filename, body); err != nil {
 			log.Error().Msgf("Failed to generate %s report", format)
 			break
 		}
 	}
+	global.Metric.Stop()
 	return err
 }
 

internal/console/kics.go

@@ -30,6 +30,7 @@ var (
 	logPath   string
 	noColor   bool
 	silent    bool
+	profiling string
 	verbose   bool
 
 	warning []string
@@ -89,9 +90,13 @@ func initialize(rootCmd *cobra.Command) error {
 		"",
 		false,
 		"display only log messages to CLI output (mutually exclusive with silent)")
+	rootCmd.PersistentFlags().StringVarP(&profiling,
+		"profiling",
+		"",
+		"",
+		"enables performance profiler that prints resource consumption metrics in the logs during the execution (CPU, MEM)")
 
-	err := rootCmd.PersistentFlags().MarkDeprecated(printer.LogFileFlag, "please use --log-path instead")
-	if err != nil {
+	if err := rootCmd.PersistentFlags().MarkDeprecated(printer.LogFileFlag, "please use --log-path instead"); err != nil {
 		return err
 	}
 
@@ -132,7 +137,7 @@ func Execute() error {
 	}
 	defer sentry.Flush(timeMult * time.Second)
 
-	if err := initialize(rootCmd); err != nil {
+	if err = initialize(rootCmd); err != nil {
 		sentry.CaptureException(err)
 		log.Err(err).Msg("Failed to initialize CLI")
 		return err

internal/console/scan.go

@@ -13,6 +13,8 @@ import (
 	consoleHelpers "github.com/Checkmarx/kics/internal/console/helpers"
 	internalPrinter "github.com/Checkmarx/kics/internal/console/printer"
 	"github.com/Checkmarx/kics/internal/constants"
+	"github.com/Checkmarx/kics/internal/global"
+	"github.com/Checkmarx/kics/internal/metrics"
 	"github.com/Checkmarx/kics/internal/storage"
 	"github.com/Checkmarx/kics/internal/tracker"
 	"github.com/Checkmarx/kics/pkg/engine"
@@ -90,12 +92,17 @@ func NewScanCmd() *cobra.Command {
 		Use:   scanCommandStr,
 		Short: "Executes a scan analysis",
 		PersistentPreRunE: func(cmd *cobra.Command, args []string) error {
-			err := initializeConfig(cmd)
-			if err != nil {
+			if err := initializeConfig(cmd); err != nil {
+				return err
+			}
+			if err := internalPrinter.SetupPrinter(cmd.InheritedFlags()); err != nil {
 				return err
 			}
-			err = internalPrinter.SetupPrinter(cmd.InheritedFlags())
+			var err error
+			global.Metric, err = metrics.InitializeMetrics(cmd.InheritedFlags().Lookup("profiling"))
 			if err != nil {
+				sentry.CaptureException(err)
+				log.Err(err).Msg("Failed to initialize Metrics")
 				return err
 			}
 			return nil

internal/global/global.go

@@ -0,0 +1,12 @@
+package global
+
+import (
+	"github.com/Checkmarx/kics/internal/metrics"
+)
+
+var (
+	// Metric is the global metrics object
+	Metric = &metrics.Metrics{
+		Disable: true,
+	}
+)