Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Update Check - Now throws a NotFound #941

Closed
warrenbuckley opened this issue May 31, 2019 · 15 comments

Comments

@warrenbuckley
Copy link

commented May 31, 2019

Bug Report

Current Behavior
When using ProBot to do an update to an existing Check it has stopped working

import { Application, Context, Octokit} from 'probot';
import Webhooks from '@octokit/webhooks';
import fs from 'fs-extra';
import { ChecksUpdateParamsOutputAnnotations } from '@octokit/rest';
import { execSync } from 'child_process';

/**
 * Default config if no YML file found or its malformed
 */
let defaultConfig:IConfig = {
  Vale: {
    Enabled: true,
    Paths: {
      Configuration: "/_vale.ini",
      Styles: "/vale/DocsStyles/"
    },
    Success: {
      Header: "DEFAULT Congratulations, there are no errors",
      Message: "DEFAULT The Vale Docs linter did not find any issues",
      ShowImage: true,
      ImageUrl: "https://media.giphy.com/media/6nuiJjOOQBBn2/giphy.gif"
    },
    Error: {
      Header: "DEFAULT Failed automated validation",
      Message: "DEFAULT There are one or more automated warnings with your PR",
      ShowImage: false,
      ImageUrl: ""
    }
  }
};


export = (app: Application) => {

  app.log('Booting up Vale Linter ProBot');

  // Listen for these PR webhook payload types
  app.on(['pull_request.opened', 'pull_request.synchronize', 'pull_request_reopened'], async (context: Context<Webhooks.WebhookPayloadPullRequest>) => {

    // Get the config from the repo that this bot installed
    // & if does not exist or malformed fallback to deafult one
    // .github/vale-linter.yml
    let config:IConfig = await context.config('vale-linter.yml', defaultConfig);

    if(config.Vale.Enabled === false){
      app.log('Vale Linter Config Disabled. Exiting Early');
      return;
    }

    app.log('Reacting to a PR webhook payload');

    const repoOwner = context.payload.repository.owner.login;
    const repoName = context.payload.repository.name;
    const headSha = context.payload.pull_request.head.sha;
    const prNumber = context.payload.number;

    // Create a NEW Check (For new PR's or code updated/sync'd or has been re-opened)
    // We will listen/hear back with a new WebHook event once it's been created
    await context.github.checks.create({
      name: 'Markdown Doc Lint',
      owner: repoOwner,
      repo: repoName,
      head_sha: headSha
    });

    app.log('Posted to GitHub API to create a Check for PR', prNumber);

  });

  app.on('check_run.rerequested', async (context: Context<Webhooks.WebhookPayloadCheckRun>) => {

    // Get the config from the repo that this bot installed
    // & if does not exist or malformed fallback to deafult one
    // .github/vale-linter.yml
    let config:IConfig = await context.config('vale-linter.yml', defaultConfig);

    if(config.Vale.Enabled === false){
      app.log('Vale Linter Config Disabled. Exiting Early');
      return;
    }

    // When we re-request. Lets create a NEW check
    // Thus the Check Run Created WebHook will fire below..

    const repoOwner = context.payload.repository.owner.login;
    const repoName = context.payload.repository.name;
    const headSha = context.payload.check_run.head_sha;

    await context.github.checks.create({
      name: 'Markdown Doc Lint',
      owner: repoOwner,
      repo: repoName,
      head_sha: headSha
    });

  });

  // Listen for when check is created from PR opened or PR Sync'd events
  app.on(['check_run.created'], async (context: Context<Webhooks.WebhookPayloadCheckRun>) => {

    // Get the config from the repo that this bot installed
    // & if does not exist or malformed fallback to deafult one
    // .github/vale-linter.yml
    let config:IConfig = await context.config('vale-linter.yml', defaultConfig);

    app.log('CONFIG', config);

    if(config.Vale.Enabled === false){
      app.log('Vale Linter Config Disabled. Exiting Early');
      return;
    }

    app.log('Reacting to a Check Run Created payload');

    //TODO: Need to 100% verify the check is for us & not another tool/servic
    //Think we can verify in either
    //context.payload.check_run.app.id
    //context.payload.check_run.app.name

    const repoOwner = context.payload.repository.owner.login;
    const repoName = context.payload.repository.name;
    const checkRunId = context.payload.check_run.id;

    const startTime = new Date();

    app.log('repoOwner', repoOwner);
    app.log('repoName', repoName);
    app.log('CheckRun', checkRunId);

    app.log('GitHub API Update Check with start time');

    // Update the check with in-progress state & date-time stamp
    // It goes KABOOM 🔥 💀 here
    await context.github.checks.update({
      owner: repoOwner,
      repo: repoName,
      check_run_id: checkRunId,
      status: "in_progress",
      started_at: startTime.toISOString()
    });

    const headSha = context.payload.check_run.head_sha;

    // Create the vale-lint folder to do our processing in & subdir for the vale YML style rules
    fs.mkdirpSync(`./vale-lint_${headSha}/files`);
    fs.mkdirpSync(`./vale-lint_${headSha}/${config.Vale.Paths.Styles}`);

    // Download _vale.ini from master branch
    const valeFile = await context.github.repos.getContents({ owner: repoOwner, repo: repoName, path: config.Vale.Paths.Configuration });
    const valeRawData = valeFile.data.content;
    const valeFileContent = Buffer.from(valeRawData, "base64").toString();

    // Save _vale.ini file
    await fs.writeFile(`./vale-lint_${headSha}/${config.Vale.Paths.Configuration}`, valeFileContent);
    app.log(`Written ./vale-lint_${headSha}/${config.Vale.Paths.Configuration} file`);


    // Get all files from 'vale/DocStyles' in repo root from master/default branch
    const valeStyles = await context.github.repos.getContents({ owner: repoOwner, repo: repoName, path: config.Vale.Paths.Styles });
    const valeStylesItems:Array<any> = valeStyles.data;

    for(const item of valeStylesItems){
      const filePath = item.path; // 'vale/DocStyles/BadWords.yml'

      // Download each file from the master/default branch
      const blobContent = await context.github.git.getBlob({owner: repoOwner, repo: repoName, file_sha: item.sha });
      const rawData = blobContent.data.content;
      const fileContent = Buffer.from(rawData, "base64").toString();

      fs.writeFileSync(`./vale-lint_${headSha}/${filePath}`, fileContent);
      app.log(`Written ./vale-lint_${headSha}/${filePath} file from default branch`);
    }


    // Fetch the list of files in the PR from the head_sha
    // Gives us an array of files that changed & their sha's so we can get their file contents
    var tree = await context.github.git.getTree({ owner: repoOwner, repo: repoName, tree_sha: headSha });
    var treeResponse = tree.data;
    var treeData:Array<any> = treeResponse.tree; // Array of objects

    // Filter the list of items (don't want images or anything else but .md files)
    const markdownFiles = treeData.filter(path => {
      const {path: filename, type} = path
      return type === 'blob'  && filename.endsWith('.md')
    });

    // For each markdown file - go and download it & save it in 'vale-lint/files'
    for(const file of markdownFiles){
      // Download each file
      const prBlob = await context.github.git.getBlob({owner: repoOwner, repo: repoName, file_sha: file.sha });
      var rawData = prBlob.data.content;
      var fileContent = Buffer.from(rawData, "base64").toString();

      // Write file to disk
      fs.writeFileSync(`./vale-lint_${headSha}/files/${file.path}`, fileContent);
      app.log(`Written file from PR to ./vale-lint_${headSha}/files/${file.path}`);
    }

    // Call the VALE CLI tool to output results as JSON
    // We must pass --no-exit otherwise if we find an error, we dont get the result but an error saying it exited etc
    var valeLint = execSync("vale --no-exit --output=JSON .", { cwd: `./vale-lint_${headSha}/files`});
    var rawString = valeLint.toString();
    app.log('Raw JSON string', rawString);

    // Example JSON result
    // {
    //   "README.md": [
    //     {
    //       "Check": "DocsStyles.BadWords",
    //       "Description": "",
    //       "Line": 6,
    //       "Link": "",
    //       "Message": "'slave' should be changed",
    //       "Severity": "error",
    //       "Span": [
    //         22,
    //         26
    //       ],
    //       "Hide": false,
    //       "Match": "slave"
    //     }
    //   ]
    // }

    // Convert to a proper JSON object to query/iterate over etc
    const resultJson = JSON.parse(rawString) as IValeJSON;


    // Check the JSON is NOT an empty json object `{}`
    const hasLints = Object.entries(resultJson).length > 0 && resultJson.constructor === Object;
    app.log('Has Lints?', hasLints);

    // No Errors - so let's bail out early & POST a SUCCESS message/check result
    if(hasLints === false){
      // Finish time
      const finishTime = new Date();

      let successCheck:Octokit.ChecksUpdateParams = {
        owner: repoOwner,
        repo: repoName,
        check_run_id: checkRunId,
        status: "completed",
        conclusion: "success",
        completed_at: finishTime.toISOString()
      };

      let successOutput:Octokit.ChecksUpdateParamsOutput = {
        title: config.Vale.Success.Header,
        summary: config.Vale.Success.Message
      }

      // If we have images enabled add it into the output object that makes up the larger check object
      if(config.Vale.Success.ShowImage){

        let images: Array<Octokit.ChecksUpdateParamsOutputImages> = new Array<Octokit.ChecksUpdateParamsOutputImages>();
        images.push({
          alt: config.Vale.Success.Header,
          image_url: config.Vale.Success.ImageUrl
        });

        // Update the output object
        successOutput.images = images;
      }

      //Add the output to the main object to send back to GitHub
      successCheck.output = successOutput;

      // Update check with SUCCESS result
      await context.github.checks.update(successCheck);

      // Delete vale-lint folder
      fs.removeSync(`./vale-lint_${headSha}`);

      // Exit/finish early
      return;
    }

    // An array to store our annotations in
    const annotations:Array<ChecksUpdateParamsOutputAnnotations> = new Array<ChecksUpdateParamsOutputAnnotations>();

    // For each error create an annotation
    for (const objectKey of Object.getOwnPropertyNames(resultJson)){
      const fileName = objectKey;
      const lintItems = resultJson[objectKey];

      // The filename can contain an array of objects
      for(const item of lintItems){

        // Vale states to map to GitHub Check Annotation Level
        // error = failure
        // warning = warning
        // suggestion = notice
        var githubLevel : "notice" | "warning" | "failure"  = "notice";

        switch (item.Severity) {
          case "suggestion":
            githubLevel = "notice";
            break;

          case "warning":
            githubLevel = "warning";
            break;

          case "error":
            githubLevel = "failure";
            break;

          default:
            githubLevel = "notice";
            break;
        }

        annotations.push({
          title: item.Check,
          message: item.Message,
          annotation_level: githubLevel,
          path: fileName,
          start_line: item.Line,
          end_line: item.Line,
          start_column: item.Span[0],
          end_column: item.Span[1]
        });
      }
    }

    // NOTE: GitHub API only accepts 50 annotations
    // If we have 50+ items will need to do multiple updates to the check
    app.log('Annotations', annotations);

    // Delete vale-lint folder
    fs.removeSync(`./vale-lint_${headSha}`);

    // Finish time
    const finishTime = new Date();

    // Update check with final result
    let errorCheck:Octokit.ChecksUpdateParams = {
      owner: repoOwner,
      repo: repoName,
      check_run_id: checkRunId,
      status: "completed",
      conclusion: "failure",
      completed_at: finishTime.toISOString()
    };

    let errorOutput:Octokit.ChecksUpdateParamsOutput = {
      title: config.Vale.Error.Header,
      summary: config.Vale.Error.Message
    }

    // If we have images enabled add it into the output object that makes up the larger check object
    if(config.Vale.Error.ShowImage){

      let images: Array<Octokit.ChecksUpdateParamsOutputImages> = new Array<Octokit.ChecksUpdateParamsOutputImages>();
      images.push({
        alt: config.Vale.Error.Header,
        image_url: config.Vale.Error.ImageUrl
      });

      // Update the output object
      errorOutput.images = images;
    }

    //Add the output to the main object to send back to GitHub
    errorCheck.output = errorOutput;

    // Update check with SUCCESS result
    await context.github.checks.update(errorCheck);

  });

  // For more information on building apps:
  // https://probot.github.io/docs/

  // To get your app running against GitHub, see:
  // https://probot.github.io/docs/development/
}

Expected behavior/code
For the Octokit to perform the REST API call & update the Check.

Environment

  • Probot version(s): 9.2.10
  • Node/npm version: Node v10.15.3 & npm 6.9.0
  • OS: Windows 10

Additional context

15:31:15.389Z  INFO probot: GitHub API Update Check with start time
15:31:16.444Z ERROR event: Not Found (id=aed8ac00-83b7-11e9-9115-ea0af161e4b6)
  HttpError: Not Found
      at response.text.then.message (C:\Code-Personal\_Docker-Playground\vale-linter\probot-app\node_modules\@octokit\request\lib\request.js:56:27)
      at process._tickCallback (internal/process/next_tick.js:68:7)
  --
  event: {
    "event": "check_run.created",
    "id": "aed8ac00-83b7-11e9-9115-ea0af161e4b6",
    "installation": 940633,
    "repository": "warrenbuckley/Checks-Linting-Testing"
  }
15:31:16.447Z ERROR probot: Not Found
  HttpError: Not Found
      at response.text.then.message (C:\Code-Personal\_Docker-Playground\vale-linter\probot-app\node_modules\@octokit\request\lib\request.js:56:27)
      at process._tickCallback (internal/process/next_tick.js:68:7)
15:31:16.452Z  INFO http: POST / 500 - 1584.96 ms (id=e5ff2c20-b3c9-4ee9-986d-71408c705827)
15:31:16.455Z ERROR probot: Internal Server Error
  Error: Internal Server Error
      at Request.callback (C:\Code-Personal\_Docker-Playground\vale-linter\probot-app\node_modules\superagent\lib\node\index.js:706:15)
      at IncomingMessage.parser (C:\Code-Personal\_Docker-Playground\vale-linter\probot-app\node_modules\superagent\lib\node\index.js:916:18)
      at IncomingMessage.emit (events.js:194:15)
      at IncomingMessage.EventEmitter.emit (domain.js:441:20)
      at endReadableNT (_stream_readable.js:1125:12)
      at process._tickCallback (internal/process/next_tick.js:63:19)
@welcome

This comment has been minimized.

Copy link

commented May 31, 2019

Thanks for opening this issue. A contributor should be by to give feedback soon. In the meantime, please check out the contributing guidelines and explore other ways you can get involved.

@issue-label-bot issue-label-bot bot added the bug 🐞 label May 31, 2019

@issue-label-bot

This comment has been minimized.

Copy link

commented May 31, 2019

Issue-Label Bot is automatically applying the label bug 🐞 to this issue, with a confidence of 0.95. Please mark this comment with 👍 or 👎 to give our bot feedback!

Links: app homepage, dashboard and code for this bot.

@gr2m

This comment has been minimized.

Copy link
Contributor

commented May 31, 2019

A sudden 404 can mean that sth is wrong with authentication, maybe you invalidated your private key?

The code you pasted is way too long. You have to create a minimal test case that is easy to reproduce in order to get help

@warrenbuckley

This comment has been minimized.

Copy link
Author

commented May 31, 2019

Will look into auth to see what’s happened. End of working week.

Sorry for the long code snippet. Just a frustration/panic it stopped working at the end of my working day.

@gr2m

This comment has been minimized.

Copy link
Contributor

commented May 31, 2019

Maybe contact support. I the logs of the WIP app, see a big spike of 401 Bad Credentials responses from the API, as well as an increase of Server Errors (500 responses). https://www.githubstatus.com/ shows nothing, but something is up, maybe you are affected by the same thing.

Welcome to GitHub's home for real-time and historical data on system performance.
@warrenbuckley

This comment has been minimized.

Copy link
Author

commented May 31, 2019

Interesting I defiantly not changed the PGP key. So not sure why it would return 401 auth problems.

I will contact support if it still persists. Won’t be until later tonight (UK here) or over weekend

@warrenbuckley

This comment has been minimized.

Copy link
Author

commented Jun 1, 2019

So the following works:

  • ProBot listen/receives to the PR WebHook payload
  • This uses GitHub API to create a Check
  • ProBot hears the Check Created WebHook payload
  • We then attempt to set the start time and set the check to be in progress and do a GitHub API

It is this second GitHub API call to update the existing check that fails @gr2m

So to me it does not seem to be Auth issues as ProBot can hear the WebHook payloads all OK and was able to create the initial check via the GitHub API?!

    const repoOwner = context.payload.repository.owner.login;
    const repoName = context.payload.repository.name;
    const checkRunId = context.payload.check_run.id;

    const startTime = new Date();

    app.log('GitHub API Update Check with start time');

    // Update the check with in-progress state & date-time stamp
    await context.github.checks.update({
      owner: repoOwner,
      repo: repoName,
      check_run_id: checkRunId,
      status: "in_progress",
      started_at: startTime.toISOString()
    });
@gr2m

This comment has been minimized.

Copy link
Contributor

commented Jun 2, 2019

Could you try to add delay before creating the context.github.checks.update() call? I was told by support that in some cases there might be a replication lag for auth tokens. So when probot creates a token for the installation that it receives the webhook for, it might not yet have replicated to the place it’s check for when handling the check run requests.

This is not ideal but give it a try to see if it works, it might at least narrow down the problem

@warrenbuckley

This comment has been minimized.

Copy link
Author

commented Jun 3, 2019

Hi @gr2m thanks for the update
I will try when I am back off holiday (away this week) so if we can still keep this open so I can report findings that would be awesome :)

Odd thing is that this has worked previously...

@warrenbuckley

This comment has been minimized.

Copy link
Author

commented Jun 8, 2019

Changed code snippet as follows:

context.github.checks.update(
{
  owner: repoOwner,
  repo: repoName,
  check_run_id: checkRunId,
  status: "in_progress",
  started_at: startTime.toISOString()
}).then(function(value){
  app.log('data', value.data);
  app.log('headers', value.headers);
  app.log('status', value.status);
}).catch(reason => {
  app.log('reason', reason);
});

OK the odd thing here is that the check is updated correctly AFAIK according to this output (to be in progress) and I get a HTTP 200 OK and the other data returned all seems fine.

10:24:32.274Z  INFO probot:
  data { id: 144516167,
    node_id: 'MDg6Q2hlY2tSdW4xNDQ1MTYxNjc=',
    head_sha: '2a10d6cb914db41c71850abd2fe5d7fa65d8f3b7',
    external_id: '',
    url:
     'https://api.github.com/repos/warrenbuckley/Checks-Linting-Testing/check-runs/144516167',
    html_url:
     'https://github.com/warrenbuckley/Checks-Linting-Testing/runs/144516167',
    details_url: 'https://github.com/umbraco/vale-linter',
    status: 'in_progress',
    conclusion: null,
    started_at: '2019-06-08T10:24:31Z',
    completed_at: null,
    output:
     { title: null,
       summary: null,
       text: null,
       annotations_count: 0,
       annotations_url:
        'https://api.github.com/repos/warrenbuckley/Checks-Linting-Testing/check-runs/144516167/annotations' },
    name: 'Markdown Doc Lint',
    check_suite: { id: 135769754 },
    app:
     { id: 30393,
       node_id: 'MDM6QXBwMzAzOTM=',
       owner:
        { login: 'warrenbuckley',
          id: 1389894,
          node_id: 'MDQ6VXNlcjEzODk4OTQ=',
          avatar_url: 'https://avatars0.githubusercontent.com/u/1389894?v=4',
          gravatar_id: '',
          url: 'https://api.github.com/users/warrenbuckley',
          html_url: 'https://github.com/warrenbuckley',
          followers_url: 'https://api.github.com/users/warrenbuckley/followers',
          following_url:
           'https://api.github.com/users/warrenbuckley/following{/other_user}',
          gists_url: 'https://api.github.com/users/warrenbuckley/gists{/gist_id}',
          starred_url:
           'https://api.github.com/users/warrenbuckley/starred{/owner}{/repo}',
          subscriptions_url: 'https://api.github.com/users/warrenbuckley/subscriptions',
          organizations_url: 'https://api.github.com/users/warrenbuckley/orgs',
          repos_url: 'https://api.github.com/users/warrenbuckley/repos',
          events_url:
           'https://api.github.com/users/warrenbuckley/events{/privacy}',
          received_events_url: 'https://api.github.com/users/warrenbuckley/received_events',
          type: 'User',
          site_admin: false },
       name: 'Vale Linter',
       description:
        'An internal only bot for Umbraco CMS to be used with the Umbraco Documentation Repo to help lint the markdown files using the vale CLI tool.',
       external_url: 'https://github.com/umbraco/vale-linter',
       html_url: 'https://github.com/apps/vale-linter',
       created_at: '2019-05-09T14:48:49Z',
       updated_at: '2019-05-30T13:56:35Z',
       permissions:
        { checks: 'write',
          contents: 'read',
          metadata: 'read',
          pull_requests: 'write' },
       events: [ 'check_run', 'check_suite', 'pull_request' ] },
    pull_requests: [] }
10:24:32.284Z  INFO probot:
  headers { 'access-control-allow-origin': '*',
    'access-control-expose-headers':
     'ETag, Link, Location, Retry-After, X-GitHub-OTP, X-RateLimit-Limit, X-RateLimit-Remaining, X-RateLimit-Reset, X-OAuth-Scopes, X-Accepted-OAuth-Scopes, X-Poll-Interval, X-GitHub-Media-Type',
    'cache-control': 'private, max-age=60, s-maxage=60',
    connection: 'close',
    'content-encoding': 'gzip',
    'content-security-policy': 'default-src \'none\'',
    'content-type': 'application/json; charset=utf-8',
    date: 'Sat, 08 Jun 2019 10:24:22 GMT',
    etag: 'W/"a59c9aee9534b84ed08f54fc28d2a2aa"',
    'referrer-policy': 'origin-when-cross-origin, strict-origin-when-cross-origin',
    server: 'GitHub.com',
    status: '200 OK',
    'strict-transport-security': 'max-age=31536000; includeSubdomains; preload',
    'transfer-encoding': 'chunked',
    vary:
     'Accept, Authorization, Cookie, X-GitHub-OTP, Accept-Encoding',
    'x-content-type-options': 'nosniff',
    'x-frame-options': 'deny',
    'x-github-media-type': 'github.antiope-preview; format=json',
    'x-github-request-id': 'D2BE:2009B:5637D0F:6C4D7B0:5CFB8CD6',
    'x-ratelimit-limit': '5000',
    'x-ratelimit-remaining': '4976',
    'x-ratelimit-reset': '1559993062',
    'x-xss-protection': '1; mode=block' }
10:24:32.288Z  INFO probot: status 200

However directly before this log output from the promise being returned I get the following errors in the console being reported to me. Is this more a library thing with Octokit/Rest JS api itself @gr2m ?

10:24:31.199Z  INFO probot: POST http://localhost:3000/ - 200
10:24:31.703Z  INFO probot: Reacting to a Check Run Created payload
{ Deprecation: [@octokit/request] `error.code` is deprecated, use `error.status`.
    at HttpError.get (C:\Code-Personal\_Docker-Playground\vale-linter\probot-app\node_modules\@octokit\request\lib\http-error.js:18:17)
    at Object.Logger.stdSerializers.err (C:\Code-Personal\_Docker-Playground\vale-linter\probot-app\node_modules\bunyan\lib\bunyan.js:1148:19)
    at C:\Code-Personal\_Docker-Playground\vale-linter\probot-app\node_modules\bunyan\lib\bunyan.js:873:50
    at Array.forEach (<anonymous>)
    at Logger._applySerializers (C:\Code-Personal\_Docker-Playground\vale-linter\probot-app\node_modules\bunyan\lib\bunyan.js:865:35)
    at mkRecord (C:\Code-Personal\_Docker-Playground\vale-linter\probot-app\node_modules\bunyan\lib\bunyan.js:978:17)
    at Logger.error (C:\Code-Personal\_Docker-Playground\vale-linter\probot-app\node_modules\bunyan\lib\bunyan.js:1044:19)
    at Application.<anonymous> (C:\Code-Personal\_Docker-Playground\vale-linter\probot-app\node_modules\probot\lib\application.js:159:33)
    at step (C:\Code-Personal\_Docker-Playground\vale-linter\probot-app\node_modules\probot\lib\application.js:43:23)
    at Object.throw (C:\Code-Personal\_Docker-Playground\vale-linter\probot-app\node_modules\probot\lib\application.js:24:53)
    at rejected (C:\Code-Personal\_Docker-Playground\vale-linter\probot-app\node_modules\probot\lib\application.js:16:65) name: 'Deprecation' }
10:24:32.000Z ERROR event: Not Found (id=944e1570-89d7-11e9-959c-1d187ff90491)
  HttpError: Not Found
      at response.text.then.message (C:\Code-Personal\_Docker-Playground\vale-linter\probot-app\node_modules\@octokit\request\lib\request.js:56:27)
      at process._tickCallback (internal/process/next_tick.js:68:7)
  --
  event: {
    "event": "check_run.created",
    "id": "944e1570-89d7-11e9-959c-1d187ff90491",
    "installation": 940633,
    "repository": "warrenbuckley/Checks-Linting-Testing"
  }
10:24:32.003Z ERROR probot: Not Found
  HttpError: Not Found
      at response.text.then.message (C:\Code-Personal\_Docker-Playground\vale-linter\probot-app\node_modules\@octokit\request\lib\request.js:56:27)
      at process._tickCallback (internal/process/next_tick.js:68:7)
10:24:32.004Z  INFO http: POST / 500 - 624.79 ms (id=51403226-c1ac-46ef-8b27-a2efcc283045)
10:24:32.006Z ERROR probot: Internal Server Error
  Error: Internal Server Error
      at Request.callback (C:\Code-Personal\_Docker-Playground\vale-linter\probot-app\node_modules\superagent\lib\node\index.js:706:15)
      at IncomingMessage.parser (C:\Code-Personal\_Docker-Playground\vale-linter\probot-app\node_modules\superagent\lib\node\index.js:916:18)
      at IncomingMessage.emit (events.js:194:15)
      at IncomingMessage.EventEmitter.emit (domain.js:441:20)
      at endReadableNT (_stream_readable.js:1125:12)
      at process._tickCallback (internal/process/next_tick.js:63:19)

I have tried your suggestion now by putting in a wait of 5000ms before we update the check to be in progress after receiving the created check payload in Probot & still get the same results of an error being reported as above but the final check response is a HTTP 200 OK

Package.json

Here is the package.json for reference:

{
  "name": "vale-linter",
  "version": "1.0.0",
  "description": "A Probot app",
  "author": "Warren Buckley <warren@umbraco.com>",
  "license": "ISC",
  "repository": "https://github.com//vale-linter.git",
  "homepage": "https://github.com//vale-linter",
  "bugs": "https://github.com//vale-linter/issues",
  "keywords": [
    "probot",
    "github",
    "probot-app"
  ],
  "scripts": {
    "build": "tsc -p tsconfig.json",
    "dev": "nodemon --exec \"npm start\"",
    "start": "probot run ./lib/index.js",
    "lint": "standard **/*.ts --fix",
    "test": "jest && standard **/*.ts",
    "test:watch": "jest --watch --notify --notifyMode=change --coverage",
    "temp": "node ./lib/test.js"
  },
  "dependencies": {
    "@types/nock": "^9.3.0",
    "fs-extra": "^7.0.1",
    "nock": "^10.0.0",
    "probot": "^9.2.10"
  },
  "devDependencies": {
    "@types/fs-extra": "^5.1.0",
    "@types/jest": "^24.0.0",
    "@types/node": "^11.9.0",
    "@types/nodegit": "^0.24.6",
    "eslint-plugin-typescript": "^0.14.0",
    "jest": "^24.0.0",
    "nodemon": "^1.17.2",
    "smee-client": "^1.0.2",
    "standard": "^12.0.1",
    "ts-jest": "^24.0.0",
    "typescript": "^3.3.1",
    "typescript-eslint-parser": "^22.0.0"
  },
  "engines": {
    "node": ">= 8.3.0"
  },
  "standard": {
    "parser": "typescript-eslint-parser",
    "env": [
      "jest"
    ],
    "plugins": [
      "typescript"
    ]
  },
  "jest": {
    "testEnvironment": "node"
  }
}
@warrenbuckley

This comment has been minimized.

Copy link
Author

commented Jun 8, 2019

OK some more digging @gr2m

I performed npm outdated and saw probot as one of the outdated resources so immediate reaction is to update it, in order to see if this fixes the issue or not with

npm update --save/--save-dev

Followed by npm run build for the TypeScript scaffolded Probot template to generate the JS in the lib folder in order to us use the npm run dev to bootup the ProBot app for testing.

In doing so I get an error immediately when the app boots up now...

λ npm run dev

> vale-linter@1.0.0 dev C:\Code-Personal\_Docker-Playground\vale-linter\probot-app
> nodemon --exec "npm start"

[nodemon] 1.19.1
[nodemon] to restart at any time, enter `rs`
[nodemon] watching: *.*
[nodemon] starting `npm start`

> vale-linter@1.0.0 start C:\Code-Personal\_Docker-Playground\vale-linter\probot-app
> probot run ./lib/index.js

10:48:43.112Z  INFO probot: Booting up Vale Linter ProBot
10:48:43.442Z  INFO probot: Forwarding https://smee.io/8ImWYyeBwOLh0iD to http://localhost:3000/
10:48:43.446Z  INFO probot: Listening on http://localhost:3000
{ Deprecation: [@octokit/request-error] `error.code` is deprecated, use `error.status`.
    at RequestError.get (C:\Code-Personal\_Docker-Playground\vale-linter\probot-app\node_modules\@octokit\request-error\dist-node\index.js:29:17)
    at Object.Logger.stdSerializers.err (C:\Code-Personal\_Docker-Playground\vale-linter\probot-app\node_modules\bunyan\lib\bunyan.js:1148:19)
    at mkRecord (C:\Code-Personal\_Docker-Playground\vale-linter\probot-app\node_modules\bunyan\lib\bunyan.js:942:35)
    at Logger.error (C:\Code-Personal\_Docker-Playground\vale-linter\probot-app\node_modules\bunyan\lib\bunyan.js:1044:19)
    at process.Probot.errorHandler (C:\Code-Personal\_Docker-Playground\vale-linter\probot-app\node_modules\probot\lib\index.js:194:29)
    at process.emit (events.js:189:13)
    at process.EventEmitter.emit (domain.js:441:20)
    at emitPromiseRejectionWarnings (internal/process/promises.js:119:20)
    at process._tickCallback (internal/process/next_tick.js:69:34) name: 'Deprecation' }
10:48:43.684Z ERROR probot: 'Expiration time' claim ('exp') is too far in the future
  HttpError: 'Expiration time' claim ('exp') is too far in the future
      at response.text.then.message (C:\Code-Personal\_Docker-Playground\vale-linter\probot-app\node_modules\@octokit\request\dist-node\index.js:85:23)
      at process._tickCallback (internal/process/next_tick.js:68:7)
10:48:43.791Z  INFO probot: Connected https://smee.io/8ImWYyeBwOLh0iD

With the key error I can read from this is that
'Expiration time' claim ('exp') is too far in the future

@gr2m

This comment has been minimized.

Copy link
Contributor

commented Jun 9, 2019

That is very interesting! Thanks for the digging! The exp for the app’s JSON WEB TOKEN is calculated here:

https://github.com/octokit/app.js/blob/60ca3d97401e728790da68a0e13a1b2bbd1fc05e/src/get-signed-json-web-token.ts#L9

I wonder how this could end up too far in the future? Might the machine where you create the token have a wrong time set? Any idea?

GitHub
GitHub Apps toolset for Node.js. Contribute to octokit/app.js development by creating an account on GitHub.
@warrenbuckley

This comment has been minimized.

Copy link
Author

commented Jun 10, 2019

@gr2m hmmm 🤔 no my Laptop date/time is set correctly so I am really unsure. I think something has gone funky in this project at some point.

I am going to scaffold a new TypeScript ProBot from https://github.com/probot/create-probot-app and see if I can reproduce this or not.

Please hold...
Please Hold

GitHub
🤖📦 Create a new probot app. Contribute to probot/create-probot-app development by creating an account on GitHub.
@warrenbuckley

This comment has been minimized.

Copy link
Author

commented Jun 10, 2019

OK I can not reproduce the error with the JWT expiration token at boot, however I still can reproduce and run into the original error as reported @gr2m

I have pushed my rough proof of concept code to this repo here
https://github.com/warrenbuckley/vale-linter

I would appreciate if you can clone this and run this as a new app yourself to see if you can help me find the root cause of this problem.

The ProBot/GitHub App I am now testing with the newly scaffolded TypeScript is
https://github.com/apps/vale-linter
ID: 32646

Cheers,
Warren 😄

GitHub
A GitHub bot built with ProBot to lint PRs using the Vale tool - warrenbuckley/vale-linter
GitHub
GitHub is where people build software. More than 36 million people use GitHub to discover, fork, and contribute to over 100 million projects.
@warrenbuckley

This comment has been minimized.

Copy link
Author

commented Jun 12, 2019

Closing this issue as embarrassingly it was a mistake by me & was not due to creating the updated check as I first thought, but trying to get a file with the GitHub Octokit rest.js API which did not exist (typo in path from the config yml file)

However still getting the error occasionally regarding the JWT time too far in future. Will see if I can get more details on that & make sure its not a dumb thing from me first & if not I will create a new issue @gr2m

Embarrassed
Embarrassed

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
2 participants
You can’t perform that action at this time.