Merge pull request #1050 from snyk/chore/add-more-debug-logs

RUN-2198 chore: add more logs for debug purpose

Author: minsiyang

src/common/process.ts

@@ -28,7 +28,8 @@ export function exec(
   const allArguments = processArgs.map((arg) => arg.body);
   return spawn(bin, allArguments, { env, capture: ['stdout', 'stderr'] }).catch(
     (error) => {
-      const message = (error && error.stderr) || 'Unknown reason';
+      const message =
+        error?.stderr || error?.stdout || error?.message || 'Unknown reason';
       const loggableArguments = processArgs
         .filter((arg) => !arg.sanitise)
         .map((arg) => arg.body);

src/supervisor/metadata-extractor.ts

@@ -30,6 +30,7 @@ export function buildImageMetadata(
     delete container.args;
     delete container.env;
     delete container.command;
+    //! would container.envFrom also include sensitive data?
     containerNameToSpec[container.name] = container;
   }
 
@@ -41,6 +42,17 @@ export function buildImageMetadata(
   const images: IWorkload[] = [];
   for (const containerStatus of containerStatuses) {
     if (!(containerStatus.name in containerNameToSpec)) {
+      logger.debug(
+        {
+          workloadName: workloadMeta.objectMeta.name,
+          workloadType: workloadMeta.kind,
+          workloadNamespace: workloadMeta.objectMeta.namespace,
+          containerName: containerStatus.name,
+          image: containerStatus.image,
+          imageId: containerStatus.imageID,
+        },
+        'container name is not in containerNameToSpec lists',
+      );
       continue;
     }
     images.push({
@@ -143,6 +155,16 @@ export async function buildMetadataForWorkload(
   const isAssociatedWithParent = isPodAssociatedWithParent(pod);
 
   if (!pod.metadata || pod.metadata.namespace === undefined || !pod.spec) {
+    const logContext = {
+      workloadName: pod.metadata?.name,
+      workloadType: pod.kind,
+      workloadNamespace: pod.metadata?.namespace,
+      clusterName: pod.metadata?.clusterName,
+    };
+    logger.debug(
+      logContext,
+      'cannot build metadata for workload without pod information',
+    );
     // Some required parameters are missing, we cannot process further
     return undefined;
   }

src/supervisor/watchers/handlers/pod.ts

@@ -38,8 +38,16 @@ export async function handleReadyPod(
     // ImageName may contain a tag. The image behind this tag can be mutated and can change over time.
     // We need to compare on ImageID which will reliably tell us if the image has changed.
     if (scanned === workload.imageId) {
+      logger.debug(
+        { workloadToScan, imageId: workload.imageId },
+        'image already scanned',
+      );
       continue;
     }
+    logger.debug(
+      { workloadToScan, imageId: workload.imageId },
+      'image has not been scanned',
+    );
     await setWorkloadImageAlreadyScanned(
       workload,
       workload.imageName,
@@ -59,16 +67,28 @@ export async function handleReadyPod(
 }
 
 export function isPodReady(pod: V1Pod): boolean {
+  const podStatus = pod.status !== undefined;
+  const podStatusPhase = pod.status?.phase === PodPhase.Running;
+  const podContainerStatuses = pod.status?.containerStatuses !== undefined;
+  const containerReadyStatuses = pod.status?.containerStatuses?.some(
+    (container) =>
+      container.state !== undefined &&
+      (container.state.running !== undefined ||
+        container.state.waiting !== undefined),
+  ) as boolean;
+
+  const logContext = {
+    podStatus,
+    podStatusPhase,
+    podContainerStatuses,
+    containerReadyStatuses,
+  };
+  logger.debug(logContext, 'checking to see if pod is ready to process');
   return (
-    pod.status !== undefined &&
-    pod.status.phase === PodPhase.Running &&
-    pod.status.containerStatuses !== undefined &&
-    pod.status.containerStatuses.some(
-      (container) =>
-        container.state !== undefined &&
-        (container.state.running !== undefined ||
-          container.state.waiting !== undefined),
-    )
+    podStatus &&
+    podStatusPhase &&
+    podContainerStatuses &&
+    containerReadyStatuses
   );
 }
 

src/supervisor/workload-sanitization.ts

@@ -1,4 +1,5 @@
 import { KubernetesObject, V1ObjectMeta } from '@kubernetes/client-node';
+import { logger } from '../common/logger';
 
 export function trimWorkloads<
   T extends KubernetesObject & Partial<{ status: unknown; spec: unknown }>,
@@ -14,6 +15,7 @@ export function trimWorkloads<
 export function trimWorkload<
   T extends KubernetesObject & Partial<{ status: unknown; spec: unknown }>,
 >(workload: T): T & { metadata: V1ObjectMeta } {
+  logger.debug(workload.metadata, 'workload metadata state before trimming');
   return {
     apiVersion: workload.apiVersion,
     kind: workload.kind,
@@ -24,7 +26,7 @@ export function trimWorkload<
 }
 
 export function trimMetadata(metadata?: V1ObjectMeta): V1ObjectMeta {
-  return {
+  const trimmedMetadata = {
     name: metadata?.name,
     namespace: metadata?.namespace,
     annotations: metadata?.annotations,
@@ -34,4 +36,6 @@ export function trimMetadata(metadata?: V1ObjectMeta): V1ObjectMeta {
     resourceVersion: metadata?.resourceVersion,
     generation: metadata?.generation,
   };
+  logger.debug(trimmedMetadata, 'workload metadata state after trimming');
+  return trimmedMetadata;
 }