add debug logs with performance measurements

packages/cli/src/bin.ts

@@ -44,6 +44,8 @@ import { printUpdateMessage } from './utils/printUpdateMessage'
 import { Validate } from './Validate'
 import { Version } from './Version'
 
+const debug = Debug('prisma:cli:bin')
+
 // eslint-disable-next-line @typescript-eslint/no-var-requires, @typescript-eslint/no-unsafe-assignment
 const packageJson = require('../package.json')
 
@@ -152,8 +154,13 @@ async function main(): Promise<number> {
     ['version', 'init', 'migrate', 'db', 'introspect', 'studio', 'generate', 'validate', 'format', 'telemetry'],
   )
 
+  const startCliExec = performance.now()
   // Execute the command
   const result = await cli.parse(commandArray)
+  const endCliExec = performance.now()
+  const cliExecElapsedTime = endCliExec - startCliExec
+  debug(`Execution time for executing "await cli.parse(commandArray)": ${cliExecElapsedTime} ms`)
+
   // Did it error?
   if (result instanceof HelpError) {
     console.error(result.message)

packages/cli/src/utils/checkpoint.ts

@@ -27,12 +27,16 @@ export async function runCheckpointClientCheck({
   telemetryInformation: string
   schemaPath?: string
 }): Promise<Check.Result | 0> {
+  // If the user has disabled telemetry, we can stop here already.
   if (process.env['CHECKPOINT_DISABLE']) {
     // TODO: this breaks checkpoint-client abstraction, ideally it would export a reusable isGloballyDisabled() function
-    debug('runCheckpointClientCheck() disabled by env var')
+    debug('runCheckpointClientCheck() is disabled by the CHECKPOINT_DISABLE env var.')
     return 0
   }
+
   try {
+    const startGetInfo = performance.now()
+    // Get some info about the project
     const [projectPathHash, { schemaProvider, schemaPreviewFeatures, schemaGeneratorsProviders }] = await Promise.all([
       // SHA256 identifier for the project based on the Prisma schema path
       getProjectHash(),
@@ -42,6 +46,10 @@ export async function runCheckpointClientCheck({
     // SHA256 of the cli path
     const cliPathHash = getCLIPathHash()
 
+    const endGetInfo = performance.now()
+    const getInfoElapsedTime = endGetInfo - startGetInfo
+    debug(`runCheckpointClientCheck(): Execution time for getting info: ${getInfoElapsedTime} ms`)
+
     const data: Check.Input = {
       // Name of the product
       product: 'prisma',
@@ -70,8 +78,14 @@ export async function runCheckpointClientCheck({
       cli_path: process.argv[1],
     }
 
+    const startCheckpoint = performance.now()
     // Call Checkpoint Client and return result
-    return await checkpoint.check(data)
+    const checkpointResult = await checkpoint.check(data)
+    const endCheckpoint = performance.now()
+    const checkpointElapsedTime = endCheckpoint - startCheckpoint
+    debug(`runCheckpointClientCheck(): Execution time for "await checkpoint.check(data)": ${checkpointElapsedTime} ms`)
+
+    return checkpointResult
   } catch (e) {
     debug('Error from runCheckpointClientCheck()')
     debug(e)