Node worker did not start properly ('30' second timeout)

[sschutten]

I have a Logic App Standard workflow that includes the Inline Code action. Starting this week I get the following exception when I try to run the logic app locally. This used to work fine for at least a week or three. I don't know what changed or what I can do to further investigate. I verified I have the right NodeJS version installed.

VS Code version: 1.68.1
Node.js: 16.13.0
Azure Logic Apps (Standard) extension: 1.0.19
Function Runtime Version: 4.0.1.1681
OS: Windows_NT x64 10.0.19044

[2022-07-05T12:50:46.957Z] Host lock lease acquired by instance ID '000000000000000000000000A3ABDEE2'.
[2022-07-05T12:51:12.987Z] Workflow Error: operationName='WorkflowDefinitionProvider.ProcessWorkflow', message='Workflow 'SendTagReport' validate and create workflow operation failed, the exception is 'The input 
parameter 'code' for inline code action 'E-mail_body' contains invalid code. Parsing the code failed with 
error 'Node worker did not start properly ('30' second timeout).'.'', exception='Microsoft.Azure.Workflows.Common.ErrorResponses.ErrorResponseMessageException: The input parameter 'code' for inline code action 'E-mail_body' contains invalid code. Parsing the code failed with error 'Node worker did not start properly 
('30' second timeout).'.
[2022-07-05T12:51:12.989Z]  ---> Microsoft.Azure.Workflows.Common.ErrorResponses.ErrorResponseMessageException: Node worker did not start properly ('30' second timeout).
[2022-07-05T12:51:12.991Z]    at Microsoft.Azure.Workflows.Languages.Edge.JScript.Engines.NodeProcessHandler.StartNodeProcess()
[2022-07-05T12:51:12.993Z]    at Microsoft.Azure.Workflows.Languages.Edge.JScript.Engines.NodeProcessHandler.StartNodeProcessIfNotStarted()
[2022-07-05T12:51:12.994Z]    at Microsoft.Azure.Workflows.Languages.Edge.JScript.Engines.JavascriptAnalysisEngine.FindDependencies(String actionName, String javascript)
[2022-07-05T12:51:12.996Z]    at Microsoft.Azure.Workflows.Web.Engines.EdgeFlowWebManagementEngine.GetActionDependencies(String actionName, String actionCode)
[2022-07-05T12:51:12.998Z]    --- End of inner exception stack trace ---
[2022-07-05T12:51:12.999Z]    at Microsoft.Azure.Workflows.Web.Engines.EdgeFlowWebManagementEngine.GetActionDependencies(String actionName, String actionCode)
[2022-07-05T12:51:13.001Z]    at Microsoft.Azure.Workflows.Web.Engines.EdgeFlowWebManagementEngine.<GetInlineCodeActionsGeneratedDependencies>b__10_3(KeyValuePair`2 actionKvp)
[2022-07-05T12:51:13.003Z]    at Microsoft.WindowsAzure.ResourceStack.Common.Extensions.ConcurrencyExtensions.AggregateOperationsConcurrently[TElement,TResult,TAccumulate](IEnumerable`1 source, Func`2 operation, 
TAccumulate seed, Func`3 accumulator, Int32 concurrencyLimit, CancellationToken cancellationToken)        
[2022-07-05T12:51:13.005Z]    at Microsoft.Azure.Workflows.Web.Engines.EdgeFlowWebManagementEngine.GetInlineCodeActionsGeneratedDependencies(FlowPropertiesDefinition definition)
[2022-07-05T12:51:13.006Z]    at Microsoft.Azure.Workflows.Web.Engines.EdgeFlowWebManagementEngine.GetTemplateRuntimeContext(FlowPropertiesDefinition definition, String flowName, Flow existingFlow, EdgeConnectionReferencesDefinition edgeConnectionReferencesDefinition)
[2022-07-05T12:51:13.008Z]    at Microsoft.Azure.Workflows.Web.Engines.EdgeFlowWebManagementEngine.ValidateAndCreateFlow(String flowName, FlowPropertiesDefinition flowPropertiesDefinition)
[2022-07-05T12:51:13.010Z]    at Microsoft.WindowsAzure.ResourceStack.Common.Algorithms.AsyncRetry.Retry(Func`1 action, Int32 retryCount, TimeSpan retryInterval, CancellationToken cancellationToken, Nullable`1 retryTimeout, Func`2 isRetryable, Action`1 errorAction, Func`2 retryAfter)
[2022-07-05T12:51:13.012Z]    at Microsoft.WindowsAzure.ResourceStack.Common.Algorithms.AsyncRetry.Retry(Func`1 action, Int32 retryCount, TimeSpan retryInterval, CancellationToken cancellationToken, Nullable`1 retryTimeout, Func`2 isRetryable, Action`1 errorAction, Func`2 retryAfter)
[2022-07-05T12:51:13.014Z]    at Microsoft.Azure.Workflows.WebJobs.Extensions.Initialization.WorkflowFunctionDefinitionProvider.ProcessWorkflow(FlowFunction flowFunction, ConcurrentDictionary`2 flowsProcessed)', 
extensionVersion='1.0.0.0', siteName='UNDEFINED_SITE_NAME', slotName='', activityId='ef07a91a-8c90-4665-8db4-15909fc495f0'.

[MeatFacer]

I am having the same problem. Has anyone been able to solve this problem?
Creating a javascript action in the portal also doesn't work for me. I get the error "Workflow validation failed for the workflow" after saving a workflow when a javascript action is included.

[TonnyWildeman]

I found a workaround. I figured it out by opening up Microsoft.Azure.Workflows.Languages.Edge.JScript.Engines.dll and the class NodeProcessHandler. I found that out by increasing the log level for the func.exe by adding AzureFunctionsJobHost__logging__LogLevel__Default: Trace in local.settings.json.

You could run the Analysis server yourself and have the port in the local.settings.json.

• choose any tcp port number that is not opened
• add "LogicAppsNodePort": <your port number> to your local.settings.json
• open a terminal and go to the following folder: {cwd}/bin/Debug/netcoreapp3.1\JS\Analysis
• run node with the command: node index.js <your port number> 30000

the last number is the timeout in milliseconds for the js analysis service. You could increase that if you want. I suspect the timeout is not passed along properly.

edit: had to escape some characters

[TonnyWildeman]

So, I dug a little deeper and found the reason why the node js analysis service is not starting.
The code is being called with the following cmd line:

 node index.js 60461 334681,4167

In index.js the line

let timeout = setTimeout(() => process.kill(process.pid, 'SIGTERM'), timeoutDurationInMilliseconds);

immediately invokes, because the string 334681,4167 is being converted due to implicit type coercion to 0. Thus invoke immediately:
https://developer.mozilla.org/en-US/docs/Web/API/setTimeout#non-number_delay_values_are_silently_coerced_into_numbers

[yoHasse]

I found a workaround. I figured it out by opening up Microsoft.Azure.Workflows.Languages.Edge.JScript.Engines.dll and the class NodeProcessHandler. I found that out by increasing the log level for the func.exe by adding AzureFunctionsJobHost__logging__LogLevel__Default: Trace in local.settings.json.

You could run the Analysis server yourself and have the port in the local.settings.json.

• choose any tcp port number that is not opened
• add "LogicAppsNodePort": to your local.settings.json
• open a terminal and go to the following folder: {cwd}/bin/Debug/netcoreapp3.1\JS\Analysis
• run node with the command: node index.js 30000

the last number is the timeout in milliseconds for the js analysis service. You could increase that if you want. I suspect the timeout is not passed along properly.

edit: had to escape some characters

Some extra information on this:

• Above works if you're logic app is nuget based.
• If not, then your analysis server should be located somwhere around:
  • windows: C:\Users\<user name>\.azure-functions-core-tools\Functions\ExtensionBundles\Microsoft.Azure.Functions.ExtensionBundle.Workflows\<version>\JS\Analysis

Do these steps as mentioned before:

• choose any tcp port number that is not opened
• add "LogicAppsNodePort": to your local.settings.json

Then:

• cd C:\Users\<user name>\.azure-functions-core-tools\Functions\ExtensionBundles\Microsoft.Azure.Functions.ExtensionBundle.Workflows\<bundle version>\JS\Analysis
• node index.js <your port number> 30000

[github-actions[bot]]

This issue is stale because it has been open for 30 days with no activity.

[msitsoftware]

I tried another workaround using WSL. That works fine for me. I installed all the necessary packages inside linux (currently I'm using Ubuntu 20.04). From Linux I'm going start VSCode and I have the same Developer experience. No problems with Inline Scripts!!

[timjansenortec]

With all the newest versions, it seems that a second node process is now started with a different command:
"node" "C:\Program Files\Microsoft\Azure Functions Core Tools\workers\node\dist/src/nodejsWorker.js" --host 127.0.0.1 --port 58215 --workerId 2804864d-bd59-427d-9937-8f654e67ae95 --requestId b6be4b8d-8ff9-4255-9bb6-e676f81e5ed6 --grpcMaxMessageLength 2147483647

The 'original' node is also still started, this still gives errors when running locally in VSCode
("node" index.js 58606 324138,5186)

FUNCTIONS_WORKER_RUNTIME does not seem to have any effect anymore.
I have not found any change in behavior yet when setting this to 'node', 'dotnet' or 'dotnet-isolated'.
I think this is because the way that workers are started has changed a lot with the introduction multi lang workers.

[andyheyns93]

VS Code version: 1.90.2
Node.js: 16.14.2 (64 bit)
Azure Logic Apps (Standard) extension: 4.25.1
Function Runtime Version: 4.0.5611
OS: Windows 11 - Version 23H2 (OS Build 22631.3737)

I still get this issue when running my workflow locally (attaching to vscode)

Workflow 'XXXXXXX' validation and creation failed. Error: 'One or more errors occurred. ('No connection could be made because the target machine actively refused it. (localhost:55294)'. Status code: 'InternalServerError'.) ('No connection could be made because the target machine actively refused it. (localhost:55294)'. Status code: 'InternalServerError'.) ('No connection could be made because the target machine actively refused it. (localhost:55294)'. Status code: 'InternalServerError'.) ('No connection could be made because the target machine actively refused it. (localhost:55294)'. Status code: 'InternalServerError'.)'

I have resolved this by using following (work-around):

1. Install 'forever' node module
   npm install forever -g

2. Update '.vscode/tasks.json' with following tasks
   { "type": "shell", "options": { "cwd": "${workspaceFolder}" }, "command": "forever stopall", "label": "clean-node-engine", "isBackground": true, "presentation": { "reveal": "never", "close": true } }, { "type": "shell", "options": { "cwd": "${workspaceFolder}" }, "command": "forever start -c \"node bin/Debug/net6.0/JS/Analysis/index.js 9999 30000\" ./", "dependsOn": [ "build", "clean-node-engine" ], "label": "run-node-engine" }
   Note: net6.0 is used above with 'LogicAppsNodePort' 9999 !

3. Update the 'dependsOn' of 'func: host start' in '.vscode/tasks.json'
   "dependsOn": [ "build", "run-node-engine" ],

4. Update 'local.settings.json'
   "LogicAppsNodePort": "9999"

5. Update '.vscode/launch.json'
   "postDebugTask": "clean-node-engine"

I want to clarify that I did no optimization for all these steps, just a basic workaround for not using following command each time after my LogicApp is being build.
node bin/Debug/net6.0/JS/Analysis/index.js 9999 30000

Other suggestions are welcome.