Measure inactiveness (#480)

* #429 save wip

* #429 save wip

* #429 save wip

* #429 fix stuff

* #429 add test for negative case

* #429 review fixes

Author: prayerslayer

common/util.js

@@ -96,6 +96,29 @@ export function setIn(obj, path, value) {
   return obj
 }
 
+function findDeepInObjImpl(obj, fn, result = []) {
+  if (typeof obj === 'object' && obj != null) {
+    for (const key of Object.keys(obj)) {
+      if (fn(key)) {
+        result.push([key, obj[key]])
+      }
+      findDeepInObjImpl(obj[key], fn, result)
+    }
+  }
+  return result
+}
+
+/**
+ * Returns an array of [key, val] for all
+ * keys in provided object where fn(key) returns true.
+ *
+ * @param obj object to walk
+ * @param fn will be passed key. is expected to return true iff key/ should be talken.
+ */
+export function findDeepInObj(obj, fn) {
+  return findDeepInObjImpl(obj, fn, [])
+}
+
 export function encode(string, encoding = 'base64') {
   if (encoding !== 'base64') {
     throw new Error(`Encoding "${encoding}" not supported`)

config/system.yaml

@@ -36,11 +36,11 @@ STATIC_DIR: ./dist/client
 # Database configuration
 # sqlite or postgres
 DB_DRIVER: sqlite
-#DB_NAME: postgres
-#DB_USER: postgres
-#DB_PASS: postgres
-#DB_HOST: 192.168.99.100
-#DB_PORT: 5432
+# DB_NAME: zappr
+# DB_USER: postgres
+# DB_PASS: postgres
+# DB_HOST: 192.168.99.100
+# DB_PORT: 5432
 SQLITE_FILE: ./zappr.sqlite
 
 # Token encryption

migrations/006-add-check-execution-columns.js

@@ -0,0 +1,67 @@
+const schema = 'zappr_data'
+const tableName = 'checks'
+
+module.exports.up = function (queryInterface, Sequelize) {
+  // delay between github and check execution
+  const lastExecutionDelayMs = queryInterface.addColumn(
+    {
+      schema,
+      tableName
+    },
+    'last_execution_delay_ms',
+    {
+      type: Sequelize.INTEGER,
+      allowNull: true
+    })
+  // when check was executed
+  const lastExecution = queryInterface.addColumn(
+    {
+      schema,
+      tableName
+    },
+    'last_execution_ts',
+    {
+      type: Sequelize.DATE,
+      allowNull: true
+    })
+  // how long did check execution take
+  const lastExecutionMs = queryInterface.addColumn(
+    {
+      schema,
+      tableName
+    },
+    'last_execution_ms',
+    {
+      type: Sequelize.INTEGER,
+      allowNull: true
+    })
+  // was check execution successful (ie we were able to set a status)
+  const lastExecutionSuccessful = queryInterface.addColumn(
+    {
+      schema,
+      tableName
+    },
+    'last_execution_successful',
+    {
+      type: Sequelize.BOOLEAN,
+      allowNull: true
+    })
+  return Promise.all([
+    lastExecutionDelayMs,
+    lastExecution,
+    lastExecutionMs,
+    lastExecutionSuccessful
+  ])
+}
+
+module.exports.down = function (queryInterface) {
+  return Promise.all(
+    ['last_execution_successful',
+      'last_execution_ms',
+      'last_execution_ts',
+      'last_execution_delay_ms'].map(col => queryInterface.removeColumn({
+      tableName,
+      schema
+    }, col)))
+
+}

server/checks/Autobranch.js

@@ -67,16 +67,12 @@ export default class Autobranch extends Check {
       info(`${repository.full_name}: Ignore issue #${issue.number}. Action was "${action}" instead of "opened".`)
       return
     }
-    try {
-      const owner = repository.owner.login
-      const repo = repository.name
-      const {sha} = await this.github.getHead(owner, repo, repository.default_branch, token)
-      // branch could exist already
-      await this.github.createBranch(owner, repo, branchName, sha, token)
-      info(`Created branch ${branchName} for ${sha} in ${repository.full_name}`)
-    } catch (e) {
-      // but we don't care
-      error(`Could not create branch ${branchName} for ${sha} in ${repository.full_name}`, e)
-    }
+
+    const owner = repository.owner.login
+    const repo = repository.name
+    const {sha} = await this.github.getHead(owner, repo, repository.default_branch, token)
+    // branch could exist already
+    await this.github.createBranch(owner, repo, branchName, sha, token)
+    info(`Created branch ${branchName} for ${sha} in ${repository.full_name}`)
   }
 }

server/checks/CheckRunner.js

@@ -9,9 +9,10 @@ import {
 } from './index'
 import { getPayloadFn } from './Check'
 import createAuditService from '../service/AuditServiceCreator'
+import { checkHandler as defaultCheckHandler } from '../handler/CheckHandler'
 import { githubService as defaultGithubService } from '../service/GithubService'
 import { pullRequestHandler as defaultPullRequestHandler } from '../handler/PullRequestHandler'
-import merge from 'lodash/merge'
+import { findDeepInObj } from '../../common/util'
 import { logger } from '../../common/debug'
 const info = logger('checkrunner', 'info')
 const error = logger('checkrunner', 'error')
@@ -27,12 +28,36 @@ function getTokens(dbRepo) {
   return (dbRepo.checks || []).reduce((agg, check) => ({[check.type]: check.token, ...agg}), {})
 }
 
+/**
+ * Returns when this GH event was triggered based on payload.
+ *
+ * Necessary because there is no top-level timestamp in the payload for every event,
+ * we have to look into the event itself and check different properties. Not cool.
+ * So this naive implementation looks for properties /.+?_at/ with value /\d{4}-\d{2}-\d{2}T\d{2}:\d{2}:\d{2}Z/
+ * and parses them and returns the most current.
+ *
+ * This approach may now work well in 100% of the cases, but avoids that we forget to
+ * change it in the future when we support new events.
+ *
+ * @param payload
+ */
+export function getTriggeredAt(payload) {
+  const endsWithAt = /^.+?_at$/
+  const looksLikeDate = /\d{4}-\d{2}-\d{2}T\d{2}:\d{2}:\d{2}Z/
+  return findDeepInObj(payload, key => endsWithAt.test(key))
+  .filter(([_, val]) => looksLikeDate.test(val))
+  .map(([_, val]) => Date.parse(val))
+  .reduce((mostCurrent, ts) => Math.max(mostCurrent, ts), 0)
+}
+
 export default class CheckRunner {
   constructor(githubService = defaultGithubService,
               pullRequestHandler = defaultPullRequestHandler,
+              checkHandler = defaultCheckHandler,
               auditService = createAuditService()) {
     this.githubService = githubService
     this.pullRequestHandler = pullRequestHandler
+    this.checkHandler = checkHandler
     this.approval = new Approval(this.githubService, this.pullRequestHandler, auditService)
     this.autobranch = new Autobranch(this.githubService)
     this.commitMessage = new CommitMessage(this.githubService)
@@ -109,40 +134,78 @@ export default class CheckRunner {
   }
 
   async handleGithubWebhook(dbRepo, checkArgs) {
-    const {event} = checkArgs
+    const {event, payload, config} = checkArgs
     const owner = dbRepo.json.owner.login
     const name = dbRepo.json.name
     const tokens = getTokens(dbRepo)
-    info(`${owner}/${name}: Handling Github event ${event}.${checkArgs.payload.action}`)
+    const start = Date.now()
+    const delay = start - getTriggeredAt(payload)
+    info(`${owner}/${name}: Handling Github event ${event}.${payload.action}`)
 
     if (PullRequestLabels.isTriggeredBy(event) && tokens[PullRequestLabels.TYPE]) {
       info(`${owner}/${name}: Executing check PullRequestLabels`)
-      await this.pullRequestLabels.execute(checkArgs.config, checkArgs.payload, tokens[PullRequestLabels.TYPE])
+      await this.checkHandler.onExecutionStart(dbRepo.id, PullRequestLabels.TYPE, delay)
+      try {
+        await this.pullRequestLabels.execute(config, payload, tokens[PullRequestLabels.TYPE])
+        await this.checkHandler.onExecutionEnd(dbRepo.id, PullRequestLabels.TYPE, Date.now() - start, true)
+      } catch (e) {
+        await this.checkHandler.onExecutionEnd(dbRepo.id, PullRequestLabels.TYPE, Date.now() - start, false)
+      }
     }
 
     if (Specification.isTriggeredBy(event) && tokens[Specification.TYPE]) {
       info(`${owner}/${name}: Executing check Specification`)
-      await this.specification.execute(checkArgs.config, checkArgs.payload, tokens[Specification.TYPE])
+      await this.checkHandler.onExecutionStart(dbRepo.id, Specification.TYPE, delay)
+      try {
+        await this.specification.execute(config, payload, tokens[Specification.TYPE])
+        await this.checkHandler.onExecutionEnd(dbRepo.id, Specification.TYPE, Date.now() - start, true)
+      } catch (e) {
+        await this.checkHandler.onExecutionEnd(dbRepo.id, Specification.TYPE, Date.now() - start, false)
+      }
     }
 
     if (Approval.isTriggeredBy(event) && tokens[Approval.TYPE]) {
       info(`${owner}/${name}: Executing check Approval`)
-      await this.approval.execute(checkArgs.config, event, checkArgs.payload, tokens[Approval.TYPE], dbRepo.id)
+      await this.checkHandler.onExecutionStart(dbRepo.id, Approval.TYPE, delay)
+      try {
+        await this.approval.execute(config, event, payload, tokens[Approval.TYPE], dbRepo.id)
+        await this.checkHandler.onExecutionEnd(dbRepo.id, Approval.TYPE, Date.now() - start, true)
+      } catch (e) {
+        await this.checkHandler.onExecutionEnd(dbRepo.id, Approval.TYPE, Date.now() - start, false)
+      }
     }
 
     if (Autobranch.isTriggeredBy(event) && tokens[Autobranch.TYPE]) {
       info(`${owner}/${name}: Executing check Autobranch`)
-      await this.autobranch.execute(checkArgs.config, checkArgs.payload, tokens[Autobranch.TYPE])
+      await this.checkHandler.onExecutionStart(dbRepo.id, Autobranch.TYPE, delay)
+      try {
+        await this.autobranch.execute(config, payload, tokens[Autobranch.TYPE])
+        await this.checkHandler.onExecutionEnd(dbRepo.id, Autobranch.TYPE, Date.now() - start, true)
+      } catch (e) {
+        await this.checkHandler.onExecutionEnd(dbRepo.id, Autobranch.TYPE, Date.now() - start, false)
+      }
     }
 
     if (CommitMessage.isTriggeredBy(event) && tokens[CommitMessage.TYPE]) {
       info(`${owner}/${name}: Executing check CommitMessage`)
-      await this.commitMessage.execute(checkArgs.config, checkArgs.payload, tokens[CommitMessage.TYPE])
+      await this.checkHandler.onExecutionStart(dbRepo.id, CommitMessage.TYPE, delay)
+      try {
+        await this.commitMessage.execute(config, payload, tokens[CommitMessage.TYPE])
+        await this.checkHandler.onExecutionEnd(dbRepo.id, CommitMessage.TYPE, Date.now() - start, true)
+      } catch (e) {
+        await this.checkHandler.onExecutionEnd(dbRepo.id, CommitMessage.TYPE, Date.now() - start, false)
+      }
     }
 
     if (PullRequestTasks.isTriggeredBy(event) && tokens[PullRequestTasks.TYPE]) {
       info(`${owner}/${name}: Executing check PullRequestTasks`)
-      await this.pullRequestTasks.execute(checkArgs.config, checkArgs.payload, tokens[PullRequestTasks.TYPE])
+      await this.checkHandler.onExecutionStart(dbRepo.id, PullRequestTasks.TYPE, delay)
+      try {
+        await this.pullRequestTasks.execute(config, payload, tokens[PullRequestTasks.TYPE])
+        await this.checkHandler.onExecutionEnd(dbRepo.id, PullRequestTasks.TYPE, Date.now() - start, true)
+      } catch (e) {
+        await this.checkHandler.onExecutionEnd(dbRepo.id, PullRequestTasks.TYPE, Date.now() - start, false)
+      }
     }
   }
 }

server/handler/CheckHandler.js

@@ -1,3 +1,4 @@
+import Sequelize from 'sequelize'
 import CheckHandlerError, { CHECK_NOT_FOUND, CHECK_EXISTS, DATABASE_ERROR } from './CheckHandlerError'
 import { Check } from '../model'
 import { githubService } from '../service/GithubService'
@@ -21,7 +22,7 @@ function findHookEventsFor(types) {
               .filter((evt, i, arr) => i === arr.lastIndexOf(evt)) // deduplicate
 }
 
-class CheckHandler {
+export class CheckHandler {
   constructor(github = githubService) {
     this.github = github
   }
@@ -139,9 +140,39 @@ class CheckHandler {
     const evts = findHookEventsFor(types)
 
     await this.github.updateWebhookFor(repo.owner.login, repo.name, evts, user.accessToken)
-    await checkHandler.onDeleteCheck(repo.id, type)
+    await this.onDeleteCheck(repo.id, type)
     info(`${repo.full_name}: disabled check ${type}`)
   }
+
+  onExecutionStart(repoId, type, delay) {
+    // set last_execution_ts to now
+    // set last execution delay
+    return Check.update({
+      last_execution_ts: Sequelize.fn('NOW'),
+      last_execution_delay_ms: delay,
+      last_execution_successful: null,
+      last_execution_ms: null
+    }, {
+      where: {
+        repositoryId: repoId,
+        type
+      }
+    })
+  }
+
+  onExecutionEnd(repoId, type, executionTime, executionSuccess) {
+    // set last execution ms
+    // set last execution success = true
+    return Check.update({
+      last_execution_successful: executionSuccess,
+      last_execution_ms: executionTime
+    }, {
+      where: {
+        repositoryId: repoId,
+        type
+      }
+    })
+  }
 }
 
 export const checkHandler = new CheckHandler()

server/model/Check.js

@@ -31,6 +31,22 @@ export default db.define('check', {
     type: Sequelize.TEXT,
     allowNull: true
   },
+  last_execution_delay_ms: {
+    type: Sequelize.INTEGER,
+    allowNull: true
+  },
+  last_execution_ts: {
+    type: Sequelize.DATE,
+    allowNull: true
+  },
+  last_execution_ms: {
+    type: Sequelize.INTEGER,
+    allowNull: true
+  },
+  last_execution_successful: {
+    type: Sequelize.BOOLEAN,
+    allowNull: true
+  },
   createdAt: {
     type: Sequelize.DATE,
     allowNull: false,

test/common/util.test.js

@@ -2,6 +2,7 @@ import { expect } from 'chai'
 import {
   getIn,
   setIn,
+  findDeepInObj,
   encode,
   decode,
   setDifference,
@@ -185,6 +186,31 @@ describe('common/util', () => {
     })
   })
 
+  describe('findDeepInObj', () => {
+    it('works on flat objects', () => {
+      const obj = {
+        a: 1,
+        b: 2,
+        cc: 3
+      }
+      const result = findDeepInObj(obj, key => /^[a-z]$/.test(key))
+      expect(result).to.deep.equal([['a', 1], ['b', 2]])
+    })
+
+    it('works on deep objects', () => {
+      const obj = {
+        a: {
+          b: {
+            cc: 3
+          }
+        },
+        dd: 4
+      }
+      const result = findDeepInObj(obj, key => /^[a-z]{2}$/.test(key))
+      expect(result).to.deep.equal([['cc', 3], ['dd', 4]])
+    })
+  })
+
   describe('getIn', () => {
     const obj = {
       commit: {