Merge pull request #444 from actions/yoannchaudet-deployment-polling-backoff

Add backoff and jitter to deployment polling

.github/workflows/codeql-analysis.yml

@@ -42,7 +42,7 @@ jobs:
 
       # Initializes the CodeQL tools for scanning.
       - name: Initialize CodeQL
-        uses: github/codeql-action/init@v4
+        uses: github/codeql-action/init@v3
         with:
           languages: ${{ matrix.language }}
           # If you wish to specify custom queries, you can do so here or in a config file.
@@ -53,7 +53,7 @@ jobs:
       # Autobuild attempts to build any compiled languages  (C/C++, C#, or Java).
       # If this step fails, then you should remove it and run the build manually (see below)
       - name: Autobuild
-        uses: github/codeql-action/autobuild@v4
+        uses: github/codeql-action/autobuild@v3
 
       # ℹ️ Command-line programs to run using the OS shell.
       # 📚 https://git.io/JvXDl
@@ -67,4 +67,4 @@ jobs:
       #   make release
 
       - name: Perform CodeQL Analysis
-        uses: github/codeql-action/analyze@v4
+        uses: github/codeql-action/analyze@v3

README.md

@@ -51,7 +51,7 @@ jobs:
 | `token` | `true` | `${{ github.token }}` | The GitHub token used to create an authenticated client - Provided for you by default! |
 | `timeout` | `false` | `"600000"` | Time in milliseconds after which to timeout and cancel the deployment (default: 10 minutes) |
 | `error_count` | `false` | `"10"` | Maximum number of status report errors before cancelling a deployment (default: 10) |
-| `reporting_interval` | `false` | `"5000"` | Time in milliseconds between two deployment status reports (default: 5 seconds) |
+| `reporting_interval` | `false` | `"5000"` | Initial time in milliseconds between deployment status reports. Successful non-terminal polls use exponential backoff up to 30 seconds, or the configured interval when higher, with ±20% jitter. Error backoff is added separately (default: 5 seconds). |
 | `artifact_name` | `false` | `"github-pages"` | The name of the artifact to deploy |
 | `preview` | `false` | `"false"` | Is this attempting to deploy a pull request as a GitHub Pages preview site? (NOTE: This feature is only in alpha currently and is not available to the public!) |
 

action.yml

@@ -18,7 +18,7 @@ inputs:
     required: false
     default: '10'
   reporting_interval:
-    description: 'Time in milliseconds between two deployment status report (default: 5 seconds)'
+    description: 'Initial time between deployment status reports; successful polls use capped backoff and jitter, with error backoff added separately (default: 5 seconds)'
     required: false
     default: '5000'
   artifact_name:

dist/index.js

@@ -149920,9 +149920,18 @@ const finalErrorStatus = {
 }
 
 const MAX_TIMEOUT = 600000
+const DEFAULT_REPORTING_INTERVAL = 5000
+const MAX_REPORTING_INTERVAL = 30000
+const REPORTING_BACKOFF_MULTIPLIER = 1.5
+const REPORTING_JITTER_FACTOR = 0.2
 const ONE_GIGABYTE = 1073741824
 const SIZE_LIMIT_DESCRIPTION = '1 GB'
 
+function getJitteredInterval(interval) {
+  const jitter = interval * REPORTING_JITTER_FACTOR
+  return Math.round(interval - jitter + Math.random() * jitter * 2)
+}
+
 class Deployment {
   constructor() {
     const context = getContext()
@@ -150034,9 +150043,19 @@ class Deployment {
     }
 
     const deploymentId = this.deploymentInfo.id || this.buildVersion
-    const reportingInterval = Number(core.getInput('reporting_interval'))
+    const reportingIntervalInput = Number(core.getInput('reporting_interval'))
+    const initialReportingInterval =
+      Number.isFinite(reportingIntervalInput) && reportingIntervalInput > 0
+        ? reportingIntervalInput
+        : DEFAULT_REPORTING_INTERVAL
+    const maxReportingInterval = Math.max(MAX_REPORTING_INTERVAL, initialReportingInterval)
     const maxErrorCount = Number(core.getInput('error_count'))
 
+    if (initialReportingInterval !== reportingIntervalInput) {
+      core.warning(`Invalid reporting_interval value; using the default of ${DEFAULT_REPORTING_INTERVAL} milliseconds.`)
+    }
+
+    let reportingInterval = initialReportingInterval
     let errorCount = 0
 
     // Time in milliseconds between two deployment status report when status errored, default 0.
@@ -150047,7 +150066,7 @@ class Deployment {
     /*eslint no-constant-condition: ["error", { "checkLoops": false }]*/
     while (true) {
       // Handle reporting interval
-      await new Promise(resolve => setTimeout(resolve, reportingInterval + errorReportingInterval))
+      await new Promise(resolve => setTimeout(resolve, getJitteredInterval(reportingInterval + errorReportingInterval)))
 
       // Check status
       try {
@@ -150075,6 +150094,7 @@ class Deployment {
 
         // reset the error reporting interval once get the proper status back.
         errorReportingInterval = 0
+        reportingInterval = Math.min(Math.round(reportingInterval * REPORTING_BACKOFF_MULTIPLIER), maxReportingInterval)
       } catch (error) {
         core.error(error.stack)
 
@@ -150138,7 +150158,14 @@ class Deployment {
   }
 }
 
-module.exports = { Deployment, MAX_TIMEOUT, ONE_GIGABYTE, SIZE_LIMIT_DESCRIPTION }
+module.exports = {
+  Deployment,
+  MAX_TIMEOUT,
+  DEFAULT_REPORTING_INTERVAL,
+  MAX_REPORTING_INTERVAL,
+  ONE_GIGABYTE,
+  SIZE_LIMIT_DESCRIPTION
+}
 
 
 /***/ }),

src/__tests__/internal/deployment.test.js

@@ -4,7 +4,14 @@ const nock = require('nock')
 // For mocking network calls with native Fetch (octokit)
 const { MockAgent, setGlobalDispatcher } = require('undici')
 
-const { Deployment, MAX_TIMEOUT, ONE_GIGABYTE, SIZE_LIMIT_DESCRIPTION } = require('../../internal/deployment')
+const {
+  Deployment,
+  MAX_TIMEOUT,
+  DEFAULT_REPORTING_INTERVAL,
+  MAX_REPORTING_INTERVAL,
+  ONE_GIGABYTE,
+  SIZE_LIMIT_DESCRIPTION
+} = require('../../internal/deployment')
 
 const fakeJwt =
   'eyJhbGciOiJIUzI1NiIsInR5cCI6IkpXVCJ9.eyJqdGkiOiJiNjllMWIxOC1jOGFiLTRhZGQtOGYxOC03MzVlMzVjZGJhZjAiLCJzdWIiOiJyZXBvOnBhcGVyLXNwYS9taW55aTplbnZpcm9ubWVudDpQcm9kdWN0aW9uIiwiYXVkIjoiaHR0cHM6Ly9naXRodWIuY29tL3BhcGVyLXNwYSIsInJlZiI6InJlZnMvaGVhZHMvbWFpbiIsInNoYSI6ImEyODU1MWJmODdiZDk3NTFiMzdiMmM0YjM3M2MxZjU3NjFmYWM2MjYiLCJyZXBvc2l0b3J5IjoicGFwZXItc3BhL21pbnlpIiwicmVwb3NpdG9yeV9vd25lciI6InBhcGVyLXNwYSIsInJ1bl9pZCI6IjE1NDY0NTkzNjQiLCJydW5fbnVtYmVyIjoiMzQiLCJydW5fYXR0ZW1wdCI6IjIiLCJhY3RvciI6IllpTXlzdHkiLCJ3b3JrZmxvdyI6IkNJIiwiaGVhZF9yZWYiOiIiLCJiYXNlX3JlZiI6IiIsImV2ZW50X25hbWUiOiJwdXNoIiwicmVmX3R5cGUiOiJicmFuY2giLCJlbnZpcm9ubWVudCI6IlByb2R1Y3Rpb24iLCJqb2Jfd29ya2Zsb3dfcmVmIjoicGFwZXItc3BhL21pbnlpLy5naXRodWIvd29ya2Zsb3dzL2JsYW5rLnltbEByZWZzL2hlYWRzL21haW4iLCJpc3MiOiJodHRwczovL3Rva2VuLmFjdGlvbnMuZ2l0aHVidXNlcmNvbnRlbnQuY29tIiwibmJmIjoxNjM4ODI4MDI4LCJleHAiOjE2Mzg4Mjg5MjgsImlhdCI6MTYzODgyODYyOH0.1wyupfxu1HGoTyIqatYg0hIxy2-0bMO-yVlmLSMuu2w'
@@ -35,7 +42,7 @@ describe('Deployment', () => {
         case 'token':
           return process.env.GITHUB_TOKEN
         case 'reporting_interval':
-          return 50 // Lower reporting interval to speed up test
+          return process.env.INPUT_REPORTING_INTERVAL || 50 // Lower reporting interval to speed up test
         default:
           return process.env[`INPUT_${param.toUpperCase()}`] || ''
       }
@@ -121,6 +128,58 @@ describe('Deployment', () => {
       twirpScope.done()
     })
 
+    it('can successfully create a deployment with a 64-character build version', async () => {
+      process.env.GITHUB_SHA = 'a'.repeat(64)
+
+      const twirpScope = nock(process.env.ACTIONS_RESULTS_URL)
+        .post(LIST_ARTIFACTS_TWIRP_PATH)
+        .reply(
+          200,
+          {
+            artifacts: [{ databaseId: 11, name: 'github-pages', size: 221 }]
+          },
+          { headers: { 'content-type': 'application/json' } }
+        )
+
+      mockPool
+        .intercept({
+          path: `/repos/${process.env.GITHUB_REPOSITORY}/pages/deployments`,
+          method: 'POST',
+          body: bodyString => {
+            const body = JSON.parse(bodyString)
+            const keys = Object.keys(body).sort()
+            return (
+              keys.length === 3 &&
+              keys[0] === 'artifact_id' &&
+              keys[1] === 'oidc_token' &&
+              keys[2] === 'pages_build_version' &&
+              body.artifact_id === 11 &&
+              body.pages_build_version === process.env.GITHUB_SHA &&
+              body.oidc_token === fakeJwt
+            )
+          }
+        })
+        .reply(
+          200,
+          {
+            status_url: `https://api.github.com/repos/${process.env.GITHUB_REPOSITORY}/pages/deployments/${process.env.GITHUB_SHA}`,
+            page_url: 'https://actions.github.io/is-awesome'
+          },
+          { headers: { 'content-type': 'application/json' } }
+        )
+
+      const deployment = new Deployment()
+      await deployment.create(fakeJwt)
+
+      expect(process.env.GITHUB_SHA).toHaveLength(64)
+      expect(core.setFailed).not.toHaveBeenCalled()
+      expect(core.info).toHaveBeenLastCalledWith(
+        expect.stringMatching(new RegExp(`^Created deployment for ${process.env.GITHUB_SHA}`))
+      )
+
+      twirpScope.done()
+    })
+
     it('can successfully create a preview deployment', async () => {
       process.env.GITHUB_SHA = 'valid-build-version'
 
@@ -556,6 +615,42 @@ describe('Deployment', () => {
   })
 
   describe('#check', () => {
+    afterEach(() => {
+      jest.restoreAllMocks()
+      delete process.env.INPUT_ERROR_COUNT
+      delete process.env.INPUT_REPORTING_INTERVAL
+    })
+
+    const mockDeploymentStatus = (status, times = 1) => {
+      mockPool
+        .intercept({
+          path: `/repos/${process.env.GITHUB_REPOSITORY}/pages/deployments/${process.env.GITHUB_SHA}`,
+          method: 'GET'
+        })
+        .reply(200, { status }, { headers: { 'content-type': 'application/json' } })
+        .times(times)
+    }
+
+    const createPendingDeployment = () => {
+      const deployment = new Deployment()
+      deployment.deploymentInfo = {
+        id: process.env.GITHUB_SHA,
+        pending: true
+      }
+      deployment.startTime = Date.now()
+      return deployment
+    }
+
+    const runWithoutWaiting = async deployment => {
+      const timeoutSpy = jest.spyOn(global, 'setTimeout').mockImplementation(resolve => {
+        resolve()
+        return 0
+      })
+
+      await deployment.check()
+      return timeoutSpy
+    }
+
     it('sets output to success when deployment is successful', async () => {
       process.env.GITHUB_SHA = 'valid-build-version'
 
@@ -912,7 +1007,7 @@ describe('Deployment', () => {
           case 'error_count':
             return 10
           case 'reporting_interval':
-            return 0 // The default of 5000 is too long for the test
+            return 1 // The default of 5000 is too long for the test
           case 'timeout':
             return 42
           default:
@@ -938,6 +1033,108 @@ describe('Deployment', () => {
       expect(core.info).toHaveBeenLastCalledWith('Reported success!')
       twirpScope.done()
     })
+
+    it('backs off successful non-terminal status checks', async () => {
+      process.env.GITHUB_SHA = 'valid-build-version'
+      process.env.INPUT_ERROR_COUNT = '10'
+      mockDeploymentStatus('deployment_in_progress', 2)
+      mockDeploymentStatus('succeed')
+      const randomSpy = jest.spyOn(Math, 'random').mockReturnValue(0.5)
+
+      const timeoutSpy = await runWithoutWaiting(createPendingDeployment())
+
+      expect(timeoutSpy).toHaveBeenNthCalledWith(1, expect.any(Function), 50)
+      expect(timeoutSpy).toHaveBeenNthCalledWith(2, expect.any(Function), 75)
+      expect(timeoutSpy).toHaveBeenNthCalledWith(3, expect.any(Function), 113)
+
+      timeoutSpy.mockRestore()
+      randomSpy.mockRestore()
+      delete process.env.INPUT_ERROR_COUNT
+    })
+
+    it('caps the successful status check backoff', async () => {
+      process.env.GITHUB_SHA = 'valid-build-version'
+      process.env.INPUT_ERROR_COUNT = '10'
+      process.env.INPUT_REPORTING_INTERVAL = '20000'
+      mockDeploymentStatus('deployment_in_progress')
+      mockDeploymentStatus('succeed')
+      const randomSpy = jest.spyOn(Math, 'random').mockReturnValue(0.5)
+
+      const timeoutSpy = await runWithoutWaiting(createPendingDeployment())
+
+      expect(timeoutSpy.mock.calls.map(([, interval]) => interval)).toEqual([20000, MAX_REPORTING_INTERVAL])
+
+      timeoutSpy.mockRestore()
+      randomSpy.mockRestore()
+    })
+
+    it('does not reduce a configured interval above the backoff cap', async () => {
+      process.env.GITHUB_SHA = 'valid-build-version'
+      process.env.INPUT_ERROR_COUNT = '10'
+      process.env.INPUT_REPORTING_INTERVAL = '45000'
+      mockDeploymentStatus('deployment_in_progress')
+      mockDeploymentStatus('succeed')
+      jest.spyOn(Math, 'random').mockReturnValue(0.5)
+
+      const timeoutSpy = await runWithoutWaiting(createPendingDeployment())
+
+      expect(timeoutSpy.mock.calls.map(([, interval]) => interval)).toEqual([45000, 45000])
+    })
+
+    it.each(['not-a-number', '0', '-1'])(
+      'uses the default reporting interval for invalid input %s',
+      async reportingInterval => {
+        process.env.GITHUB_SHA = 'valid-build-version'
+        process.env.INPUT_ERROR_COUNT = '10'
+        process.env.INPUT_REPORTING_INTERVAL = reportingInterval
+        mockDeploymentStatus('succeed')
+        jest.spyOn(Math, 'random').mockReturnValue(0.5)
+
+        const timeoutSpy = await runWithoutWaiting(createPendingDeployment())
+
+        expect(timeoutSpy).toHaveBeenCalledWith(expect.any(Function), DEFAULT_REPORTING_INTERVAL)
+        expect(core.warning).toHaveBeenCalledWith(
+          `Invalid reporting_interval value; using the default of ${DEFAULT_REPORTING_INTERVAL} milliseconds.`
+        )
+      }
+    )
+
+    it('jitters status check intervals by up to twenty percent', async () => {
+      process.env.GITHUB_SHA = 'valid-build-version'
+      process.env.INPUT_ERROR_COUNT = '10'
+      mockDeploymentStatus('deployment_in_progress')
+      mockDeploymentStatus('succeed')
+      const randomSpy = jest.spyOn(Math, 'random').mockReturnValueOnce(0).mockReturnValueOnce(1)
+
+      const timeoutSpy = await runWithoutWaiting(createPendingDeployment())
+
+      expect(timeoutSpy).toHaveBeenNthCalledWith(1, expect.any(Function), 40)
+      expect(timeoutSpy).toHaveBeenNthCalledWith(2, expect.any(Function), 90)
+
+      timeoutSpy.mockRestore()
+      randomSpy.mockRestore()
+    })
+
+    it('keeps success backoff separate from error backoff', async () => {
+      process.env.GITHUB_SHA = 'valid-build-version'
+      process.env.INPUT_ERROR_COUNT = '10'
+      mockPool
+        .intercept({
+          path: `/repos/${process.env.GITHUB_REPOSITORY}/pages/deployments/${process.env.GITHUB_SHA}`,
+          method: 'GET'
+        })
+        .reply(500, {}, { headers: { 'content-type': 'application/json' } })
+      mockDeploymentStatus('deployment_in_progress')
+      mockDeploymentStatus('succeed')
+      const randomSpy = jest.spyOn(Math, 'random').mockReturnValue(0.5)
+
+      const timeoutSpy = await runWithoutWaiting(createPendingDeployment())
+
+      expect(timeoutSpy.mock.calls.map(([, interval]) => interval)).toEqual([50, 51, 75])
+
+      timeoutSpy.mockRestore()
+      randomSpy.mockRestore()
+    })
   })
 
   describe('#cancel', () => {

src/internal/deployment.js

@@ -24,9 +24,18 @@ const finalErrorStatus = {
 }
 
 const MAX_TIMEOUT = 600000
+const DEFAULT_REPORTING_INTERVAL = 5000
+const MAX_REPORTING_INTERVAL = 30000
+const REPORTING_BACKOFF_MULTIPLIER = 1.5
+const REPORTING_JITTER_FACTOR = 0.2
 const ONE_GIGABYTE = 1073741824
 const SIZE_LIMIT_DESCRIPTION = '1 GB'
 
+function getJitteredInterval(interval) {
+  const jitter = interval * REPORTING_JITTER_FACTOR
+  return Math.round(interval - jitter + Math.random() * jitter * 2)
+}
+
 class Deployment {
   constructor() {
     const context = getContext()
@@ -138,9 +147,19 @@ class Deployment {
     }
 
     const deploymentId = this.deploymentInfo.id || this.buildVersion
-    const reportingInterval = Number(core.getInput('reporting_interval'))
+    const reportingIntervalInput = Number(core.getInput('reporting_interval'))
+    const initialReportingInterval =
+      Number.isFinite(reportingIntervalInput) && reportingIntervalInput > 0
+        ? reportingIntervalInput
+        : DEFAULT_REPORTING_INTERVAL
+    const maxReportingInterval = Math.max(MAX_REPORTING_INTERVAL, initialReportingInterval)
     const maxErrorCount = Number(core.getInput('error_count'))
 
+    if (initialReportingInterval !== reportingIntervalInput) {
+      core.warning(`Invalid reporting_interval value; using the default of ${DEFAULT_REPORTING_INTERVAL} milliseconds.`)
+    }
+
+    let reportingInterval = initialReportingInterval
     let errorCount = 0
 
     // Time in milliseconds between two deployment status report when status errored, default 0.
@@ -151,7 +170,7 @@ class Deployment {
     /*eslint no-constant-condition: ["error", { "checkLoops": false }]*/
     while (true) {
       // Handle reporting interval
-      await new Promise(resolve => setTimeout(resolve, reportingInterval + errorReportingInterval))
+      await new Promise(resolve => setTimeout(resolve, getJitteredInterval(reportingInterval + errorReportingInterval)))
 
       // Check status
       try {
@@ -179,6 +198,7 @@ class Deployment {
 
         // reset the error reporting interval once get the proper status back.
         errorReportingInterval = 0
+        reportingInterval = Math.min(Math.round(reportingInterval * REPORTING_BACKOFF_MULTIPLIER), maxReportingInterval)
       } catch (error) {
         core.error(error.stack)
 
@@ -242,4 +262,11 @@ class Deployment {
   }
 }
 
-module.exports = { Deployment, MAX_TIMEOUT, ONE_GIGABYTE, SIZE_LIMIT_DESCRIPTION }
+module.exports = {
+  Deployment,
+  MAX_TIMEOUT,
+  DEFAULT_REPORTING_INTERVAL,
+  MAX_REPORTING_INTERVAL,
+  ONE_GIGABYTE,
+  SIZE_LIMIT_DESCRIPTION
+}