Additional logging when debugging directive (#4210)

* Additional logging when debugging directive

* wip

* Add docs

common/changes/@autorest/configuration/feature-directive-debug_2021-07-13-17-42.json

@@ -0,0 +1,11 @@
+{
+  "changes": [
+    {
+      "packageName": "@autorest/configuration",
+      "comment": "**Added** `debug` flag to directive to enable additional logging",
+      "type": "minor"
+    }
+  ],
+  "packageName": "@autorest/configuration",
+  "email": "tiguerin@microsoft.com"
+}

common/changes/@autorest/core/feature-directive-debug_2021-07-13-17-42.json

@@ -0,0 +1,11 @@
+{
+  "changes": [
+    {
+      "packageName": "@autorest/core",
+      "comment": "**Added** `debug` flag to directive to enable additional logging",
+      "type": "minor"
+    }
+  ],
+  "packageName": "@autorest/core",
+  "email": "tiguerin@microsoft.com"
+}

docs/generate/directives.md

@@ -33,6 +33,36 @@ Directives consist of three parts:
 
 [See built in directives here](./built-in-directives.md)
 
+## Debug a directive
+
+### `debug` flag
+
+Directive provide a `debug` field that will enable verbose logging of the directive run.
+
+Example:
+
+```yaml
+directive:
+  - from: swagger-document
+    where: $.paths
+    debug: true
+    transform: >-
+      $["x-abc"] = true
+```
+
+### `$lib.log` function
+
+Along with some other available function to the transform context(See [eval.ts](https://github.com/Azure/autorest/blob/main/packages/extensions/core/src/lib/plugins/transformer/eval.ts)) `$lib.log` lets you log.
+
+```yaml
+directive:
+  - from: swagger-document
+    where: $.paths
+    transform: >-
+      $lib.log($);
+      $["x-abc"] = true
+```
+
 ## Directive Scenarios
 
 The following directives cover the most common tweaking scenarios for generation. Most of those have a `built-in` [directive](./built-in-directives.md) helper and are shown here as examples.

packages/extensions/core/src/lib/context/autorest-context.ts

@@ -46,6 +46,10 @@ export class AutorestContext implements AutorestLogger {
     return this.config.raw;
   }
 
+  public debug(message: string) {
+    this.logger.debug(message);
+  }
+
   public verbose(message: string) {
     this.logger.verbose(message);
   }

packages/extensions/core/src/lib/context/logger.ts

@@ -19,6 +19,13 @@ export class AutorestCoreLogger {
     this.suppressor = new Suppressor(config);
   }
 
+  public debug(message: string) {
+    this.log({
+      Channel: Channel.Debug,
+      Text: message,
+    });
+  }
+
   public verbose(message: string) {
     this.log({
       Channel: Channel.Verbose,

packages/extensions/core/src/lib/plugins/transformer/manipulation.ts

@@ -8,12 +8,11 @@ import { YieldCPU } from "@azure-tools/tasks";
 import { AutorestContext } from "../../autorest-core";
 import { Channel, Message, SourceLocation } from "../../message";
 import { manipulateObject } from "./object-manipulator";
-import { values } from "@azure-tools/linq";
 import { evalDirectiveTest, evalDirectiveTransform } from "./eval";
 import { ResolvedDirective, resolveDirectives } from "@autorest/configuration";
 
 export class Manipulator {
-  private transformations: Array<ResolvedDirective>;
+  private transformations: ResolvedDirective[];
 
   public constructor(private context: AutorestContext) {
     this.transformations = resolveDirectives(
@@ -24,54 +23,73 @@ export class Manipulator {
 
   private matchesSourceFilter(document: string, transform: ResolvedDirective, artifact: string | null): boolean {
     document = "/" + document;
-    return values(transform.from).any((each) => artifact === each || document.endsWith("/" + each));
+    return transform.from.find((x) => artifact === x || document.endsWith("/" + x)) !== undefined;
   }
 
   private async processInternal(data: DataHandle, sink: DataSink, documentId?: string): Promise<DataHandle> {
     for (const directive of this.transformations) {
-      // matches filter?
-      if (this.matchesSourceFilter(documentId || data.key, directive, data.artifactType)) {
-        try {
-          for (const where of directive.where) {
-            // transform
-            for (const transformCode of directive.transform) {
-              await YieldCPU();
-              const result = await this.processDirectiveTransform(data, sink, where, transformCode);
-              data = result.result;
-            }
+      data = await this.processDirective(directive, data, sink, documentId);
+    }
 
-            // test
-            for (const testCode of directive.test) {
-              const doc = await data.ReadObject<any>();
-              const allHits = nodes(doc, where);
-              for (const hit of allHits) {
-                const testResults = evalDirectiveTest(testCode, {
-                  value: hit.value,
-                  doc: doc,
-                  path: hit.path,
-                });
+    return data;
+  }
 
-                for (const testResult of testResults) {
-                  if (testResult === false || typeof testResult !== "boolean") {
-                    const messageText = typeof testResult === "string" ? testResult : "Custom test failed";
-                    const message = (<Message>testResult).Text
-                      ? <Message>testResult
-                      : <Message>{ Text: messageText, Channel: Channel.Warning, Details: testResult };
-                    message.Source = message.Source || [<SourceLocation>{ Position: { path: hit.path } }];
-                    for (const src of message.Source) {
-                      src.document = src.document || data.key;
-                    }
-                    this.context.Message(message);
-                  }
+  private async processDirective(directive: ResolvedDirective, data: DataHandle, sink: DataSink, documentId?: string) {
+    const match = this.matchesSourceFilter(documentId || data.key, directive, data.artifactType);
+
+    if (directive.debug) {
+      const action = match ? "will" : "will not";
+      this.context.debug(
+        `Directive \`${directive.name}\` **${action}** run on document \`${data.description} (${data.artifactType})\``,
+      );
+    }
+    // matches filter?
+    if (!match) {
+      return data;
+    }
+
+    try {
+      for (const where of directive.where) {
+        // transform
+        for (const transformCode of directive.transform) {
+          await YieldCPU();
+          if (directive.debug) {
+            this.context.debug(`Running \`${where}\` transform:\n------------\n ${transformCode}\n----------------`);
+          }
+          const result = await this.processDirectiveTransform(data, sink, where, transformCode, directive.debug);
+          data = result.result;
+        }
+
+        // test
+        for (const testCode of directive.test) {
+          const doc = await data.readObject<any>();
+          const allHits = nodes(doc, where);
+          for (const hit of allHits) {
+            const testResults = evalDirectiveTest(testCode, {
+              value: hit.value,
+              doc: doc,
+              path: hit.path,
+            });
+
+            for (const testResult of testResults) {
+              if (testResult === false || typeof testResult !== "boolean") {
+                const messageText = typeof testResult === "string" ? testResult : "Custom test failed";
+                const message = (<Message>testResult).Text
+                  ? <Message>testResult
+                  : <Message>{ Text: messageText, Channel: Channel.Warning, Details: testResult };
+                message.Source = message.Source || [<SourceLocation>{ Position: { path: hit.path } }];
+                for (const src of message.Source) {
+                  src.document = src.document || data.key;
                 }
+                this.context.Message(message);
               }
             }
           }
-        } catch {
-          // TODO: Temporary comment. First I will make the modifiers for PowerShell work. It shouldn't fail with PowerShell modifiers.
-          // throw Error(`Directive given has something wrong. - ${JSON.stringify(trans['directive'], null, 2)} - It could be badly formatted or not being declared. Please check your configuration file. `);
         }
       }
+    } catch {
+      // TODO: Temporary comment. First I will make the modifiers for PowerShell work. It shouldn't fail with PowerShell modifiers.
+      // throw Error(`Directive given has something wrong. - ${JSON.stringify(trans['directive'], null, 2)} - It could be badly formatted or not being declared. Please check your configuration file. `);
     }
 
     return data;
@@ -82,6 +100,7 @@ export class Manipulator {
     sink: DataSink,
     where: string,
     transformCode: string,
+    debug: boolean,
   ): Promise<{ anyHit: boolean; result: DataHandle }> {
     return manipulateObject(
       data,
@@ -97,6 +116,7 @@ export class Manipulator {
         }),
       this.context,
       transformCode,
+      debug,
     );
   }
 

packages/extensions/core/src/lib/plugins/transformer/object-manipulator.ts

@@ -22,6 +22,7 @@ import {
 import { AutorestContext } from "../../autorest-core";
 import { Channel } from "../../message";
 import { identitySourceMapping } from "@autorest/common";
+import { inspect } from "util";
 
 export async function manipulateObject(
   src: DataHandle,
@@ -30,6 +31,7 @@ export async function manipulateObject(
   transformer: (doc: any, obj: any, path: JsonPath) => any, // transforming to `undefined` results in removal
   config?: AutorestContext,
   transformationString?: string,
+  debug?: boolean,
   mappingInfo?: {
     transformerSourceHandle: DataHandle;
     transformerSourcePosition: SmartPosition;
@@ -37,9 +39,15 @@ export async function manipulateObject(
   },
 ): Promise<{ anyHit: boolean; result: DataHandle }> {
   if (whereJsonQuery === "$") {
-    const data = await src.ReadData();
+    if (debug && config) {
+      config.debug("Query is $ runnning directive transform on raw text.");
+    }
+    const data = await src.readData();
     const newObject = transformer(null, data, []);
     if (newObject !== data) {
+      if (debug && config) {
+        config.debug("Directive transform changed text. Skipping object transform.");
+      }
       const resultHandle = await target.writeData(src.description, newObject, src.identity, src.artifactType);
       return {
         anyHit: true,
@@ -50,7 +58,7 @@ export async function manipulateObject(
 
   // find paths matched by `whereJsonQuery`
 
-  let ast: YAMLNode = CloneAst(await src.ReadYamlAst());
+  let ast: YAMLNode = CloneAst(await src.readYamlAst());
   const doc = ParseNode<any>(ast);
   const hits = nodes(doc, whereJsonQuery).sort((a, b) => a.path.length - b.path.length);
   if (hits.length === 0) {
@@ -65,9 +73,19 @@ export async function manipulateObject(
     if (ast === undefined) {
       throw new Error("Cannot remove root node.");
     }
+    if (debug && config) {
+      config.debug(
+        `Directive transform match path ${hit.path}. Running on value:\n------------\n${inspect(
+          hit.value,
+        )}\n------------`,
+      );
+    }
 
     try {
       const newObject = transformer(doc, Clone(hit.value), hit.path);
+      if (debug && config) {
+        config.debug(`Transformed Result:\n------------\n${inspect(newObject)}\n------------`);
+      }
       const newAst = newObject === undefined ? undefined : ToAst(newObject); // <- can extend ToAst to also take an "ambient" object with AST, in order to create anchor refs for existing stuff!
       const oldAst = ResolveRelativeNode(ast, ast, hit.path);
       ast =

packages/extensions/core/src/lib/plugins/transformer/transformer.ts

@@ -3,20 +3,18 @@ import { createPerFilePlugin, PipelinePlugin } from "../../pipeline/common";
 import { Manipulator } from "./manipulation";
 import { Channel } from "../../message";
 import { evalDirectiveTransform } from "./eval";
-import { resolveDirectives } from "@autorest/configuration";
 
 /* @internal */
 export function createGraphTransformerPlugin(): PipelinePlugin {
   return async (context, input, sink) => {
     // object transforms must have a where clause and a transform
-    const directives = resolveDirectives(
-      context.config,
+    const directives = context.resolveDirectives(
       (x) => x.from.length > 0 && x.transform.length > 0 && x.where.length > 0,
     ); // && (!!x.where && x.where.length > 0)
 
     const result: Array<DataHandle> = [];
-    for (const file of await input.Enum()) {
-      const inputHandle = await input.Read(file);
+    for (const file of await input.enum()) {
+      const inputHandle = await input.read(file);
       if (inputHandle) {
         const documentId = `/${inputHandle.description || inputHandle.key}`;
         let contents: AnyObject | undefined = undefined;

packages/libs/configuration/src/configuration-schema/autorest-configuration-schema.ts

@@ -18,6 +18,11 @@ export const AUTOREST_CONFIGURATION_SCHEMA = {
       "transform": { type: "string", array: true },
       "text-transform": { type: "string", array: true },
       "test": { type: "string", array: true },
+      "debug": {
+        type: "boolean",
+        description:
+          "Debug this directive. When set to true autorest will log additional information regarding that directive.",
+      },
     },
   },
   "declare-directive": {

packages/libs/configuration/src/directive.ts

@@ -16,6 +16,7 @@ export interface Directive {
   "transform"?: string[] | string;
   "text-transform"?: string[] | string;
   "test"?: string[] | string;
+  "debug"?: boolean;
 }
 
 export class ResolvedDirective {
@@ -25,6 +26,7 @@ export class ResolvedDirective {
   suppress: string[];
   transform: string[];
   test: string[];
+  debug: boolean;
 
   constructor(directive: Directive) {
     // copy untyped content over
@@ -37,6 +39,11 @@ export class ResolvedDirective {
     this.suppress = arrayOf(directive["suppress"]);
     this.transform = arrayOf(directive["transform"] || directive["text-transform"]);
     this.test = arrayOf(directive["test"]);
+    this.debug = directive.debug ?? false;
+  }
+
+  public get name() {
+    return `${this.from} @ ${this.where}`;
   }
 }