trivy icon indicating copy to clipboard operation
trivy copied to clipboard

bug (k8s): intermittent failures in k8s scanning

Open afdesk opened this issue 1 year ago • 0 comments

Description

SOMETIMES a k8s scan fails with a panic.

It happens when Trivy executes PostAnalyze yet, but the temporary file is already removed.

I managed to enable logs and caught it.

the full log
$ ./tr k8s --report all --include-namespaces rbac-test --compliance k8s-pss-baseline-0.1 --debug

2024-10-09T11:55:36+06:00       DEBUG   Compliance spec loaded from disk bundle spec="k8s-pss-baseline-0.1"
2024-10-09T11:55:36+06:00       DEBUG   Parsed severities       severities=[UNKNOWN LOW MEDIUM HIGH CRITICAL]
2024-10-09T11:55:36+06:00       DEBUG   Ignore statuses statuses=[]
2024-10-09T11:55:38+06:00       INFO    Node scanning is enabled
2024-10-09T11:55:38+06:00       INFO    If you want to disable Node scanning via an in-cluster Job, please try '--disable-node-collector' to disable the Node-Collector job.
2024-10-09T11:55:38+06:00       INFO    [misconfig] Misconfiguration scanning is enabled
2024-10-09T11:55:38+06:00       INFO    [misconfig] Misconfiguration scanning is enabled
2024-10-09T11:55:38+06:00       INFO    [misconfig] Misconfiguration scanning is enabled
2024-10-09T11:55:38+06:00       INFO    [misconfig] Misconfiguration scanning is enabled
2024-10-09T11:55:38+06:00       DEBUG   [misconfig] Checks successfully loaded from disk
2024-10-09T11:55:38+06:00       INFO    [misconfig] Misconfiguration scanning is enabled
2024-10-09T11:55:38+06:00       DEBUG   Enabling misconfiguration scanners      scanners=[azure-arm cloudformation dockerfile helm kubernetes terraform terraformplan-json terraformplan-snapshot]
2024-10-09T11:55:38+06:00       DEBUG   [misconfig] Checks successfully loaded from disk
2024-10-09T11:55:38+06:00       DEBUG   Enabling misconfiguration scanners      scanners=[azure-arm cloudformation dockerfile helm kubernetes terraform terraformplan-json terraformplan-snapshot]
2024-10-09T11:55:38+06:00       DEBUG   Initializing scan cache...      type="fs"
2024-10-09T11:55:38+06:00       DEBUG   Initializing scan cache...      type="fs"
2024-10-09T11:55:38+06:00       DEBUG   [misconfig] Checks successfully loaded from disk
2024-10-09T11:55:38+06:00       DEBUG   Enabling misconfiguration scanners      scanners=[azure-arm cloudformation dockerfile helm kubernetes terraform terraformplan-json terraformplan-snapshot]
2024-10-09T11:55:38+06:00       DEBUG   Initializing scan cache...      type="fs"
2024-10-09T11:55:38+06:00       DEBUG   [misconfig] Checks successfully loaded from disk
2024-10-09T11:55:38+06:00       DEBUG   Enabling misconfiguration scanners      scanners=[azure-arm cloudformation dockerfile helm kubernetes terraform terraformplan-json terraformplan-snapshot]
2024-10-09T11:55:38+06:00       DEBUG   Initializing scan cache...      type="fs"
2024-10-09T11:55:38+06:00       DEBUG   [misconfig] Checks successfully loaded from disk
2024-10-09T11:55:38+06:00       DEBUG   Enabling misconfiguration scanners      scanners=[azure-arm cloudformation dockerfile helm kubernetes terraform terraformplan-json terraformplan-snapshot]
2024-10-09T11:55:38+06:00       DEBUG   Initializing scan cache...      type="fs"
2024-10-09T11:55:38+06:00       DEBUG   Scanning files for misconfigurations... scanner="Kubernetes"
6 / 6 [--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------->] 100.00% ? p/s2024-10-09T11:55:38+06:00       DEBUG   [rego] Overriding filesystem for checks
2024-10-09T11:55:38+06:00       DEBUG   [rego] Embedded libraries are loaded    count=13
2024-10-09T11:55:39+06:00       DEBUG   [rego] Embedded checks are loaded       count=508
2024-10-09T11:55:39+06:00       DEBUG   [rego] Checks from disk are loaded      count=521
2024-10-09T11:55:39+06:00       DEBUG   [rego] Overriding filesystem for data
6 / 6 [--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------->] 100.00% ? p/s2024-10-09T11:55:39+06:00       DEBUG   [k8s scanner] Scanning files    count=1
2024-10-09T11:55:39+06:00       DEBUG   [rego] Scanning inputs  count=1
2024-10-09T11:55:39+06:00       DEBUG   Scanning files for misconfigurations... scanner="Helm"
2024-10-09T11:55:39+06:00       DEBUG   [rego] Overriding filesystem for checks
2024-10-09T11:55:39+06:00       DEBUG   [rego] Embedded libraries are loaded    count=13
6 / 6 [--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------->] 100.00% ? p/s2024-10-09T11:55:39+06:00       DEBUG   [rego] Embedded checks are loaded       count=508
2024-10-09T11:55:39+06:00       DEBUG   [rego] Checks from disk are loaded      count=521
2024-10-09T11:55:39+06:00       DEBUG   [rego] Overriding filesystem for data
6 / 6 [--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------->] 100.00% ? p/s2024-10-09T11:55:39+06:00       DEBUG   OS is not detected.
2024-10-09T11:55:39+06:00       INFO    Detected config files   num=1
2024-10-09T11:55:39+06:00       DEBUG   Scanned config file     file_path="rbac-test-Deployment-my-web-deploy-1589231793.yaml"
2024-10-09T11:55:39+06:00       INFO    Removing temporary file path="/var/folders/q0/ykp5nvjx0j5_t4llxyh5hcm40000gn/T/rbac-test-Deployment-my-web-deploy-1589231793.yaml"
2024-10-09T11:55:39+06:00       DEBUG   [vex] VEX filtering is disabled
2024-10-09T11:55:39+06:00       INFO    [misconfig] Misconfiguration scanning is enabled
2024-10-09T11:55:39+06:00       DEBUG   [misconfig] Checks successfully loaded from disk
2024-10-09T11:55:39+06:00       DEBUG   Enabling misconfiguration scanners      scanners=[azure-arm cloudformation dockerfile helm kubernetes terraform terraformplan-json terraformplan-snapshot]
2024-10-09T11:55:39+06:00       DEBUG   Initializing scan cache...      type="fs"
2024-10-09T11:55:39+06:00       DEBUG   Scanning files for misconfigurations... scanner="Kubernetes"
2024-10-09T11:55:39+06:00       DEBUG   [rego] Overriding filesystem for checks
2024-10-09T11:55:39+06:00       DEBUG   [rego] Embedded libraries are loaded    count=13
2024-10-09T11:55:39+06:00       DEBUG   [rego] Embedded checks are loaded       count=508
6 / 6 [--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------->] 100.00% ? p/s2024-10-09T11:55:39+06:00       DEBUG   [rego] Checks from disk are loaded      count=521
2024-10-09T11:55:39+06:00       DEBUG   [rego] Overriding filesystem for data
2024-10-09T11:55:39+06:00       DEBUG   [k8s scanner] Scanning files    count=1
2024-10-09T11:55:39+06:00       DEBUG   [rego] Scanning inputs  count=1
2024-10-09T11:55:39+06:00       DEBUG   Scanning files for misconfigurations... scanner="Helm"
2024-10-09T11:55:39+06:00       DEBUG   [rego] Overriding filesystem for checks
2024-10-09T11:55:39+06:00       DEBUG   [rego] Embedded libraries are loaded    count=13
6 / 6 [--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------->] 100.00% ? p/s2024-10-09T11:55:39+06:00       DEBUG   [rego] Embedded checks are loaded       count=508
2024-10-09T11:55:39+06:00       DEBUG   [rego] Checks from disk are loaded      count=521
2024-10-09T11:55:39+06:00       DEBUG   [rego] Overriding filesystem for data
6 / 6 [--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------->] 100.00% ? p/s2024-10-09T11:55:40+06:00       DEBUG   OS is not detected.
2024-10-09T11:55:40+06:00       INFO    Detected config files   num=1
2024-10-09T11:55:40+06:00       DEBUG   Scanned config file     file_path="rbac-test-RoleBinding-user1-ns-reader-binding-370168013.yaml"
2024-10-09T11:55:40+06:00       INFO    Removing temporary file path="/var/folders/q0/ykp5nvjx0j5_t4llxyh5hcm40000gn/T/rbac-test-RoleBinding-user1-ns-reader-binding-370168013.yaml"
2024-10-09T11:55:40+06:00       DEBUG   [vex] VEX filtering is disabled
2024-10-09T11:55:40+06:00       DEBUG   Scanning files for misconfigurations... scanner="Helm"
2024-10-09T11:55:40+06:00       DEBUG   [rego] Overriding filesystem for checks
2024-10-09T11:55:40+06:00       DEBUG   [rego] Embedded libraries are loaded    count=13
2024-10-09T11:55:40+06:00       DEBUG   [rego] Embedded checks are loaded       count=508
6 / 6 [--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------->] 100.00% ? p/s2024-10-09T11:55:40+06:00       DEBUG   [rego] Checks from disk are loaded      count=521
2024-10-09T11:55:40+06:00       DEBUG   [rego] Overriding filesystem for data
2024-10-09T11:55:40+06:00       DEBUG   Scanning files for misconfigurations... scanner="Kubernetes"
2024-10-09T11:55:40+06:00       DEBUG   [rego] Overriding filesystem for checks
2024-10-09T11:55:40+06:00       DEBUG   [rego] Embedded libraries are loaded    count=13
6 / 6 [--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------->] 100.00% ? p/s2024-10-09T11:55:40+06:00       DEBUG   [rego] Embedded checks are loaded       count=508
2024-10-09T11:55:40+06:00       DEBUG   [rego] Checks from disk are loaded      count=521
2024-10-09T11:55:40+06:00       DEBUG   [rego] Overriding filesystem for data
6 / 6 [--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------->] 100.00% ? p/s2024-10-09T11:55:40+06:00       DEBUG   [k8s scanner] Scanning files    count=1
2024-10-09T11:55:40+06:00       DEBUG   [rego] Scanning inputs  count=1
2024-10-09T11:55:40+06:00       DEBUG   OS is not detected.
2024-10-09T11:55:40+06:00       INFO    Detected config files   num=1
2024-10-09T11:55:40+06:00       DEBUG   Scanned config file     file_path="rbac-test-ConfigMap-kube-root-ca.crt-1889279511.yaml"
2024-10-09T11:55:40+06:00       INFO    Removing temporary file path="/var/folders/q0/ykp5nvjx0j5_t4llxyh5hcm40000gn/T/rbac-test-ConfigMap-kube-root-ca.crt-1889279511.yaml"
2024-10-09T11:55:40+06:00       DEBUG   [vex] VEX filtering is disabled
2024-10-09T11:55:40+06:00       DEBUG   Scanning files for misconfigurations... scanner="Helm"
2024-10-09T11:55:40+06:00       DEBUG   [rego] Overriding filesystem for checks
2024-10-09T11:55:40+06:00       DEBUG   [rego] Embedded libraries are loaded    count=13
6 / 6 [--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------->] 100.00% ? p/s2024-10-09T11:55:40+06:00       DEBUG   [rego] Embedded checks are loaded       count=508
2024-10-09T11:55:41+06:00       DEBUG   [rego] Checks from disk are loaded      count=521
2024-10-09T11:55:41+06:00       DEBUG   [rego] Overriding filesystem for data
6 / 6 [--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------->] 100.00% ? p/s2024-10-09T11:55:41+06:00       DEBUG   Scanning files for misconfigurations... scanner="Kubernetes"
2024-10-09T11:55:41+06:00       DEBUG   [rego] Overriding filesystem for checks
2024-10-09T11:55:41+06:00       DEBUG   [rego] Embedded libraries are loaded    count=13
2024-10-09T11:55:41+06:00       DEBUG   [rego] Embedded checks are loaded       count=508
2024-10-09T11:55:41+06:00       DEBUG   [rego] Checks from disk are loaded      count=521
2024-10-09T11:55:41+06:00       DEBUG   [rego] Overriding filesystem for data
6 / 6 [--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------->] 100.00% ? p/s2024-10-09T11:55:41+06:00       DEBUG   [k8s scanner] Scanning files    count=1
2024-10-09T11:55:41+06:00       DEBUG   [rego] Scanning inputs  count=1
2024-10-09T11:55:41+06:00       DEBUG   OS is not detected.
2024-10-09T11:55:41+06:00       INFO    Detected config files   num=1
2024-10-09T11:55:41+06:00       DEBUG   Scanned config file     file_path="rbac-test-ServiceAccount-default-1133560203.yaml"
2024-10-09T11:55:41+06:00       INFO    Removing temporary file path="/var/folders/q0/ykp5nvjx0j5_t4llxyh5hcm40000gn/T/rbac-test-ServiceAccount-default-1133560203.yaml"
2024-10-09T11:55:41+06:00       DEBUG   [vex] VEX filtering is disabled
6 / 6 [--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------->] 100.00% ? p/s2024-10-09T11:55:41+06:00       DEBUG   Scanning files for misconfigurations... scanner="Kubernetes"
2024-10-09T11:55:41+06:00       DEBUG   [rego] Overriding filesystem for checks
2024-10-09T11:55:41+06:00       DEBUG   [rego] Embedded libraries are loaded    count=13
2024-10-09T11:55:41+06:00       DEBUG   [rego] Embedded checks are loaded       count=508
2024-10-09T11:55:41+06:00       DEBUG   [rego] Checks from disk are loaded      count=521
2024-10-09T11:55:41+06:00       DEBUG   [rego] Overriding filesystem for data
6 / 6 [--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------->] 100.00% ? p/s2024-10-09T11:55:41+06:00       DEBUG   [k8s scanner] Scanning files    count=1
2024-10-09T11:55:41+06:00       DEBUG   [rego] Scanning inputs  count=1
2024-10-09T11:55:41+06:00       DEBUG   Scanning files for misconfigurations... scanner="Helm"
2024-10-09T11:55:41+06:00       DEBUG   [rego] Overriding filesystem for checks
2024-10-09T11:55:41+06:00       DEBUG   [rego] Embedded libraries are loaded    count=13
2024-10-09T11:55:41+06:00       DEBUG   [rego] Embedded checks are loaded       count=508
6 / 6 [--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------->] 100.00% ? p/s2024-10-09T11:55:41+06:00       DEBUG   [rego] Checks from disk are loaded      count=521
2024-10-09T11:55:41+06:00       DEBUG   [rego] Overriding filesystem for data
6 / 6 [--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------->] 100.00% ? p/s2024-10-09T11:55:42+06:00       DEBUG   OS is not detected.
2024-10-09T11:55:42+06:00       INFO    Detected config files   num=1
2024-10-09T11:55:42+06:00       DEBUG   Scanned config file     file_path="rbac-test-ServiceAccount-user1-1956903791.yaml"
2024-10-09T11:55:42+06:00       INFO    Removing temporary file path="/var/folders/q0/ykp5nvjx0j5_t4llxyh5hcm40000gn/T/rbac-test-ServiceAccount-user1-1956903791.yaml"
2024-10-09T11:55:42+06:00       DEBUG   [vex] VEX filtering is disabled
2024-10-09T11:55:42+06:00       INFO    Removing temporary file path="/var/folders/q0/ykp5nvjx0j5_t4llxyh5hcm40000gn/T/rbac-test-Role-ns-reader-3536559846.yaml"
6 / 6 [----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------] 100.00% 2 p/s
2024-10-09T11:55:42+06:00       FATAL   Fatal error
  - k8s scan error:
    github.com/aquasecurity/trivy/pkg/k8s/commands.(*runner).run
        /Users/amf/aqua/my-trivy/pkg/k8s/commands/run.go:91
  - scanning misconfigurations error:
    github.com/aquasecurity/trivy/pkg/k8s/scanner.(*Scanner).Scan.func1
        /Users/amf/aqua/my-trivy/pkg/k8s/scanner/scanner.go:116
  - scan error:
    github.com/aquasecurity/trivy/pkg/commands/artifact.(*runner).scanArtifact
        /Users/amf/aqua/my-trivy/pkg/commands/artifact/run.go:261
  - scan failed:
    github.com/aquasecurity/trivy/pkg/commands/artifact.(*runner).scan
        /Users/amf/aqua/my-trivy/pkg/commands/artifact/run.go:622
  - failed analysis:
    github.com/aquasecurity/trivy/pkg/scanner.Scanner.ScanArtifact
        /Users/amf/aqua/my-trivy/pkg/scanner/scan.go:158
  - walk filesystem:
    github.com/aquasecurity/trivy/pkg/fanal/artifact/local.Artifact.Inspect
        /Users/amf/aqua/my-trivy/pkg/fanal/artifact/local/fs.go:113
  - walk dir error:
    github.com/aquasecurity/trivy/pkg/fanal/walker.(*FS).Walk
        /Users/amf/aqua/my-trivy/pkg/fanal/walker/fs.go:35
  - unknown error with /var/folders/q0/ykp5nvjx0j5_t4llxyh5hcm40000gn/T/rbac-test-ServiceAccount-user1-1956903791.yaml:
    github.com/aquasecurity/trivy/pkg/fanal/walker.(*FS).Walk.(*FS).onError.func2
        /Users/amf/aqua/my-trivy/pkg/fanal/walker/fs.go:92
  - lstat /var/folders/q0/ykp5nvjx0j5_t4llxyh5hcm40000gn/T/rbac-test-ServiceAccount-user1-1956903791.yaml: no such file or directory

Reason

Now Trivy k8s scan tries to handle kubernetes yaml files in parallel. Because Trivy creates a misconfig scanner for each thread, sometime one misconfig scanner works faster and removes a temporary file, then another misconfig scanner can't find this temporary yaml and will arise a fatal error.

Discussed in https://github.com/aquasecurity/trivy/discussions/7663

afdesk avatar Oct 09 '24 06:10 afdesk