From 26e23b2c7d46159c8849e6c6ff97792bd07472e2 Mon Sep 17 00:00:00 2001
From: Adam Harvey <adam.harvey@dxc.com>
Date: Thu, 4 Mar 2021 14:23:01 -0500
Subject: [PATCH] Refactor logging

Signed-off-by: Adam Harvey <adam.harvey@dxc.com>
---
 .../src/DocsBuilder/builder.ts                | 51 ++++++++++++-------
 1 file changed, 34 insertions(+), 17 deletions(-)

diff --git a/plugins/techdocs-backend/src/DocsBuilder/builder.ts b/plugins/techdocs-backend/src/DocsBuilder/builder.ts
index 51f4d212ba..38cc7ca562 100644
--- a/plugins/techdocs-backend/src/DocsBuilder/builder.ts
+++ b/plugins/techdocs-backend/src/DocsBuilder/builder.ts
@@ -14,7 +14,7 @@
  * limitations under the License.
  */
 import { NotModifiedError } from '@backstage/backend-common';
-import { Entity } from '@backstage/catalog-model';
+import { Entity, serializeEntityRef } from '@backstage/catalog-model';
 import {
   GeneratorBase,
   GeneratorBuilder,
@@ -31,12 +31,6 @@ import path from 'path';
 import { Logger } from 'winston';
 import { BuildMetadataStorage } from '.';
 
-const getEntityId = (entity: Entity) => {
-  return `${entity.kind}:${entity.metadata.namespace ?? ''}:${
-    entity.metadata.name
-  }`;
-};
-
 type DocsBuilderArguments = {
   preparers: PreparerBuilder;
   generators: GeneratorBuilder;
@@ -78,9 +72,15 @@ export class DocsBuilder {
     }
 
     /**
-     * Prepare and cache check
+     * Prepare (and cache check)
      */
 
+    this.logger.info(
+      `Step 1 of 3: Preparing docs for entity ${serializeEntityRef(
+        this.entity,
+      )}`,
+    );
+
     // Use the in-memory storage for setting and getting etag for this entity.
     const buildMetadataStorage = new BuildMetadataStorage(
       this.entity.metadata.uid,
@@ -92,6 +92,7 @@ export class DocsBuilder {
     // make sure to limit checking for cache invalidation to once per minute or so.
     let preparedDir: string;
     let etag: string;
+
     try {
       const preparerResponse = await this.preparer.prepare(this.entity, {
         etag: buildMetadataStorage.getEtag(),
@@ -102,21 +103,32 @@ export class DocsBuilder {
     } catch (err) {
       if (err instanceof NotModifiedError) {
         // No need to prepare anymore since cache is valid.
+        this.logger.debug(
+          `Docs for ${serializeEntityRef(
+            this.entity,
+          )} are unmodified. Using cache, skipping generate and prepare`,
+        );
         return;
       }
       throw new Error(err.message);
     }
 
     this.logger.info(
-      `TechDocs prepare step completed for entity ${getEntityId(this.entity)}.`,
+      `Prepare step completed for entity ${serializeEntityRef(
+        this.entity,
+      )}, stored at ${preparedDir}`,
     );
-    this.logger.debug(`Prepared files temporarily stored at ${preparedDir}`);
 
     /**
      * Generate
      */
 
-    this.logger.info(`Running generator on entity ${getEntityId(this.entity)}`);
+    this.logger.info(
+      `Step 2 of 3: Generating docs for entity ${serializeEntityRef(
+        this.entity,
+      )}`,
+    );
+
     // Create a temporary directory to store the generated files in.
     const tmpdirPath = os.tmpdir();
     // Fixes a problem with macOS returning a path that is a symlink
@@ -133,13 +145,12 @@ export class DocsBuilder {
       etag,
     });
 
-    this.logger.debug(`Generated files temporarily stored at ${outputDir}`);
     // Remove Prepared directory since it is no longer needed.
     // Caveat: Can not remove prepared directory in case of git preparer since the
     // local git repository is used to get etag on subsequent requests.
     if (this.preparer instanceof UrlPreparer) {
       this.logger.debug(
-        `Removing prepared directory ${preparedDir} since the site has been generated.`,
+        `Removing prepared directory ${preparedDir} since the site has been generated`,
       );
       try {
         // Not a blocker hence no need to await this.
@@ -153,17 +164,23 @@ export class DocsBuilder {
      * Publish
      */
 
-    this.logger.info(`Running publisher on entity ${getEntityId(this.entity)}`);
+    this.logger.info(
+      `Step 3 of 3: Publishing docs for entity ${serializeEntityRef(
+        this.entity,
+      )}`,
+    );
+
     await this.publisher.publish({
       entity: this.entity,
       directory: outputDir,
     });
-    this.logger.debug(
-      `Removing generated directory ${outputDir} since the site has been published`,
-    );
+
     try {
       // Not a blocker hence no need to await this.
       fs.remove(outputDir);
+      this.logger.debug(
+        `Removing generated directory ${outputDir} since the site has been published`,
+      );
     } catch (error) {
       this.logger.debug(`Error removing generated directory ${error.message}`);
     }