Added more logging + increased delay after creating a fresh branch

src/gitlab.ts

@@ -118,9 +118,13 @@ export const runCommandInGitlabPipeline = async (ctx: Context, task: Task): Prom
   */
   let wasBranchRegistered = false;
   const waitForBranchMaxTries = 3;
-  const waitForBranchRetryDelay = 1024;
+  const waitForBranchRetryDelayMs = 2000;
 
   const branchPresenceUrl = `${gitlabProjectApi}/repository/branches/${branchNameUrlEncoded}`;
+
+  // add small preventive delay, as checking right-away most probably would cause a retry
+  await millisecondsDelay(waitForBranchRetryDelayMs);
+
   for (let waitForBranchTryCount = 0; waitForBranchTryCount < waitForBranchMaxTries; waitForBranchTryCount++) {
     logger.debug({ branchPresenceUrl }, `Sending request to see if the branch for task ${task.id} is ready`);
     const response = await fetch(branchPresenceUrl, { headers: { "PRIVATE-TOKEN": gitlab.accessToken } });
@@ -132,8 +136,9 @@ export const runCommandInGitlabPipeline = async (ctx: Context, task: Task): Prom
         { branchPresenceUrl, task, response },
         `Branch of task ${task.id} was not found. Waiting before retrying...`,
       );
-      await millisecondsDelay(waitForBranchRetryDelay);
+      await millisecondsDelay(waitForBranchRetryDelayMs);
     } else if (response.ok) {
+      logger.debug({ branchNameUrlEncoded, response }, `Found branch ${branchNameUrlEncoded} for task ${task.id}`);
       wasBranchRegistered = true;
       break;
     } else {
@@ -143,7 +148,7 @@ export const runCommandInGitlabPipeline = async (ctx: Context, task: Task): Prom
 
   if (!wasBranchRegistered) {
     throw new Error(
-      `Task's branch was not registered on GitLab after ${waitForBranchMaxTries * waitForBranchRetryDelay}ms`,
+      `Task's branch was not registered on GitLab after ${waitForBranchMaxTries * waitForBranchRetryDelayMs}ms`,
     );
   }
 
@@ -153,11 +158,13 @@ export const runCommandInGitlabPipeline = async (ctx: Context, task: Task): Prom
     id: number;
     project_id: number;
   }>(
+    logger,
     fetch(pipelineCreationUrl, { method: "POST", headers: { "PRIVATE-TOKEN": gitlab.accessToken } }),
     Joi.object()
       .keys({ id: Joi.number().required(), project_id: Joi.number().required() })
       .options({ allowUnknown: true }),
   );
+
   logger.info({ pipeline, task }, `Created pipeline for task ${task.id}`);
 
   const jobFetchUrl = `${gitlabProjectApi}/pipelines/${pipeline.id}/jobs`;
@@ -169,6 +176,7 @@ export const runCommandInGitlabPipeline = async (ctx: Context, task: Task): Prom
       },
     ]
   >(
+    logger,
     fetch(jobFetchUrl, { headers: { "PRIVATE-TOKEN": gitlab.accessToken } }),
     Joi.array()
       .items(Joi.object().keys({ web_url: Joi.string().required() }).options({ allowUnknown: true }))
@@ -186,6 +194,7 @@ export const cancelGitlabPipeline = async (
 ): Promise<void> => {
   logger.info({ pipeline }, "Cancelling GitLab pipeline");
   await validatedFetch(
+    logger,
     fetch(
       /*
         Note: this endpoint can be called any time, even if the pipeline has
@@ -199,11 +208,12 @@ export const cancelGitlabPipeline = async (
 };
 
 const isPipelineFinished = async (ctx: Context, pipeline: TaskGitlabPipeline) => {
-  const { gitlab } = ctx;
+  const { gitlab, logger } = ctx;
 
   const { status } = await validatedFetch<{
     status: string;
   }>(
+    logger,
     fetch(`https://${gitlab.domain}/api/v4/projects/${pipeline.projectId}/pipelines/${pipeline.id}`, {
       headers: { "PRIVATE-TOKEN": gitlab.accessToken },
     }),

src/utils.ts

@@ -1,7 +1,7 @@
 import assert from "assert";
 import Joi from "joi";
 import fetch from "node-fetch";
-import { normalizeValue } from "opstooling-js";
+import { Logger, normalizeValue } from "opstooling-js";
 
 export const envVar = (name: string): string => {
   const val = process.env[name];
@@ -70,28 +70,39 @@ export class Err<T> {
   constructor(public value: T) {}
 }
 
+/**
+ * @throws Joi.ValidationError
+ */
 export const validatedFetch = async <T>(
-  response: ReturnType<typeof fetch>,
+  logger: Logger,
+  fetchFn: ReturnType<typeof fetch>,
   schema: Joi.AnySchema,
   { decoding }: { decoding: "json" } = { decoding: "json" },
 ): Promise<T> => {
   // eslint-disable-next-line @typescript-eslint/no-unsafe-assignment
   const body = await (async () => {
     switch (decoding) {
       case "json": {
-        return await (await response).json();
+        return await (await fetchFn).json();
       }
       default: {
         const exhaustivenessCheck: never = decoding;
         // eslint-disable-next-line @typescript-eslint/restrict-template-expressions
-        throw new Error(`Not exhaustive: ${exhaustivenessCheck}`);
+        const msg = `Not exhaustive: ${exhaustivenessCheck}`;
+        logger.fatal(msg);
+        throw new Error(msg);
       }
     }
   })();
+
   const validation = schema.validate(body);
+
   if (validation.error) {
+    // eslint-disable-next-line @typescript-eslint/no-unsafe-assignment
+    logger.error({ error: validation.error, response: body }, `Fetch validation error`);
     throw validation.error;
   }
+
   return validation.value as T;
 };