feat: add debugging output for init script (#71)

lib/index.ts

@@ -5,6 +5,10 @@ import * as subProcess from './sub-process';
 import * as tmp from 'tmp';
 import {MissingSubProjectError} from './errors';
 import chalk from 'chalk';
+import debugModule = require('debug');
+
+// To enable debugging output, run the CLI as `DEBUG=snyk-gradle-plugin snyk ...`
+const debugLogging = debugModule('snyk-gradle-plugin');
 
 const packageFormatVersion = 'mvn:0.0.1';
 
@@ -236,6 +240,15 @@ async function getAllDepsAllProjects(root, targetFile, options): Promise<DepRoot
   });
 }
 
+const reEcho = /^SNYKECHO (.*)$/;
+
+async function printIfEcho(line: string) {
+  const maybeMatch = reEcho.exec(line);
+  if (maybeMatch) {
+    debugLogging(maybeMatch[1]);
+  }
+}
+
 async function getAllDeps(root, targetFile, options: SingleRootInspectOptions | MultiRootsInspectOptions):
     Promise<JsonDepsScriptResult> {
   const args = buildArgs(root, targetFile, options.args);
@@ -291,7 +304,7 @@ async function getAllDeps(root, targetFile, options: SingleRootInspectOptions |
 
   const command = getCommand(root, targetFile);
   try {
-    const stdoutText = await subProcess.execute(command, args, {cwd: root});
+    const stdoutText = await subProcess.execute(command, args, {cwd: root}, printIfEcho);
     if (tmpInitGradle !== null) {
       tmpInitGradle.removeCallback();
     }

lib/init.gradle

@@ -14,9 +14,11 @@ import groovy.json.JsonOutput
 // (-q to have clean output, -P supplies args as per https://stackoverflow.com/a/48370451)
 
 // Output format:
+//
 // Since Gradle is chatty and often prints a "Welcome" banner even with -q option,
-// the only output line that matters is prefixed with "JSONDEPS " and is a JSON representation
-// of the dependencies trees for all projects in the following format
+// the only output lines that matter are:
+// - prefixed "SNYKECHO ": should be immediately printed as debug information by the caller
+// - prefixed "JSONDEPS ": JSON representation of the dependencies trees for all projects in the following format
 
 // interface JsonDepsScriptResult {
 //   defaultProject: string;
@@ -50,6 +52,7 @@ allprojects { everyProj ->
         def onlyConf = project.hasProperty('configuration') ? configuration : null
 
         // currentChain is a protection against dependency cycles, which are perfectly normal in Java/Gradle world
+        // This function converts a Gradle dependency tree into DepTree structure used by Snyk CLI
         def depsToDict
         depsToDict = { Iterable deps, Set currentChain ->
             def res = [:]
@@ -70,14 +73,15 @@ allprojects { everyProj ->
         }
 
         doLast { task ->
-            def projectsDict = [:]
-            def defaultProjectName = task.project.name
-            def result = [
-                'defaultProject': defaultProjectName,
-                'projects': projectsDict,
-                'allSubProjectNames': allprojects.collect { it.name }
-            ]
             if (!snykMergedDepsConfExecuted) {
+                println('SNYKECHO snykResolvedDepsJson task is executing via doLast')
+                def projectsDict = [:]
+                def defaultProjectName = task.project.name
+                def result = [
+                    'defaultProject': defaultProjectName,
+                    'projects': projectsDict,
+                    'allSubProjectNames': allprojects.collect { it.name }
+                ]
 
                 def shouldScanProject = {
                     onlyProj == null ||
@@ -86,6 +90,7 @@ allprojects { everyProj ->
                 }
 
                 allprojects.findAll(shouldScanProject).each { proj ->
+                    println('SNYKECHO processing project: ' + proj.name)
                     def snykConf = null
                     if (proj.configurations.size() > 0) {
                         if (onlyConf != null) {
@@ -101,16 +106,20 @@ allprojects { everyProj ->
                             // We create a new, "merged" configuration here. It has no attributes, which might be
                             // a problem for Android builds, where a resolution of a dependency "variant"
                             // is often dependent on configuration attributes (such as BuildType or Usage).
+                            println('SNYKECHO constructing merged configuration')
                             snykConf = proj.configurations.create('snykMergedDepsConf')
                             proj.configurations
                                 .findAll({ it.name != 'snykMergedDepsConf' && (onlyConf == null || it.name == onlyConf) })
                                 .each { snykConf.extendsFrom(it) }
                         }
                     }
                     if (snykConf != null) {
+                        println('SNYKECHO resolving configuration ' + snykConf.name)
+                        def gradleDeps = snykConf.resolvedConfiguration.firstLevelModuleDependencies
+                        println('SNYKECHO converting the dependency graph to the DepTree format')
                         projectsDict[proj.name] = [
                             'targetFile': findProject(proj.path).buildFile.toString(),
-                            'depDict': depsToDict(snykConf.resolvedConfiguration.firstLevelModuleDependencies, new HashSet())
+                            'depDict': depsToDict(gradleDeps, new HashSet())
                         ]
                     } else {
                         projectsDict[proj.name] = [

lib/sub-process.ts

@@ -1,6 +1,15 @@
 import * as childProcess from 'child_process';
+import debugModule = require('debug');
 
-export function execute(command: string, args: string[], options: {cwd?: string}): Promise<string> {
+const debugLogging = debugModule('snyk-gradle-plugin');
+
+// Executes a subprocess. Resolves successfully with stdout contents if the exit code is 0.
+export function execute(
+  command: string,
+  args: string[],
+  options: {cwd?: string},
+  perLineCallback?: (s: string) => Promise<void>,
+): Promise<string> {
   const spawnOptions: childProcess.SpawnOptions = {shell: true};
   if (options && options.cwd) {
     spawnOptions.cwd = options.cwd;
@@ -11,10 +20,14 @@ export function execute(command: string, args: string[], options: {cwd?: string}
     let stderr = '';
 
     const proc = childProcess.spawn(command, args, spawnOptions);
-    proc.stdout.on('data', (data) => {
-      stdout = stdout + data;
+    proc.stdout.on('data', (data: Buffer) => {
+      const strData = data.toString();
+      stdout = stdout + strData;
+      if (perLineCallback) {
+        strData.split('\n').forEach(perLineCallback);
+      }
     });
-    proc.stderr.on('data', (data) => {
+    proc.stderr.on('data', (data: Buffer) => {
       stderr = stderr + data;
     });
 
@@ -30,7 +43,11 @@ ${stdout}
 ${stderr}
 `));
       }
-      resolve(stdout || stderr);
+      if (stderr) {
+        debugLogging('subprocess exit code = 0, but stderr was not empty: ' + stderr);
+      }
+
+      resolve(stdout);
     });
   });
 }

package.json

@@ -35,8 +35,10 @@
     "typescript": "^3.4.5"
   },
   "dependencies": {
+    "@types/debug": "^4.1.4",
     "chalk": "^2.4.2",
     "clone-deep": "^0.3.0",
+    "debug": "^4.1.1",
     "tmp": "0.0.33",
     "tslib": "^1.9.3"
   }