NodeJS - FailureException: Worker was unable to load function IsActiveSponsor: 'TypeError: isPlainObject is not a function'

[warrenbuckley]

Problem

After upgrading to the latest version 4.5.6 of @octokit/graphql a NodeJS serverless Azure Function now complains about
isPlainObject is not a function at Object.keys.forEach.key

If I revert the package.json dependency back to 4.5.4 then it continues to work as it once did.

This works fine locally with the Azure Functions CLI with VSCode, however once deployed to Azure it gives the following error and is tricky to debug further & pass info onto the NPM package owner of @octokit/graphql

Error

2020-09-21T19:59:05.569 [Information] Executing 'Functions.GithubIssue' (Reason='This function was programmatically called via the host APIs.', Id=d7811d3a-4ede-44c1-b9cf-2c59f48a126f)
2020-09-21T19:59:05.858 [Error] Executed 'Functions.GithubIssue' (Failed, Id=d7811d3a-4ede-44c1-b9cf-2c59f48a126f, Duration=287ms)Result: FailureException: Worker was unable to load function GithubIssue: 'TypeError: isPlainObject is not a function'Stack: TypeError: isPlainObject is not a functionat Object.keys.forEach.key (D:\home\site\wwwroot\node_modules\@octokit\endpoint\dist-node\index.js:24:9)
at Array.forEach (<anonymous>)at mergeDeep (D:\home\site\wwwroot\node_modules\@octokit\endpoint\dist-node\index.js:23:24)
at merge (D:\home\site\wwwroot\node_modules\@octokit\endpoint\dist-node\index.js:52:25)
at withDefaults (D:\home\site\wwwroot\node_modules\@octokit\endpoint\dist-node\index.js:348:20)
at Object.<anonymous> (D:\home\site\wwwroot\node_modules\@octokit\endpoint\dist-node\index.js:376:18)
at Module._compile (internal/modules/cjs/loader.js:778:30)at Object.Module._extensions..js (internal/modules/cjs/loader.js:789:10)at Module.load (internal/modules/cjs/loader.js:653:32)
at tryModuleLoad (internal/modules/cjs/loader.js:593:12)

This is the same error reported here but it seems specific to once the code is in the Azure Infrastructure as I am able to run this Azure Function locally on my machine with no issues & with little debugging information available it is hard to pass on repro steps to the package author.
octokit/graphql.js#195

Investigative information

Please provide the following:

• Timestamp: 2020-09-21 19:59:05.460
• Function App version: ~3
• Function App name: https://github-sponsor-check-deploy.azurewebsites.net
• Function name(s) (as appropriate): GithubIssue
• Operation ID: d2b6d677eb2dfb4fbc780a1325880718
• Invocation ID: d7811d3a-4ede-44c1-b9cf-2c59f48a126f
• Region: West Europe
• FUNCTIONS_EXTENSION_VERSION: ~3
• FUNCTIONS_WORKER_RUNTIME: node
• WEBSITE_NODE_DEFAULT_VERSION: ~10

Repro steps

1. Deploy the example code at the bottom of this issue
2. Verify it works locally in Azure Functions CLI
3. Deploy/push to Azure Functions
4. Verify you get the same error with

Expected behaviour

• The Azure Function to execute without errors

Actual behaviour

• Throws the error in the Azure Portal when testing invocation of HTTP Trigger

Related information

Provide any related information

• Programming language use: NodeJS
• Links to source: https://github.com/warrenbuckley/Is-Github-Sponsor/blob/master/GithubIssue/index.ts
• Deployed via GitHub Action - https://github.com/warrenbuckley/Is-Github-Sponsor/runs/1130600068?check_suite_focus=true#step:5:1

function.json

{
  "bindings": [
    {
      "authLevel": "anonymous",
      "type": "httpTrigger",
      "direction": "in",
      "name": "req",
      "methods": [
        "get",
        "post"
      ]
    },
    {
      "type": "http",
      "direction": "out",
      "name": "res"
    }
  ],
  "scriptFile": "../dist/GithubIssue/index.js"
}

Source

import { Context, HttpRequest } from "@azure/functions"
import { graphql } from "@octokit/graphql";

// Azure Function HTTP Trigger entry point
export default async function (context: Context, req: HttpRequest): Promise<void> {
  const userToken = (req.query.token || (req.body && req.body.token));
  const graphqlWithAuth = graphql.defaults({
    headers: {
      authorization: `token ${userToken}`,
    },
  });

  try {
    const data = await graphqlWithAuth(`{
        viewer {
          login
        }
      }`);

    console.log(data);
    context.res = {
        status: 200,
        body: data
    }
  }
  catch (error) {
    context.res = {
        status: error.status,
        body: error.message
    };
  }

  context.done();
}

[pragnagopa]

@mhoeger - transferring this issue to node worker repo. Please investigate. Thanks!

[mhoeger]

Hi @warrenbuckley ! Sorry for the delay. I'm having a busy week and haven't had time to try to repro this on my own, but one thing to check out is the Kudu portal to see if there's anything odd about your node modules?

You can go to Kudu by going to: https://github-sponsor-check-deploy.scm.azurewebsites.net/ and "Debug Console" => CMD, cd site\wwwroot in the terminal

[warrenbuckley]

I have checked the folder contents in Kudu and the node_modules folder seems to be fine @mhoeger
Hopefully you can investigate soon, so we can find the cause of this problem so I can pass back any info to the package author @gr2m of @octokit/graphql

[warrenbuckley]

@mhoeger is there any update on this at all please?

[mhoeger]

Hi @warrenbuckley ! I can't repro your issue :/ I'm using your same code and GitHub actions and am able to see things working here:
Main site:
https://mahoeger-octokit.azurewebsites.net/IsActiveSponsor
Deployment slot:
https://mahoeger-octokit-deploy.azurewebsites.net/IsActiveSponsor

[mhoeger]

Is there anything specific about your environment you've changed? Ex: under "Configuration" => "General settings" => "Platform settings"? Ex: My platform is 32-bit

[warrenbuckley]

Hi @mhoeger thanks for getting back to me
Here is a screenshot of the General Settings - mine also shows as 32Bit too, this is currently in production & being used so ideally I do not want to roll out a new Azure Function resource if I have to.

General Settings

So this seems that it could be very specific to my Azure Function & environment for it, if it can not be reproduced.
Are you able to debug or diagnose my Azure Function environment directly to see what maybe causing the problem?

Next steps

I will try and setup a new azure function resource and re-deploy it, but I am sure I will have the same experience as you Marie

Question

Does the Azure Function team have any better tooling or ways for developers to debug Azure Functions or attach to the remote process at all, in order to see what is going on? Or is my only tool available to me is to see the logs for the function in the portal & try and figure out what is going on.

[mhoeger]

Thanks @warrenbuckley ! If you could try too that would be great. The "Kudu" (scm) site is a good place to debug, although please also be careful because what you see is what is running in production. What I would do is make changes to the IsActiveSponsor even directly in code. Unfortunately we don't have remote debugging for node enabled yet :\ so adding print statements in deployed code or before deployment is probably going to be the next best thing? Note that "console.log" logs will still make it to your logs - it just won't be tied to a specific function execution

[warrenbuckley]

Azure Resource Settings & Region

Logs from VSCode deploy via extension

Deployed this way to save time setting up connecting a new GitHub Action pipeline to deploy to the test Azure Function App

09:01:36 github-issue-335: Added app setting "WEBSITE_RUN_FROM_PACKAGE" to improve performance of function app. Learn more here: https://aka.ms/AA8vxc0
09:01:40 github-issue-335: Starting deployment...
09:01:40 github-issue-335: Creating zip package...
09:01:41 github-issue-335: Zip package size: 140 kB
09:01:47 github-issue-335: Updating submodules.
09:01:47 github-issue-335: Preparing deployment for commit id '0fb2c136bd'.
09:01:48 github-issue-335: Skipping build. Project type: Run-From-Zip
09:01:48 github-issue-335: Skipping post build. Project type: Run-From-Zip
09:01:49 github-issue-335: Triggering recycle (preview mode disabled).
09:02:04 github-issue-335: Deployment successful.
09:02:18 github-issue-335: Started postDeployTask "npm install".
09:02:28 github-issue-335: Syncing triggers...
09:02:44 github-issue-335: Querying triggers...
09:02:47 github-issue-335: HTTP Trigger Urls:
  GithubIssue: https://github-issue-335.azurewebsites.net/GithubIssue
  IsActiveSponsor: https://github-issue-335.azurewebsites.net/IsActiveSponsor
09:02:54 github-issue-335: Uploading settings...
09:02:54: Added the following settings:
- GITHUB_SPONSOR_USER_TO_VERIFY
- GITHUB_ORG_TO_VERIFY
- GITHUB_REPO_HAS_CONTRIBS
09:02:54: Ignored the following settings that were already the same:
- FUNCTIONS_WORKER_RUNTIME
09:02:54: WARNING: This operation will not delete any settings in "github-issue-335". You must manually delete settings if desired.
09:02:57 github-issue-335: Successfully uploaded settings.

As suspected I cannot reproduce the error/problem.
https://github-issue-335.azurewebsites.net/IsActiveSponsor

Easy to migrate?

Is there an easy way for me to migrate away from my faulty Azure Function to a new Azure Function?

• Use the same custom domain name attached to it
• Use the same ApplicationInsights to collect data

[warrenbuckley]

Closed this @mhoeger as I managed to create a new Azure Function that is not freaking out on me & still deploys via GH Actions & transferred the domain over to this new function.

Thanks for looking into this - if this ever comes up again (doubt it will) I will re-open this issue 😄

[mhoeger]

Sorry we weren't able to diagnose the weird behavior, please do re-open if you run into it again!

[gpj-dsonnleithner]

Hello,

I had a similar issue as described here: My code worked well on my local machine (using VS Studio) however failed on Azure with weird error messages reporting that modules (not always the same!) couldn´t be loaded.

For the record one such error message:
Result: Failure Exception: Worker was unable to load function mailWatchDog: 'Error: Cannot find module 'qs' Require stack: - C:\home\site\wwwroot\common\MsGraphMail.js - C:\home\site\wwwroot\common\MailLogger.js - C:\home\site\wwwroot\mailWatchDog\index.js - C:\Program Files (x86)\SiteExtensions\Functions\3.1.3\workers\node\worker-bundle.js - C:\Program Files (x86)\SiteExtensions\Functions\3.1.3\workers\node\dist\src\nodejsWorker.js' Stack: Error: Cannot find module 'qs' Require stack: - C:\home\site\wwwroot\common\MsGraphMail.js - C:\home\site\wwwroot\common\MailLogger.js - C:\home\site\wwwroot\mailWatchDog\index.js - C:\Program Files (x86)\SiteExtensions\Functions\3.1.3\workers\node\worker-bundle.js - C:\Program Files (x86)\SiteExtensions\Functions\3.1.3\workers\node\dist\src\nodejsWorker.js at Function.Module._resolveFilename (internal/modules/cjs/loader.js:880:15) at Function.Module._load (internal/modules/cjs/loader.js:725:27) at Module.require (internal/modules/cjs/loader.js:952:19) at require (internal/modules/cjs/helpers.js:88:18) at Object.<anonymous> (C:\home\site\wwwroot\common\MsGraphMail.js:10:12) at Module._compile (internal/modules/cjs/loader.js:1063:30) at Object.Module._extensions..js (internal/modules/cjs/loader.js:1092:10) at Module.load (internal/modules/cjs/loader.js:928:32) at Function.Module._load (internal/modules/cjs/loader.js:769:14) at Module.require (internal/modules/cjs/loader.js:952:19)

Maybe this "solution" is helpful to others that stumble upon this issue:

Instead of re-instantiating a new Azure Function instance as described by @warrenbuckley , I stopped and restarted the Function App (Restart was not enough).

This resolved my issue magically (no change in code).

[Naktibalda]

I got a similar issue too:

TypeError: Worker was unable to load entry point "dist/src/functions/index.js": toSource is not a function

It turned out that deployment failed and broke the app.
Luckily it didn't happen in production.

Deployment failed with this error

Deployment has been stopped due to SCM container restart. The restart can happen due to a management operation on site. Do not perform a management operation and a deployment operation in quick succession. Adding a small delay can help avoid any conflicts.

Probably because DevOps guy was applying infrastructure changes at the same time.