add ability to enable debug logging (#2120)

* add new environment flag

* basic plumbing for debug logging

* add some real logging for config

* simplify interface, add more logging, support testing

* add doco

* add more logging around configuration

* simplify type

README.md

@@ -99,6 +99,7 @@ The following documentation is for `main`, which might contain some unreleased f
   * [Timeouts](./docs/support_files/timeouts.md)
   * [World](./docs/support_files/world.md)
 * Guides
+  * [Debugging](./docs/debugging.md)
   * [Dry run](./docs/dry_run.md)
   * [ES Modules](./docs/esm.md)
   * [Failing fast](./docs/fail_fast.md)

docs/debugging.md

@@ -0,0 +1,9 @@
+# Debugging
+
+If things aren't working the way you expect with Cucumber, you can enable debug logging. When this is enabled, Cucumber will emit logging to `stderr` relating to configuration and other things that can help you pin down a problem with your project.
+
+Cucumber uses the [popular `debug` library](https://www.npmjs.com/package/debug) to detect when debug logging should be enabled, under the `cucumber` scope. To enable debug logging, set the `DEBUG` environment variable, like:
+
+```shell
+DEBUG=cucumber
+```

features/debug.feature

@@ -0,0 +1,37 @@
+@spawn
+Feature: debug
+
+  As a Cucumber user
+  I want to enable debug logging
+  So that I can troubleshoot issues with my project
+
+  Background:
+    Given a file named "features/a.feature" with:
+      """
+      Feature: some feature
+        Scenario:
+          Given a step passes
+          When a step passes
+          Then a step passes
+      """
+    And a file named "features/step_definitions/cucumber_steps.js" with:
+      """
+      const {Given} = require('@cucumber/cucumber')
+
+      Given(/^a step passes$/, function() {});
+      """
+
+  Scenario:
+    Given my env includes "DEBUG=cucumber"
+    When I run cucumber-js
+    Then the error output contains the text:
+    """
+    No configuration file found
+    """
+
+  Scenario:
+    When I run cucumber-js
+    Then the error output does not contain the text:
+    """
+    No configuration file found
+    """

package.json

@@ -210,6 +210,7 @@
     "chalk": "^4.1.2",
     "cli-table3": "0.6.2",
     "commander": "^9.0.0",
+    "debug": "^4.3.4",
     "duration": "^0.2.2",
     "durations": "^3.4.2",
     "figures": "^3.2.0",
@@ -241,6 +242,7 @@
     "@microsoft/api-extractor": "7.29.5",
     "@sinonjs/fake-timers": "9.1.2",
     "@types/chai": "4.3.3",
+    "@types/debug": "^4.1.7",
     "@types/dirty-chai": "2.0.2",
     "@types/express": "4.17.13",
     "@types/fs-extra": "9.0.13",

src/api/console_logger.ts

@@ -0,0 +1,22 @@
+import { Console } from 'console'
+import { Writable } from 'stream'
+import { ILogger } from '../logger'
+
+export class ConsoleLogger implements ILogger {
+  private console: Console = new Console(this.stream)
+  constructor(private stream: Writable, private debugEnabled: boolean) {}
+
+  debug(...content: any[]): void {
+    if (this.debugEnabled) {
+      this.console.debug(...content)
+    }
+  }
+
+  error(...content: any[]): void {
+    this.console.error(...content)
+  }
+
+  warn(...content: any[]): void {
+    this.console.warn(...content)
+  }
+}

src/api/environment.ts

@@ -10,6 +10,7 @@ export function mergeEnvironment(
       stdout: process.stdout,
       stderr: process.stderr,
       env: process.env,
+      debug: false,
     },
     provided
   )

src/api/formatters.ts

@@ -8,6 +8,7 @@ import FormatterBuilder from '../formatter/builder'
 import fs from 'mz/fs'
 import path from 'path'
 import { IRunOptionsFormats } from './types'
+import { ILogger } from '../logger'
 
 export async function initializeFormatters({
   env,
@@ -24,7 +25,7 @@ export async function initializeFormatters({
   cwd: string
   stdout: IFormatterStream
   stderr: IFormatterStream
-  logger: Console
+  logger: ILogger
   onStreamError: () => void
   eventBroadcaster: EventEmitter
   eventDataCollector: EventDataCollector

src/api/gherkin.ts

@@ -14,6 +14,7 @@ import { Query as GherkinQuery } from '@cucumber/gherkin-utils'
 import PickleFilter from '../pickle_filter'
 import { orderPickles } from '../cli/helpers'
 import { ISourcesCoordinates } from './types'
+import { ILogger } from '../logger'
 
 interface PickleWithDocument {
   gherkinDocument: GherkinDocument
@@ -32,7 +33,7 @@ export async function getFilteredPicklesAndErrors({
 }: {
   newId: IdGenerator.NewId
   cwd: string
-  logger: Console
+  logger: ILogger
   unexpandedFeaturePaths: string[]
   featurePaths: string[]
   coordinates: ISourcesCoordinates

src/api/load_configuration.ts

@@ -12,6 +12,8 @@ import {
 import { validateConfiguration } from '../configuration/validate_configuration'
 import { convertConfiguration } from './convert_configuration'
 import { mergeEnvironment } from './environment'
+import { ILogger } from '../logger'
+import { ConsoleLogger } from './console_logger'
 
 /**
  * Load user-authored configuration to be used in a test run.
@@ -24,16 +26,23 @@ export async function loadConfiguration(
   options: ILoadConfigurationOptions = {},
   environment: IRunEnvironment = {}
 ): Promise<IResolvedConfiguration> {
-  const { cwd, env } = mergeEnvironment(environment)
+  const { cwd, stderr, env, debug } = mergeEnvironment(environment)
+  const logger: ILogger = new ConsoleLogger(stderr, debug)
   const configFile = options.file ?? locateFile(cwd)
+  if (configFile) {
+    logger.debug(`Configuration will be loaded from "${configFile}"`)
+  } else {
+    logger.debug('No configuration file found')
+  }
   const profileConfiguration = configFile
-    ? await fromFile(cwd, configFile, options.profiles)
+    ? await fromFile(logger, cwd, configFile, options.profiles)
     : {}
   const original = mergeConfigurations(
     DEFAULT_CONFIGURATION,
     profileConfiguration,
     options.provided
   )
+  logger.debug('Resolved configuration:', original)
   validateConfiguration(original)
   const runnable = await convertConfiguration(original, env)
   return {

src/api/load_sources.ts

@@ -7,9 +7,10 @@ import {
 } from './types'
 import { resolvePaths } from './paths'
 import { IdGenerator } from '@cucumber/messages'
-import { Console } from 'console'
 import { mergeEnvironment } from './environment'
 import { getFilteredPicklesAndErrors } from './gherkin'
+import { ConsoleLogger } from './console_logger'
+import { ILogger } from '../logger'
 
 /**
  * Load and parse features, produce a filtered and ordered test plan and/or parse errors.
@@ -22,10 +23,11 @@ export async function loadSources(
   coordinates: ISourcesCoordinates,
   environment: IRunEnvironment = {}
 ): Promise<ILoadSourcesResult> {
-  const { cwd, stderr } = mergeEnvironment(environment)
-  const logger = new Console(stderr)
+  const { cwd, stderr, debug } = mergeEnvironment(environment)
+  const logger: ILogger = new ConsoleLogger(stderr, debug)
   const newId = IdGenerator.uuid()
   const { unexpandedFeaturePaths, featurePaths } = await resolvePaths(
+    logger,
     cwd,
     coordinates
   )

src/api/load_support.ts

@@ -4,6 +4,8 @@ import { resolvePaths } from './paths'
 import { getSupportCodeLibrary } from './support'
 import { mergeEnvironment } from './environment'
 import { ISupportCodeLibrary } from '../support_code_library_builder/types'
+import { ILogger } from '../logger'
+import { ConsoleLogger } from './console_logger'
 
 /**
  * Load support code for use in test runs.
@@ -16,9 +18,11 @@ export async function loadSupport(
   options: ILoadSupportOptions,
   environment: IRunEnvironment = {}
 ): Promise<ISupportCodeLibrary> {
-  const { cwd } = mergeEnvironment(environment)
+  const { cwd, stderr, debug } = mergeEnvironment(environment)
+  const logger: ILogger = new ConsoleLogger(stderr, debug)
   const newId = IdGenerator.uuid()
   const { requirePaths, importPaths } = await resolvePaths(
+    logger,
     cwd,
     options.sources,
     options.support

src/api/paths.ts

@@ -3,8 +3,10 @@ import glob from 'glob'
 import path from 'path'
 import fs from 'mz/fs'
 import { ISourcesCoordinates, ISupportCodeCoordinates } from './types'
+import { ILogger } from '../logger'
 
 export async function resolvePaths(
+  logger: ILogger,
   cwd: string,
   sources: Pick<ISourcesCoordinates, 'paths'>,
   support: ISupportCodeCoordinates = {
@@ -26,12 +28,21 @@ export async function resolvePaths(
     cwd,
     unexpandedFeaturePaths
   )
+  logger.debug('Found feature files based on configuration:', featurePaths)
   const { requirePaths, importPaths } = await deriveSupportPaths(
     cwd,
     featurePaths,
     support.requirePaths,
     support.importPaths
   )
+  logger.debug(
+    'Found support files to load via `require` based on configuration:',
+    requirePaths
+  )
+  logger.debug(
+    'Found support files to load via `import` based on configuration:',
+    importPaths
+  )
   return {
     unexpandedFeaturePaths,
     featurePaths,