Added timeout for long running landkid builds. (#202)

* Added timeout to fail long running landkid builds using LAND_BUILD_TIMEOUT_TIME
* Triggerd BB API to retrieve land build status 
* Added tests 
* Fix compilation issue caused by adding root express mock


Co-authored-by: Grace <[email protected]>
Co-authored-by: Michael Blaszczyk <[email protected]>

package.json

@@ -18,6 +18,7 @@
   "scripts": {
     "clean": "rimraf dist",
     "test:unit": "jest",
+    "test:unit:watch": "jest --watch",
     "format": "prettier --write src/**/*.ts src/**/*.tsx",
     "build": "yarn clean && yarn build:server && yarn build:ui",
     "build:server": "tsc",

src/bitbucket/BitbucketClient.ts

@@ -131,6 +131,10 @@ export class BitbucketClient {
     return this.pipelines.stopLandBuild(buildId, lockId);
   }
 
+  getLandBuild(buildId: number) {
+    return this.pipelines.getLandBuild(buildId);
+  }
+
   mergePullRequest(landRequestStatus: LandRequestStatus, options?: MergeOptions) {
     return this.bitbucket.mergePullRequest(landRequestStatus, options);
   }

src/bitbucket/BitbucketPipelinesAPI.ts

@@ -146,4 +146,20 @@ export class BitbucketPipelinesAPI {
     }
     return true;
   };
+
+  getLandBuild = async (buildId: Number): Promise<BB.Pipeline> => {
+    const endpoint = `${this.apiBaseUrl}/pipelines/${buildId}`;
+    const { data } = await axios.get<BB.Pipeline>(
+      endpoint,
+      await bitbucketAuthenticator.getAuthConfig(fromMethodAndUrl('get', endpoint)),
+    );
+
+    Logger.info('Successfully loaded land build data', {
+      namespace: 'bitbucket:api:getLandBuild',
+      state: data.state,
+      buildId,
+    });
+
+    return data;
+  };
 }

src/bitbucket/__tests__/BitbucketPipelinesAPI.test.ts

@@ -0,0 +1,37 @@
+import axios from 'axios';
+import { BitbucketPipelinesAPI } from '../BitbucketPipelinesAPI';
+import { bitbucketAuthenticator } from '../BitbucketAuthenticator';
+
+jest.mock('axios');
+const mockedAxios = axios as unknown as jest.Mocked<typeof axios>;
+
+const bitbucketPipelineAPI = new BitbucketPipelinesAPI({
+  repoName: 'repo',
+  repoOwner: 'owner',
+});
+
+describe('BitbucketPipelinesAPI', () => {
+  beforeEach(() => {
+    jest.resetAllMocks();
+    jest.spyOn(bitbucketAuthenticator, 'getAuthConfig').mockResolvedValue({});
+  });
+
+  test(`getLandBuild > should return land build data`, async () => {
+    const response = {
+      data: {
+        state: {
+          result: {
+            name: 'FAILED',
+          },
+        },
+      },
+    };
+    mockedAxios.get.mockResolvedValue(response);
+
+    expect(await bitbucketPipelineAPI.getLandBuild(123)).toBe(response.data);
+    expect(mockedAxios.get).toBeCalledWith(
+      'https://api.bitbucket.org/2.0/repositories/owner/repo/pipelines/123',
+      {},
+    );
+  });
+});

src/bitbucket/types.d.ts

@@ -150,4 +150,8 @@ declare namespace BB {
     createdOn: Date;
     url: string;
   };
+
+  type Pipeline = {
+    state: { result: { name: BuildState } };
+  };
 }

src/lib/Runner.ts

@@ -25,6 +25,8 @@ import { BitbucketAPI } from '../bitbucket/BitbucketAPI';
 // 3 hours should be long enough to complete it now that we only fetch requests within 7 days (about 20 waiting requests)
 const MAX_CHECK_WAITING_REQUESTS_TIME = 1000 * 60 * 60 * 3; // 3 hours
 
+const LAND_BUILD_TIMEOUT_TIME = 1000 * 60 * 60 * 2; // 2 hours
+
 export class Runner {
   constructor(
     public queue: LandRequestQueue,
@@ -46,6 +48,11 @@ export class Runner {
     setInterval(() => {
       this.next();
     }, 15 * 1000); // 15s
+
+    // call checkRunningLandRequests() function on a interval of 10 min to verify LAND_BUILD_TIMEOUT_TIME
+    setInterval(() => {
+      this.checkRunningLandRequests();
+    }, 10 * 60 * 1000);
   }
 
   getMaxConcurrentBuilds = () =>
@@ -349,7 +356,6 @@ export class Runner {
             // checking the rest of the queue
             if (didChangeState) return true;
           }
-          // otherwise, we must just be running, nothing to do here
         }
         return false;
       },
@@ -630,6 +636,57 @@ export class Runner {
     );
   };
 
+  // this check prevents the system from being hung if BB webhook doesn't work as expected
+  checkRunningLandRequests = async () => {
+    await withLock(
+      // this lock ensures we don't run multiple checks at the same time that might cause a race condition
+      'check-running-requests',
+      async () => {
+        await withLock(
+          // this lock ensures we don't run the check when we're running this.next()
+          'status-transition',
+          async () => {
+            const requests = await this.queue.getRunning();
+            const runningRequests = requests.filter((request) => request.state === 'running');
+
+            Logger.info('Checking running landrequests for timeout', {
+              namespace: 'lib:runner:checkRunningLandRequests',
+              runningRequests,
+            });
+
+            for (const landRequestStatus of runningRequests) {
+              const timeElapsed = Date.now() - landRequestStatus.date.getTime();
+
+              if (timeElapsed > LAND_BUILD_TIMEOUT_TIME) {
+                const landRequest = landRequestStatus.request;
+
+                Logger.warn('Failing running land request as timeout period is breached', {
+                  pullRequestId: landRequest.pullRequestId,
+                  landRequestId: landRequest.id,
+                  namespace: 'lib:runner:checkRunningLandRequests',
+                });
+                await landRequest.setStatus('fail', 'Build timeout period breached');
+              } else {
+                const { buildId } = landRequestStatus.request;
+                const { state } = await this.client.getLandBuild(buildId);
+
+                // buildStatus can be SUCCESSFUL, FAILED or STOPPED
+                await this.onStatusUpdate({
+                  buildId,
+                  buildStatus: state.result?.name,
+                });
+              }
+            }
+          },
+          undefined,
+          // release the lock immediately so that this.next() can keep running, set to 100 because ttl needs to be > 0
+          100,
+        );
+      },
+      undefined,
+    );
+  };
+
   getStatusesForLandRequests = async (
     requestIds: string[],
   ): Promise<{ [id: string]: LandRequestStatus[] }> => {

src/lib/__tests__/Runner.test.ts

@@ -326,6 +326,102 @@ describe('Runner', () => {
     });
   });
 
+  describe('Check running landrequests for timeout', () => {
+    let onStatusUpdateSpy: jest.SpyInstance;
+    const getLandRequestStatus = (date: Date) => {
+      const request = new LandRequest({
+        created: new Date(123),
+        forCommit: 'abc',
+        id: '1',
+        buildId: 1,
+        triggererAaid: '123',
+        pullRequestId: 1,
+        pullRequest: mockPullRequest,
+      });
+      return new LandRequestStatus({
+        date,
+        id: '1',
+        isLatest: true,
+        request,
+        requestId: '1',
+        state: 'running',
+      });
+    };
+
+    beforeEach(() => {
+      onStatusUpdateSpy = jest.spyOn(runner, 'onStatusUpdate').mockResolvedValue();
+    });
+
+    afterEach(() => {
+      onStatusUpdateSpy.mockRestore();
+    });
+
+    test('should get land build status (failed) if timeout period is not breached', async () => {
+      jest.spyOn(mockClient, 'getLandBuild').mockResolvedValue({
+        state: {
+          result: {
+            name: 'FAILED',
+          },
+        },
+      } as any);
+      const mockLandRequestStatus = getLandRequestStatus(new Date());
+
+      //running state is within the timeout period of 2 hours
+      mockQueue.getRunning = jest.fn(async () => [mockLandRequestStatus]);
+      await wait(500);
+      expect(mockLandRequestStatus.request.setStatus).not.toHaveBeenCalled();
+      await runner.checkRunningLandRequests();
+
+      expect(mockLandRequestStatus.request.setStatus).not.toHaveBeenCalled();
+      expect(mockClient.getLandBuild).toHaveBeenCalled();
+      expect(onStatusUpdateSpy).toHaveBeenCalledWith({
+        buildId: 1,
+        buildStatus: 'FAILED',
+      });
+    });
+
+    test('should get land build status (running) if timeout period is not breached', async () => {
+      jest.spyOn(mockClient, 'getLandBuild').mockResolvedValue({
+        state: {
+          stage: {
+            name: 'RUNNING',
+          },
+        },
+      } as any);
+      //running state is within the timeout period of 2 hours
+      const mockLandRequestStatus = getLandRequestStatus(new Date());
+
+      await wait(500);
+      mockQueue.getRunning = jest.fn(async () => [mockLandRequestStatus]);
+
+      expect(mockLandRequestStatus.request.setStatus).not.toHaveBeenCalled();
+      await runner.checkRunningLandRequests();
+
+      expect(mockClient.getLandBuild).toHaveBeenCalled();
+      expect(mockLandRequestStatus.request.setStatus).not.toHaveBeenCalled();
+      expect(onStatusUpdateSpy).toHaveBeenCalledWith({
+        buildId: 1,
+        buildStatus: undefined,
+      });
+    });
+
+    test('should fail land request if timeout period is breached', async () => {
+      //running state is beyond the timeout period of 2 hours
+      const mockLandRequestStatus = getLandRequestStatus(new Date('2022-12-13T03:42:48.071Z'));
+
+      mockQueue.getRunning = jest.fn(async () => [mockLandRequestStatus]);
+
+      expect(mockLandRequestStatus.request.setStatus).not.toHaveBeenCalled();
+      await runner.checkRunningLandRequests();
+
+      expect(mockLandRequestStatus.request.setStatus).toHaveBeenCalledTimes(1);
+      expect(mockLandRequestStatus.request.setStatus).toHaveBeenCalledWith(
+        'fail',
+        'Build timeout period breached',
+      );
+    });
+  });
+
   describe('moveFromQueueToRunning', () => {
     test('should successfully transition land request from queued to running if all checks pass', async () => {
       const request = new LandRequest({

tsconfig.json

@@ -1,8 +1,13 @@
 {
   "extends": "./tsconfig.base.json",
   "compilerOptions": {
+    "rootDir": "src",
     "outDir": "dist",
   },
+  "include": [
+    "./src",
+    "./typings"
+  ],
   "exclude": [
     "node_modules",
     "tests",