Not able to run function locally

[Nagendra Singh]

I upgraded plugin to support functions.

Installed docker for mac.

Upgraded sfdx plugin to latest.

Created Salesforce Java function from Illuminated cloud.

But when I start the function locally it shows this error in console.

/usr/local/bin/sf run function start -p 8080 -b 9229
Building javafn
Error: spawn /usr/local/lib/node_modules/@salesforce/cli/node_modules/@her
oku/functions-core/bin/benny-darwin ENOENT
Code: ENOENT

‌

And in idea logs I can only see these.

‌

‌

2021-10-12 09:10:14,797 [  52838]   INFO - ellij.license.LicenseValidator - Server license validation result was Genuine. 
2021-10-12 09:10:14,797 [  52838]   INFO - ellij.license.LicenseValidator - Illuminated Cloud features are enabled. 
2021-10-12 09:10:14,848 [  52889]   INFO - .services.SpaceKtsFileDetector - SpaceKtsFileDetector 
2021-10-12 09:10:14,848 [  52889]   INFO - edCloudStartupVersionValidator - Successfully referenced EmbeddedMarkupUtil when project 'ByjusUAAT' was opened. 
2021-10-12 09:10:14,970 [  53011]   INFO - luminatedCloudFileTypeRegistry - Registering external resources http://soap.sforce.com/2006/04/metadata and urn:metadata.tooling.soap.sforce.com as /Users/nagendrasingh/Library/Application Support/JetBrains/IntelliJIdea2021.2/plugins/IlluminatedCloud2/lib/IlluminatedCloud.jar!/xsd/metadata.xsd. 
2021-10-12 09:10:15,050 [  53091]   INFO - tellij.xml.Html5SchemaProvider - HTML5_SCHEMA_LOCATION = /Applications/IntelliJ IDEA.app/Contents/lib/platform-impl.jar!/resources/html5-schema/html5.rnc 
2021-10-12 09:10:15,744 [  53785]   INFO - luminatedCloudConnectionConfig - Retrieving org list from Salesforce CLI. 
2021-10-12 09:10:15,745 [  53786]   INFO - luminatedCloudConnectionConfig - Retrieving org list information from Salesforce CLI. 
2021-10-12 09:10:50,183 [  88224]   INFO - rationStore.ComponentStoreImpl - Saving appFileTypeManager took 11 ms 
2021-10-12 09:10:51,133 [  89174]   INFO - rationStore.ComponentStoreImpl - Saving Project(name=functionsDemo, containerState=COMPONENT_CREATED, componentStore=/Users/nagendrasingh/IdeaProjects/functionsDemo)RunManager took 50 ms 
2021-10-12 09:10:51,295 [  89336]   INFO - rationStore.ComponentStoreImpl - Saving Project(name=sfdc, containerState=COMPONENT_CREATED, componentStore=/Users/nagendrasingh/IdeaProjects/sfdc)RunManager took 12 ms 
2021-10-12 09:10:51,382 [  89423]   INFO - rationStore.ComponentStoreImpl - Saving Project(name=ByjusUAAT, containerState=COMPONENT_CREATED, componentStore=/Users/nagendrasingh/IdeaProjects/ByjusUAAT)KotlinCommonCompilerArguments took 11 ms, RunManager took 12 ms 
2021-10-12 09:10:51,415 [  89456]   INFO - mponents.impl.stores.StoreUtil - saveProjectsAndApp took 1350 ms 
2021-10-12 09:10:52,551 [  90592]   INFO - rationStore.ComponentStoreImpl - Saving appFileTypeManager took 15 ms 
2021-10-12 09:10:54,270 [  92311]   INFO - rationStore.ComponentStoreImpl - Saving Project(name=sfdc, containerState=COMPONENT_CREATED, componentStore=/Users/nagendrasingh/IdeaProjects/sfdc)RunManager took 12 ms 
2021-10-12 09:10:54,357 [  92398]   INFO - mponents.impl.stores.StoreUtil - saveProjectsAndApp took 1930 ms 
2021-10-12 09:10:54,478 [  92519]   INFO - rationStore.ComponentStoreImpl - Saving appFileTypeManager took 12 ms 
2021-10-12 09:10:54,549 [  92590]   INFO - rationStore.ComponentStoreImpl - Saving Project(name=sfdc, containerState=COMPONENT_CREATED, componentStore=/Users/nagendrasingh/IdeaProjects/sfdc)Kotlin2JvmCompilerArguments took 23 ms 
2021-10-12 09:11:02,538 [ 100579]   WARN - ctionSystem.impl.ActionUpdater - Slow (134 ms) `com.jetbrains.performancePlugin.actions.CaptureMemorySnapshotAction#update`. Consider speeding it up and/or implementing UpdateInBackground. 
2021-10-12 09:11:07,148 [ 105189]   INFO - rationStore.ComponentStoreImpl - Saving appFileTypeManager took 14 ms, IlluminatedCloudSettings took 12 ms 
2021-10-12 09:11:07,190 [ 105231]   INFO - rationStore.ComponentStoreImpl - Saving Project(name=functionsDemo, containerState=COMPONENT_CREATED, componentStore=/Users/nagendrasingh/IdeaProjects/functionsDemo)RunManager took 16 ms 
2021-10-12 09:11:34,536 [ 132577]   INFO - rationStore.ComponentStoreImpl - Saving appFileTypeManager took 18 ms 
2021-10-12 09:11:34,557 [ 132598]   INFO - rationStore.ComponentStoreImpl - Saving Project(name=functionsDemo, containerState=COMPONENT_CREATED, componentStore=/Users/nagendrasingh/IdeaProjects/functionsDemo)RunManager took 13 ms 
2021-10-12 09:12:10,163 [ 168204]   WARN - tLocalSalesforceFunctionAction - The process completed with exit code 1. Checking for known issues. 
2021-10-12 09:13:08,742 [ 226783]   WARN - tLocalSalesforceFunctionAction - The process completed with exit code 1. Checking for known issues. 
2021-10-12 09:15:24,020 [ 362061]   INFO - rationStore.ComponentStoreImpl - Saving appPluginAdvertiserExtensions took 11 ms, PluginFeatureService took 13 ms, TodoConfiguration took 57 ms 
2021-10-12 09:15:24,168 [ 362209]   INFO - rationStore.ComponentStoreImpl - Saving Project(name=functionsDemo, containerState=COMPONENT_CREATED, componentStore=/Users/nagendrasingh/IdeaProjects/functionsDemo)XDebuggerManager took 27 ms 

‌

‌

Detailed log:

‌

2021-10-12 09:37:25,996 [1684037]   INFO - lij.diagnostic.DebugLogManager - Set TRACE for the following categories: #com.jetbrains.rdserver.requests, #com.jetbrains.rd.ide.document, #com.jetbrains.rdserver.document, #com.jetbrains.rdserver.editors, #com.jetbrains.rdserver.actions, #com.jetbrains.rdserver.permissions 
2021-10-12 09:37:28,964 [1687005]   INFO - rationStore.ComponentStoreImpl - Saving appGeneralSettings took 39 ms, TodoConfiguration took 20 ms 
2021-10-12 09:37:58,183 [1716224]  DEBUG - tLocalSalesforceFunctionAction - Prompting for local execution configuration for function 'javafn'. 
2021-10-12 09:37:59,885 [1717926]  DEBUG - tLocalSalesforceFunctionAction - Starting the function with the following configuration: LocalExecutionConfiguration{port=8080, debugPort=9229, environmentVariables='', network='', verbose=false, clearCache=false, noPull=false} 
2021-10-12 09:37:59,890 [1717931]  DEBUG - tLocalSalesforceFunctionAction - Running 'sf run function start'. 
2021-10-12 09:37:59,890 [1717931]  DEBUG - .SalesforceFunctionCommandUtil - Setting the working directory to '/Users/nagendrasingh/IdeaProjects/trailheadsfdx/functions/javafn'. 
2021-10-12 09:37:59,890 [1717931]  DEBUG - .SalesforceFunctionCommandUtil - Executing command line: /usr/local/bin/sf [run, function, start, -p, 8080, -b, 9229] 
2021-10-12 09:38:08,246 [1726287]   WARN - tLocalSalesforceFunctionAction - The process completed with exit code 1. Checking for known issues. 
2021-10-12 09:38:08,447 [1726488]  DEBUG - tLocalSalesforceFunctionAction - Checking for a port conflict. 

‌

[Scott Wells]

You can enable debug logging for Salesforce Functions (at the bottom of that page), repeat the failure, and attach the new log.

Having said that, I've had quite a bit of trouble getting Java functions to run consistently in Docker on Mac, specifically on an M1 Mac Mini. I've reported that to Salesforce and they've logged an internal case to investigate it. My guess is that you'll be able to reproduce this outside of IC2 by doing the following from the command-line:

cd /path/to/project/functions/functionName
sf run function start -p 8080 -b 9229

Assuming that fails in the same manner, it's unfortunately an issue with Salesforce Functions that should probably be logged directly with Salesforce.

To help characterize it further, does it work if you create a JavaScript function and try to deploy that locally into Docker? If it fails in the same manner, I'd check your Docker install. If it works, though (and that's my suspicion), I think you're hitting the same Java/Docker/Mac function issues I've been seeing.

[Nagendra Singh]

I have attached the detailed log. Let me try with JS or TS in mean time.

[Nagendra Singh]

Same with Javascript too.

‌

2021-10-12 09:44:30,461 [2108502]  DEBUG - tLocalSalesforceFunctionAction - Prompting for local execution configuration for function 'javascriptfndemo'. 
2021-10-12 09:44:34,046 [2112087]  DEBUG - tLocalSalesforceFunctionAction - Starting the function with the following configuration: LocalExecutionConfiguration{port=8080, debugPort=9229, environmentVariables='', network='', verbose=false, clearCache=false, noPull=false} 
2021-10-12 09:44:34,052 [2112093]  DEBUG - tLocalSalesforceFunctionAction - Running 'sf run function start'. 
2021-10-12 09:44:34,052 [2112093]  DEBUG - .SalesforceFunctionCommandUtil - Setting the working directory to '/Users/nagendrasingh/IdeaProjects/trailheadsfdx/functions/javascriptfndemo'. 
2021-10-12 09:44:34,052 [2112093]  DEBUG - .SalesforceFunctionCommandUtil - Executing command line: /usr/local/bin/sf [run, function, start, -p, 8080, -b, 9229] 
2021-10-12 09:44:44,617 [2122658]   WARN - tLocalSalesforceFunctionAction - The process completed with exit code 1. Checking for known issues. 
2021-10-12 09:44:44,824 [2122865]  DEBUG - tLocalSalesforceFunctionAction - Checking for a port conflict. 
2021-10-12 09:54:49,789 [2727830]  DEBUG - tLocalSalesforceFunctionAction - Prompting for local execution configuration for function 'javascriptfndemo'. 
2021-10-12 09:54:51,463 [2729504]  DEBUG - tLocalSalesforceFunctionAction - Starting the function with the following configuration: LocalExecutionConfiguration{port=8080, debugPort=9229, environmentVariables='', network='', verbose=false, clearCache=false, noPull=false} 
2021-10-12 09:54:51,469 [2729510]  DEBUG - tLocalSalesforceFunctionAction - Running 'sf run function start'. 
2021-10-12 09:54:51,470 [2729511]  DEBUG - .SalesforceFunctionCommandUtil - Setting the working directory to '/Users/nagendrasingh/IdeaProjects/trailheadsfdx/functions/javascriptfndemo'. 
2021-10-12 09:54:51,470 [2729511]  DEBUG - .SalesforceFunctionCommandUtil - Executing command line: /usr/local/bin/sf [run, function, start, -p, 8080, -b, 9229] 
2021-10-12 09:55:01,074 [2739115]   WARN - tLocalSalesforceFunctionAction - The process completed with exit code 1. Checking for known issues. 
2021-10-12 09:55:01,280 [2739321]  DEBUG - tLocalSalesforceFunctionAction - Checking for a port conflict. 

For functions to work is it required that org should have functions enabled. Currently I cannot see an option to enable function in my developer edition “DevHub“.

I have even posted a question on Stackoverflow.

[Scott Wells]

I'm about to crash for the night and can continue to look into this tomorrow, but I'm definitely able to run functions locally in Docker without having the Functions feature enabled in the connected org. I just can't create a Heroku compute environment for remote function deployment and execution. All of the orgs I've been using are scratch orgs created from very simple configuration files, e.g.:

{
  "orgName": "salesforce_functions_ga",
  "edition": "Developer",
  "hasSampleData": false,
  "features": [
    "EnableSetPasswordInApi"
  ],
  "settings": {
    "lightningExperienceSettings": {
      "enableS1DesktopEnabled": true
    },
    "mobileSettings": {
      "enableS1EncryptedStoragePref2": false
    }
  }
}

I'm able to do that on Windows, Mac x64, Mac M1, and Linux successfully.

When you run sf run function start ... from the raw command-line, what output do you see? And again, it'll be tomorrow my time before I get a chance to look at this, but at least this will tee it for me.

[Nagendra Singh]

The strange part it, it works in windows perfectly fine. But same error keeps on occurring for Mac (Big Sur) OS.

So this might not be an issue with Illuminated cloud.

[Scott Wells]

It's very unlikely it's an IC2-specific issue, at least given the observed behavior. IC2 just runs the appropriate command-line to create/start/invoke/deploy a function, and the logs you've shown so far are just showing that the CLI command for deploying a function--specifically on Mac--is failing.

I noticed that the functions plugin was updated this morning (or perhaps last night) from 1.03 to 1.1.2. You might try running sf plugins update on your Mac to see whether perhaps Salesforce has already provided a fix. If not--and especially if this behavior is reproducible outside of IC2 directly from the command-line--it's definitely an issue with the sf run function start command. The real question is how best to report that to Salesforce right now...

[Nagendra Singh]

Yes the same is reproduced even from terminal.

Getting this error.

‌

Building functionsdemo
    Error: spawn /usr/local/lib/node_modules/@salesforce/cli/node_modules/@heroku/functions-core/bin/benny-darwin ENOENT
    Code: ENOENT

‌

[Scott Wells]

Okay. Just to make this 100% independent of IC2, please do the following:

cd /path/to/project/functions
sf generate function -n clirepro -l javascript
# Assuming that went fine, try to deploy this 100% unaltered function
cd clirepro
sf run function start -p 8080 -b 9229

Assuming that fails in the exact same manner, please provide the full output of the commands above, details about your exact Mac OS version, exact Node.js version, the output of sfdx --version and sf plugins, and anything else you think might be useful diagnostically. I'll provide all of that to my contacts at Salesforce to make them aware of the issue.

[Nagendra Singh]

It created the function properly but same error was thrown when I ran the function from terminal.

nagendrasingh@Nagendras-MacBook-Pro functionsdemo % cd ..
nagendrasingh@Nagendras-MacBook-Pro functions % sf generate function -n clirepro -l javascript
Created javascript function clirepro in /Users/nagendrasingh/IdeaProjects/byjusdevsfdx/functions/clirepro.
nagendrasingh@Nagendras-MacBook-Pro functions % sf run function start -p 8080 -b 9229
    Error: Invalid project.toml - File Not Found: ENOENT: no such file or directory, open '/Users/nagendrasingh/IdeaProjects/byjusdevsfdx/functions/project.toml'
     Hint: Are you in the correct working directory?
nagendrasingh@Nagendras-MacBook-Pro functions % cd clirepro 
nagendrasingh@Nagendras-MacBook-Pro clirepro % sf run function start -p 8080 -b 9229
Building clirepro
    Error: spawn /usr/local/lib/node_modules/@salesforce/cli/node_modules/@heroku/functions-core/bin/benny-darwin ENOENT
    Code: ENOENT

‌

Here are some details which may help in diagnosis.

SFDX version

nagendrasingh@Nagendras-MacBook-Pro clirepro % sfdx --version
sfdx-cli/7.121.8 darwin-x64 node-v14.18.0

SF Plugins:

nagendrasingh@Nagendras-MacBook-Pro clirepro % sf plugins
No plugins installed.

SF Plugin core:

nagendrasingh@Nagendras-MacBook-Pro clirepro % sf plugins --core
@oclif/plugin-help 5.1.1 (core)
@oclif/plugin-not-found 2.2.0 (core)
@oclif/plugin-plugins 2.0.1 (core)
@salesforce/cli 1.0.5 (core)
config 2.2.6 (core)
deploy-retrieve 1.0.3 (core)
deploy-retrieve-metadata 1.0.2 (core)
env 1.0.1 (core)
functions 1.0.3 (core)
generate 1.0.1 (core)
login 1.0.1 (core)
telemetry 1.2.6 (core)

Node Version:

nagendrasingh@Nagendras-MacBook-Pro clirepro % node -v
v14.17.6

NPM Version:

nagendrasingh@Nagendras-MacBook-Pro clirepro % npm version
{
  'clirepro-function': '0.0.1',
  npm: '6.14.15',
  ares: '1.17.2',
  brotli: '1.0.9',
  cldr: '39.0',
  icu: '69.1',
  llhttp: '2.1.3',
  modules: '83',
  napi: '8',
  nghttp2: '1.42.0',
  node: '14.17.6',
  openssl: '1.1.1l',
  tz: '2021a',
  unicode: '13.0',
  uv: '1.41.0',
  v8: '8.4.371.23-node.76',
  zlib: '1.2.11'
}

MAC OS:

Big Sur : Version 11.6

Docker for Mac

Docker Engine
v20.10.8

‌

[Scott Wells]

Thanks. That helps to isolate this to the core feature and not the IC2 functionality built atop that feature. And to be clear, I don't expect there not to be bugs in the IC2 Functions stuff, but I definitely want to make sure we're spending our diagnostic energies in the right place.

I'll pass this information on to the folks at Salesforce and hopefully they'll be able to provide some insight into what's going on. I'll keep you posted as I learn more.

[Scott Wells]

Resolving since this could be reproduced outside of IC2.

[Nagendra Singh]

This was a permission issue in MAC. I uninstalled Node and reinstalled it via brew and now it works fine even in MAC.

I pasted a detailed answer here too : https://salesforce.stackexchange.com/questions/359626/not-able-to-invoke-java-javascript-or-typescript-function-locally-mac-os

‌

[Scott Wells]

That's great to know. Thanks for sharing the details of the resolution!