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.