Log API requests/responses (#895)

* Log API requests/responses

* bump sdk version

Author: reberhardt7

package.json

@@ -121,7 +121,7 @@
     "@socketregistry/packageurl-js": "1.0.9",
     "@socketsecurity/config": "3.0.1",
     "@socketsecurity/registry": "1.1.17",
-    "@socketsecurity/sdk": "1.4.93",
+    "@socketsecurity/sdk": "1.4.94",
     "@types/blessed": "0.1.25",
     "@types/cmd-shim": "5.0.2",
     "@types/js-yaml": "4.0.9",

pnpm-lock.yaml

@@ -16,6 +16,7 @@ import { confirm, select } from '@socketsecurity/registry/lib/prompts'
 import { fetchSupportedScanFileNames } from './fetch-supported-scan-file-names.mts'
 import { handleCreateNewScan } from './handle-create-new-scan.mts'
 import constants from '../../constants.mts'
+import { debugApiRequest, debugApiResponse } from '../../utils/debug.mts'
 import { formatErrorWithDetail } from '../../utils/errors.mts'
 import { isReportSupportedFile } from '../../utils/glob.mts'
 import { fetchListAllRepos } from '../repository/fetch-list-all-repos.mts'
@@ -390,12 +391,20 @@ async function downloadManifestFile({
   const fileUrl = `${repoApiUrl}/contents/${file}?ref=${defaultBranch}`
   debugDir('inspect', { fileUrl })
 
-  const downloadUrlResponse = await fetch(fileUrl, {
-    method: 'GET',
-    headers: {
-      Authorization: `Bearer ${githubToken}`,
-    },
-  })
+  debugApiRequest('GET', fileUrl)
+  let downloadUrlResponse: Response
+  try {
+    downloadUrlResponse = await fetch(fileUrl, {
+      method: 'GET',
+      headers: {
+        Authorization: `Bearer ${githubToken}`,
+      },
+    })
+    debugApiResponse('GET', fileUrl, downloadUrlResponse.status)
+  } catch (e) {
+    debugApiResponse('GET', fileUrl, undefined, e)
+    throw e
+  }
   debugFn('notice', 'complete: request')
 
   const downloadUrlText = await downloadUrlResponse.text()
@@ -448,7 +457,9 @@ async function streamDownloadWithFetch(
   let response // Declare response here to access it in catch if needed
 
   try {
+    debugApiRequest('GET', downloadUrl)
     response = await fetch(downloadUrl)
+    debugApiResponse('GET', downloadUrl, response.status)
 
     if (!response.ok) {
       const errorMsg = `Download failed due to bad server response: ${response.status} ${response.statusText} for ${downloadUrl}`
@@ -483,6 +494,9 @@ async function streamDownloadWithFetch(
     // It resolves when the piping is fully complete and fileStream is closed.
     return { ok: true, data: localPath }
   } catch (e) {
+    if (!response) {
+      debugApiResponse('GET', downloadUrl, undefined, e)
+    }
     logger.fail(
       'An error was thrown while trying to download a manifest file... url:',
       downloadUrl,
@@ -542,11 +556,19 @@ async function getLastCommitDetails({
   const commitApiUrl = `${repoApiUrl}/commits?sha=${defaultBranch}&per_page=1`
   debugFn('inspect', 'url: commit', commitApiUrl)
 
-  const commitResponse = await fetch(commitApiUrl, {
-    headers: {
-      Authorization: `Bearer ${githubToken}`,
-    },
-  })
+  debugApiRequest('GET', commitApiUrl)
+  let commitResponse: Response
+  try {
+    commitResponse = await fetch(commitApiUrl, {
+      headers: {
+        Authorization: `Bearer ${githubToken}`,
+      },
+    })
+    debugApiResponse('GET', commitApiUrl, commitResponse.status)
+  } catch (e) {
+    debugApiResponse('GET', commitApiUrl, undefined, e)
+    throw e
+  }
 
   const commitText = await commitResponse.text()
   debugFn('inspect', 'response: commit', commitText)
@@ -646,12 +668,20 @@ async function getRepoDetails({
   const repoApiUrl = `${githubApiUrl}/repos/${orgGithub}/${repoSlug}`
   debugDir('inspect', { repoApiUrl })
 
-  const repoDetailsResponse = await fetch(repoApiUrl, {
-    method: 'GET',
-    headers: {
-      Authorization: `Bearer ${githubToken}`,
-    },
-  })
+  let repoDetailsResponse: Response
+  try {
+    debugApiRequest('GET', repoApiUrl)
+    repoDetailsResponse = await fetch(repoApiUrl, {
+      method: 'GET',
+      headers: {
+        Authorization: `Bearer ${githubToken}`,
+      },
+    })
+    debugApiResponse('GET', repoApiUrl, repoDetailsResponse.status)
+  } catch (e) {
+    debugApiResponse('GET', repoApiUrl, undefined, e)
+    throw e
+  }
   logger.success(`Request completed.`)
 
   const repoDetailsText = await repoDetailsResponse.text()
@@ -702,12 +732,20 @@ async function getRepoBranchTree({
   const treeApiUrl = `${repoApiUrl}/git/trees/${defaultBranch}?recursive=1`
   debugFn('inspect', 'url: tree', treeApiUrl)
 
-  const treeResponse = await fetch(treeApiUrl, {
-    method: 'GET',
-    headers: {
-      Authorization: `Bearer ${githubToken}`,
-    },
-  })
+  let treeResponse: Response
+  try {
+    debugApiRequest('GET', treeApiUrl)
+    treeResponse = await fetch(treeApiUrl, {
+      method: 'GET',
+      headers: {
+        Authorization: `Bearer ${githubToken}`,
+      },
+    })
+    debugApiResponse('GET', treeApiUrl, treeResponse.status)
+  } catch (e) {
+    debugApiResponse('GET', treeApiUrl, undefined, e)
+    throw e
+  }
 
   const treeText = await treeResponse.text()
   debugFn('inspect', 'response: tree', treeText)

src/commands/scan/create-scan-from-github.mts

@@ -1,3 +1,9 @@
+import fs from 'node:fs'
+import path from 'node:path'
+
+import { logger } from '@socketsecurity/registry/lib/logger'
+
+import constants from '../../constants.mts'
 import { handleApiCall } from '../../utils/api.mts'
 import { setupSdk } from '../../utils/sdk.mts'
 
@@ -51,6 +57,19 @@ export async function fetchCreateOrgFullScan(
   }
   const sockSdk = sockSdkCResult.data
 
+  if (constants.ENV.SOCKET_CLI_DEBUG) {
+    const fileInfo = await Promise.all(
+      packagePaths.map(async p => {
+        const absPath = path.resolve(process.cwd(), p)
+        const stat = await fs.promises.stat(absPath)
+        return { path: absPath, size: stat.size }
+      }),
+    )
+    logger.info(
+      `[DEBUG] ${new Date().toISOString()} Uploading full scan manifests: ${JSON.stringify(fileInfo)}`,
+    )
+  }
+
   return await handleApiCall(
     sockSdk.createOrgFullScan(orgSlug, packagePaths, cwd, {
       ...(branchName ? { branch: branchName } : {}),

src/commands/scan/fetch-create-org-full-scan.mts

@@ -154,6 +154,7 @@ export type ENV = Remap<
       npm_config_user_agent: string
       PATH: string
       SOCKET_CLI_ACCEPT_RISKS: boolean
+      SOCKET_CLI_DEBUG: boolean
       SOCKET_CLI_API_BASE_URL: string
       SOCKET_CLI_API_PROXY: string
       SOCKET_CLI_API_TIMEOUT: number
@@ -574,6 +575,8 @@ const LAZY_ENV = () => {
     PATH: envAsString(env['PATH']),
     // Accept risks of a Socket wrapped npm/npx run.
     SOCKET_CLI_ACCEPT_RISKS: envAsBoolean(env[SOCKET_CLI_ACCEPT_RISKS]),
+    // Enable debug logging in Socket CLI.
+    SOCKET_CLI_DEBUG: envAsBoolean(env['SOCKET_CLI_DEBUG']),
     // Change the base URL for Socket API calls.
     // https://github.com/SocketDev/socket-cli?tab=readme-ov-file#environment-variables-for-development
     SOCKET_CLI_API_BASE_URL:

src/constants.mts

@@ -26,7 +26,7 @@ import { logger } from '@socketsecurity/registry/lib/logger'
 import { isNonEmptyString } from '@socketsecurity/registry/lib/strings'
 
 import { getConfigValueOrUndef } from './config.mts'
-import { debugApiResponse } from './debug.mts'
+import { debugApiRequest, debugApiResponse } from './debug.mts'
 import constants, {
   CONFIG_KEY_API_BASE_URL,
   EMPTY_VALUE,
@@ -166,9 +166,6 @@ export async function handleApiCall<T extends SocketSdkOperations>(
     }
     if (description) {
       logger.fail(`An error was thrown while requesting ${description}`)
-      debugApiResponse(description, undefined, e)
-    } else {
-      debugApiResponse('Socket API', undefined, e)
     }
     debugDir('inspect', { socketSdkErrorResult })
     return socketSdkErrorResult
@@ -177,7 +174,7 @@ export async function handleApiCall<T extends SocketSdkOperations>(
   // Note: TS can't narrow down the type of result due to generics.
   if (sdkResult.success === false) {
     const endpoint = description || 'Socket API'
-    debugApiResponse(endpoint, sdkResult.status as number)
+    debugApiResponse('API', endpoint, sdkResult.status as number)
     debugDir('inspect', { sdkResult })
 
     const errCResult = sdkResult as SocketSdkErrorResult<T>
@@ -263,18 +260,20 @@ export async function handleApiCallNoSpinner<T extends SocketSdkOperations>(
   }
 }
 
-export async function queryApi(path: string, apiToken: string) {
+async function queryApi(path: string, apiToken: string) {
   const baseUrl = getDefaultApiBaseUrl()
   if (!baseUrl) {
     throw new Error('Socket API base URL is not configured.')
   }
 
-  return await fetch(`${baseUrl}${baseUrl.endsWith('/') ? '' : '/'}${path}`, {
+  const url = `${baseUrl}${baseUrl.endsWith('/') ? '' : '/'}${path}`
+  const result = await fetch(url, {
     method: 'GET',
     headers: {
       Authorization: `Basic ${btoa(`${apiToken}:`)}`,
     },
   })
+  return result
 }
 
 /**
@@ -299,21 +298,34 @@ export async function queryApiSafeText(
 
   if (description) {
     spinner.start(`Requesting ${description} from API...`)
+    debugApiRequest('GET', path, constants.ENV.SOCKET_CLI_API_TIMEOUT)
   }
 
   let result
+  const startTime = Date.now()
   try {
     result = await queryApi(path, apiToken)
+    const duration = Date.now() - startTime
+    debugApiResponse(
+      'GET',
+      path,
+      result.status,
+      undefined,
+      duration,
+      Object.fromEntries(result.headers.entries()),
+    )
     if (description) {
       spinner.successAndStop(
         `Received Socket API response (after requesting ${description}).`,
       )
     }
   } catch (e) {
+    const duration = Date.now() - startTime
     if (description) {
       spinner.failAndStop(
         `An error was thrown while requesting ${description}.`,
       )
+      debugApiResponse('GET', path, undefined, e, duration)
     }
 
     debugFn('error', 'Query API request failed')

src/utils/api.mts

@@ -18,25 +18,62 @@
  */
 
 import { debugDir, debugFn, isDebug } from '@socketsecurity/registry/lib/debug'
+import { logger } from '@socketsecurity/registry/lib/logger'
+
+import constants from '../constants.mts'
 
 /**
- * Debug an API response.
+ * Debug an API request start.
+ * Logs essential info without exposing sensitive data.
+ */
+export function debugApiRequest(
+  method: string,
+  endpoint: string,
+  timeout?: number | undefined,
+): void {
+  if (constants.ENV.SOCKET_CLI_DEBUG) {
+    const timeoutStr = timeout !== undefined ? ` (timeout: ${timeout}ms)` : ''
+    logger.info(
+      `[DEBUG] ${new Date().toISOString()} request started: ${method} ${endpoint}${timeoutStr}`,
+    )
+  }
+}
+
+/**
+ * Debug an API response end.
  * Logs essential info without exposing sensitive data.
  */
 export function debugApiResponse(
+  method: string,
   endpoint: string,
   status?: number | undefined,
   error?: unknown | undefined,
+  duration?: number | undefined,
+  headers?: Record<string, string> | undefined,
 ): void {
+  if (!constants.ENV.SOCKET_CLI_DEBUG) {
+    return
+  }
+
   if (error) {
-    debugDir('error', {
-      endpoint,
-      error: error instanceof Error ? error.message : 'Unknown error',
-    })
-  } else if (status && status >= 400) {
-    debugFn('warn', `API ${endpoint}: HTTP ${status}`)
-  } else if (isDebug('notice')) {
-    debugFn('notice', `API ${endpoint}: ${status || 'pending'}`)
+    logger.fail(
+      `[DEBUG] ${new Date().toISOString()} request error: ${method} ${endpoint} - ${error instanceof Error ? error.message : 'Unknown error'}${duration !== undefined ? ` (${duration}ms)` : ''}`,
+    )
+    if (headers) {
+      logger.info(
+        `[DEBUG] response headers: ${JSON.stringify(headers, null, 2)}`,
+      )
+    }
+  } else {
+    const durationStr = duration !== undefined ? ` (${duration}ms)` : ''
+    logger.info(
+      `[DEBUG] ${new Date().toISOString()} request ended: ${method} ${endpoint}: HTTP ${status}${durationStr}`,
+    )
+    if (headers && status && status >= 400) {
+      logger.info(
+        `[DEBUG] response headers: ${JSON.stringify(headers, null, 2)}`,
+      )
+    }
   }
 }