Move the logging one level up to send all logs and exceptions to the user

With this change, only failed builds are logged to the backend logger

Signed-off-by: Dominik Henneke <dominik.henneke@sda-se.com>

.changeset/techdocs-new-candles-sell.md

@@ -2,5 +2,5 @@
 '@backstage/techdocs-common': patch
 ---
 
-Provide an optional `logStream: Writable` argument to the `GeneratorBase#run(...)` command.
-The stream receives all log messages that are emitted during the generator run.
+Provide optional `logger: Logger` and `logStream: Writable` arguments to the `GeneratorBase#run(...)` command.
+They receive all log messages that are emitted during the generator run.

packages/techdocs-common/api-report.md

@@ -53,6 +53,7 @@ export type GeneratorRunOptions = {
     outputDir: string;
     parsedLocationAnnotation?: ParsedLocationAnnotation;
     etag?: string;
+    logger: Logger;
     logStream?: Writable;
 };
 
@@ -167,7 +168,7 @@ export class TechdocsGenerator implements GeneratorBase {
         config: Config;
     });
     // (undocumented)
-    run({ inputDir, outputDir, parsedLocationAnnotation, etag, logStream: callerLogStream, }: GeneratorRunOptions): Promise<void>;
+    run({ inputDir, outputDir, parsedLocationAnnotation, etag, logger: childLogger, logStream, }: GeneratorRunOptions): Promise<void>;
 }
 
 // @public

packages/techdocs-common/src/stages/generate/techdocs.ts

@@ -17,8 +17,6 @@
 import { ContainerRunner } from '@backstage/backend-common';
 import { Config } from '@backstage/config';
 import path from 'path';
-import { PassThrough } from 'stream';
-import * as winston from 'winston';
 import { Logger } from 'winston';
 import {
   addBuildTimestampMetadata,
@@ -36,18 +34,6 @@ type TechdocsGeneratorOptions = {
   runGeneratorIn: string;
 };
 
-const createStream = (): [string[], PassThrough] => {
-  const log = [] as Array<string>;
-
-  const stream = new PassThrough();
-  stream.on('data', chunk => {
-    const textValue = chunk.toString().trim();
-    if (textValue?.length > 1) log.push(textValue);
-  });
-
-  return [log, stream];
-};
-
 export class TechdocsGenerator implements GeneratorBase {
   private readonly logger: Logger;
   private readonly containerRunner: ContainerRunner;
@@ -75,25 +61,9 @@ export class TechdocsGenerator implements GeneratorBase {
     outputDir,
     parsedLocationAnnotation,
     etag,
-    logStream: callerLogStream,
+    logger: childLogger,
+    logStream,
   }: GeneratorRunOptions): Promise<void> {
-    // create a copy of the logger. we want to keep all settings but want to add a new logger target.
-    // without the copy, we would add the target to the original (parent) logger.
-    const childLogger = winston.createLogger(this.logger);
-
-    const [log, logStream] = createStream();
-
-    // Forward the logs to the caller
-    if (callerLogStream) {
-      childLogger.add(
-        new winston.transports.Stream({ stream: callerLogStream }),
-      );
-      // don't use logStream.pipe(callerLogStream) because it would block others to write to callerLogStream
-      logStream.on('data', data => {
-        callerLogStream.write(data);
-      });
-    }
-
     // TODO: In future mkdocs.yml can be mkdocs.yaml. So, use a config variable here to find out
     // the correct file name.
     // Do some updates to mkdocs.yml before generating docs e.g. adding repo_url
@@ -153,7 +123,6 @@ export class TechdocsGenerator implements GeneratorBase {
       this.logger.debug(
         `Failed to generate docs from ${inputDir} into ${outputDir}`,
       );
-      childLogger.error(`Build failed with error: ${log}`);
       throw new Error(
         `Failed to generate docs from ${inputDir} into ${outputDir} with error ${error.message}`,
       );

packages/techdocs-common/src/stages/generate/types.ts

@@ -13,8 +13,10 @@
  * See the License for the specific language governing permissions and
  * limitations under the License.
  */
+
 import { Entity } from '@backstage/catalog-model';
 import { Writable } from 'stream';
+import { Logger } from 'winston';
 import { ParsedLocationAnnotation } from '../../helpers';
 
 /**
@@ -24,13 +26,15 @@ import { ParsedLocationAnnotation } from '../../helpers';
  * @param {string} outputDir Directory to store generated docs in. Usually - a newly created temporary directory.
  * @param {ParsedLocationAnnotation} parsedLocationAnnotation backstage.io/techdocs-ref annotation of an entity
  * @param {string} etag A unique identifier for the prepared tree e.g. commit SHA. If provided it will be stored in techdocs_metadata.json.
- * @param {Writable} [logStream] A dedicated log stream
+ * @param {Logger} [logger] A logger that forwards the messages to the caller to be displayed outside of the backend.
+ * @param {Writable} [logStream] A log stream that can send raw log messages to the caller to be displayed outside of the backend..
  */
 export type GeneratorRunOptions = {
   inputDir: string;
   outputDir: string;
   parsedLocationAnnotation?: ParsedLocationAnnotation;
   etag?: string;
+  logger: Logger;
   logStream?: Writable;
 };
 

plugins/techdocs-backend/src/DocsBuilder/builder.ts

@@ -120,6 +120,7 @@ export class DocsBuilder {
     try {
       const preparerResponse = await this.preparer.prepare(this.entity, {
         etag: storedEtag,
+        logger: this.logger,
       });
 
       preparedDir = preparerResponse.preparedDir;
@@ -171,6 +172,7 @@ export class DocsBuilder {
       outputDir,
       parsedLocationAnnotation,
       etag: newEtag,
+      logger: this.logger,
       logStream: this.logStream,
     });
 

plugins/techdocs-backend/src/service/DocsSynchronizer.test.ts

@@ -230,6 +230,47 @@ describe('DocsSynchronizer', () => {
       expect(DocsBuilder.prototype.build).toBeCalledTimes(0);
     });
 
+    it('should forward build errors', async () => {
+      (shouldCheckForUpdate as jest.Mock).mockReturnValue(true);
+      MockedConfigReader.prototype.getString.mockReturnValue('local');
+
+      const entity = {
+        apiVersion: 'backstage.io/v1alpha1',
+        kind: 'Component',
+        metadata: {
+          uid: '0',
+          name: 'test',
+          namespace: 'default',
+          annotations: {
+            'sda.se/release-notes-location':
+              'github-releases:https://github.com/backstage/backstage',
+          },
+        },
+      };
+
+      catalogClient.getEntityByName.mockResolvedValue(entity);
+
+      const error = new Error('Some random error');
+      MockedDocsBuilder.prototype.build.mockRejectedValue(error);
+
+      await docsSynchronizer.doSync(() => mockResponseHandler, {
+        kind: 'Component',
+        namespace: 'default',
+        name: 'test',
+        token: undefined,
+      });
+
+      expect(mockResponseHandler.log).toBeCalledTimes(1);
+      expect(mockResponseHandler.log).toBeCalledWith(
+        expect.stringMatching(
+          /error.*: Failed to build the docs page: Some random error/,
+        ),
+      );
+      expect(mockResponseHandler.finish).toBeCalledTimes(0);
+      expect(mockResponseHandler.error).toBeCalledTimes(1);
+      expect(mockResponseHandler.error).toBeCalledWith(error);
+    });
+
     it('rejects when entity is not found', async () => {
       catalogClient.getEntityByName.mockResolvedValue(undefined);
 

plugins/techdocs-backend/src/service/DocsSynchronizer.ts

@@ -23,7 +23,7 @@ import {
   PublisherBase,
 } from '@backstage/techdocs-common';
 import { PassThrough } from 'stream';
-import { Logger } from 'winston';
+import * as winston from 'winston';
 import { DocsBuilder, shouldCheckForUpdate } from '../DocsBuilder';
 
 export type DocsSynchronizerSyncOpts = {
@@ -36,7 +36,7 @@ export class DocsSynchronizer {
   private readonly preparers: PreparerBuilder;
   private readonly generators: GeneratorBuilder;
   private readonly publisher: PublisherBase;
-  private readonly logger: Logger;
+  private readonly logger: winston.Logger;
   private readonly config: Config;
   private readonly catalogClient: CatalogApi;
 
@@ -51,7 +51,7 @@ export class DocsSynchronizer {
     preparers: PreparerBuilder;
     generators: GeneratorBuilder;
     publisher: PublisherBase;
-    logger: Logger;
+    logger: winston.Logger;
     config: Config;
     catalogClient: CatalogApi;
   }) {
@@ -88,12 +88,26 @@ export class DocsSynchronizer {
 
     // open the event-stream
     const { log, error, finish } = initResponseHandler();
+
+    // create a new logger to log data to the caller
+    const taskLogger = winston.createLogger({
+      level: process.env.LOG_LEVEL || 'info',
+      format: winston.format.combine(
+        winston.format.colorize(),
+        winston.format.timestamp(),
+        winston.format.simple(),
+      ),
+      defaultMeta: {},
+    });
+
     // create an in-memory stream to forward logs to the event-stream
     const logStream = new PassThrough();
     logStream.on('data', async data => {
       log(data.toString().trim());
     });
 
+    taskLogger.add(new winston.transports.Stream({ stream: logStream }));
+
     // check if the last update check was too recent
     if (!shouldCheckForUpdate(entity.metadata.uid)) {
       finish({ updated: false });
@@ -112,7 +126,7 @@ export class DocsSynchronizer {
       preparers: this.preparers,
       generators: this.generators,
       publisher: this.publisher,
-      logger: this.logger,
+      logger: taskLogger,
       entity,
       config: this.config,
       logStream,
@@ -120,10 +134,18 @@ export class DocsSynchronizer {
 
     let foundDocs = false;
 
-    const updated = await docsBuilder.build();
+    try {
+      const updated = await docsBuilder.build();
 
-    if (!updated) {
-      finish({ updated: false });
+      if (!updated) {
+        finish({ updated: false });
+        return;
+      }
+    } catch (e) {
+      const msg = `Failed to build the docs page: ${e.message}`;
+      taskLogger.error(msg);
+      this.logger.error(msg, e);
+      error(e);
       return;
     }