org.sonar.plugins.javascript.nodejs.NodeCommandException: Failed to start server

Rebse · September 18, 2023, 2:45pm

Hi,

i’m currently testing the latest Sonarlint for Eclipse 8.0.0.80157 with Eclipse 2023-06 on Windows 10
and Sonarqube Enterprise 9.9.0 LTS
nodeJS is on PATH, but after some time - in general the startup of Sonarlint consumes a lot of time compared with Sonarlint for Eclipse 7.12.0.72679 we use right now in production - an error dialog appears

The Sonarlint console verbose output has

Initializing SonarLint backend…
Starting SonarLint for Eclipse 8.0.0.80157
Starting SonarLint engine for connection ‘sonar’…
Node.js path provided by configuration: C:\Program Files\nodejs\node.exe
Checking node version…
Execute command ‘C:\Program Files\nodejs\node.exe -v’…
[…]
Starting server
No workDir in SonarLint
Running in SonarLint context, metrics will not be computed.
Using Node.js executable C:\Program Files\nodejs\node.exe from property sonar.nodejs.executable.
Checking Node.js version
Launching command C:\Program Files\nodejs\node.exe -v
Using Node.js v18.12.1.
Starting Node.js process to start the bridge server at port 49438
Launching command C:\Program Files\nodejs\node.exe C:\Wks\Eclipse\2023-06.sonarlint\work\sonar.sonarlinttmp_8608677076455321860\bridge-bundle\package\bin\server 49438 127.0.0.1 C:\Wks\git\sonar-custom-rules\java-custom-rules true true
Context set with {“workDir”:“C:\Wks\git\sonar-custom-rules\java-custom-rules”,“shouldUseTypeScriptParserForJS”:true,“sonarlint”:true,“bundles”:}
starting the bridge server at port 49438
the bridge server is running at port 49438
the bridge server closed
GET 200 https://sonar/api/developers/search_events?projects=com.foo.sonar.custom.java%3Ajava-custom-rules&from=2023-09-18T16%3A27%3A31%2B0200 | response time=49ms
Storing last event polling in C:\Wks\Eclipse\2023-06.sonarlint\storage\736f6e6172\projects\64652e68756b2e736f6e61722e637573746f6d2e6a6176613a6a6176612d637573746f6d2d72756c6573\last_event_polling.pb
GET 200 https://sonar/api/developers/search_events?projects=com.foo.sonar.custom.java%3Ajava-custom-rules&from=2023-09-18T16%3A28%3A31%2B0200 | response time=49ms
Storing last event polling in C:\Wks\Eclipse\2023-06.sonarlint\storage\736f6e6172\projects\64652e68756b2e736f6e61722e637573746f6d2e6a6176613a6a6176612d637573746f6d2d72756c6573\last_event_polling.pb
GET 200 https://sonar/api/developers/search_events?projects=com.foo.sonar.custom.java%3Ajava-custom-rules&from=2023-09-18T16%3A29%3A31%2B0200 | response time=295ms
Storing last event polling in C:\Wks\Eclipse\2023-06.sonarlint\storage\736f6e6172\projects\64652e68756b2e736f6e61722e637573746f6d2e6a6176613a6a6176612d637573746f6d2d72756c6573\last_event_polling.pb
GET 200 https://sonar/api/developers/search_events?projects=com.foo.sonar.custom.java%3Ajava-custom-rules&from=2023-09-18T16%3A30%3A31%2B0200 | response time=52ms
Storing last event polling in C:\Wks\Eclipse\2023-06.sonarlint\storage\736f6e6172\projects\64652e68756b2e736f6e61722e637573746f6d2e6a6176613a6a6176612d637573746f6d2d72756c6573\last_event_polling.pb
GET 200 https://sonar/api/developers/search_events?projects=com.foo.sonar.custom.java%3Ajava-custom-rules&from=2023-09-18T16%3A31%3A31%2B0200 | response time=74ms
Storing last event polling in C:\Wks\Eclipse\2023-06.sonarlint\storage\736f6e6172\projects\64652e68756b2e736f6e61722e637573746f6d2e6a6176613a6a6176612d637573746f6d2d72756c6573\last_event_polling.pb
Failed to start server (300s timeout)
org.sonar.plugins.javascript.nodejs.NodeCommandException: Failed to start server (300s timeout)
at org.sonar.plugins.javascript.eslint.BridgeServerImpl.startServer(BridgeServerImpl.java:188)
at org.sonar.plugins.javascript.eslint.BridgeServerImpl.startServerLazily(BridgeServerImpl.java:293)
at org.sonar.plugins.javascript.eslint.AbstractEslintSensor.execute(AbstractEslintSensor.java:73)
at org.sonarsource.sonarlint.core.analysis.container.analysis.sensor.SensorsExecutor.executeSensor(SensorsExecutor.java:75)
at org.sonarsource.sonarlint.core.analysis.container.analysis.sensor.SensorsExecutor.execute(SensorsExecutor.java:66)
at org.sonarsource.sonarlint.core.analysis.container.analysis.AnalysisContainer.doAfterStart(AnalysisContainer.java:122)
at org.sonarsource.sonarlint.core.plugin.commons.container.SpringComponentContainer.startComponents(SpringComponentContainer.java:182)
at org.sonarsource.sonarlint.core.plugin.commons.container.SpringComponentContainer.execute(SpringComponentContainer.java:161)
at org.sonarsource.sonarlint.core.analysis.container.module.ModuleContainer.analyze(ModuleContainer.java:71)
at org.sonarsource.sonarlint.core.analysis.command.AnalyzeCommand.execute(AnalyzeCommand.java:58)
at org.sonarsource.sonarlint.core.analysis.command.AnalyzeCommand.execute(AnalyzeCommand.java:32)
at org.sonarsource.sonarlint.core.analysis.AnalysisEngine$AsyncCommand.execute(AnalysisEngine.java:153)
at org.sonarsource.sonarlint.core.analysis.AnalysisEngine.executeQueuedCommands(AnalysisEngine.java:71)
at java.base/java.lang.Thread.run(Thread.java:833)

Gilbert

Julien_HENRY · September 27, 2023, 7:54am

Hi @Rebse

It seems our JavaScript analyzer is failing to start (or quickly crashing after startup):

Gilbert Rebhan:

Launching command C:\Program Files\nodejs\node.exe C:\Wks\Eclipse\2023-06.sonarlint\work\sonar.sonarlinttmp_8608677076455321860\bridge-bundle\package\bin\server 49438 127.0.0.1 C:\Wks\git\sonar-custom-rules\java-custom-rules true true
Context set with {“workDir”:“C:\Wks\git\sonar-custom-rules\java-custom-rules”,“shouldUseTypeScriptParserForJS”:true,“sonarlint”:true,“bundles”:}
starting the bridge server at port 49438
the bridge server is running at port 49438
the bridge server closed

The logs are not very helpful here, so I will check with my colleagues how we can investigate that.

Rebse · September 29, 2023, 9:26am

Just to be sure, i checked with netstat -aon | find "49438" the port 49438 was not in use

Damien_Urruty · September 29, 2023, 9:43am

Hello @Rebse,

You might be hit by this known issue, could you check if it’s related to sleep mode?

Rebse · September 29, 2023, 10:13am

Hi,

thanks for the jira ticket. Indeed the error message looks similar, but in my case it happens right after a fresh start of Eclipse, means no sleep involved.

the console has

Starting server
No workDir in SonarLint
Running in SonarLint context, metrics will not be computed.
Using Node.js executable C:\Program Files\nodejs\node.exe from property sonar.nodejs.executable.
Checking Node.js version
Launching command C:\Program Files\nodejs\node.exe -v
Using Node.js v18.12.1.
Starting Node.js process to start the bridge server at port 62746
Launching command C:\Program Files\nodejs\node.exe C:\Wks\Eclipse\2023-06.sonarlint\work\sonar.sonarlinttmp_9172488097942802011\bridge-bundle\package\bin\server 62746 127.0.0.1 C:\Wks\git\sonar-custom-rules\java-custom-rules true true
Context set with {“workDir”:“C:\Wks\git\sonar-custom-rules\java-custom-rules”,“shouldUseTypeScriptParserForJS”:true,“sonarlint”:true,“bundles”:}
starting the bridge server at port 62746
the bridge server is running at port 62746
the bridge server closed

and the progress view show 3 entries but the process seems stalled

2023-09-29_11h56_38

after some mins this message appears

2023-09-29_12h01_16

if i try to analyze the js file via context menu Sonarlint > Analyze the console has

Start analysis
Index files
Language of file “file:/C:/Wks/git/sonar-custom-rules/java-custom-rules/src/main/resources/org/sonar/l10n/java/rules/java/Person.js” is detected to be “JavaScript”
Average line length for [uri=file:/C:/Wks/git/sonar-custom-rules/java-custom-rules/src/main/resources/org/sonar/l10n/java/rules/java/Person.js] is 20
1 file indexed
Added 19 checks for language=‘ts’, repository=‘typescript’
Added 26 checks for language=‘js’, repository=‘javascript’
Setting filesystem encoding: UTF-8
[…]
Execute Sensor: JavaScript/TypeScript analysis
Skipping the start of the bridge server as it failed to start during the first analysis or it’s not answering anymore
No rules will be executed

victor.diez · September 29, 2023, 1:49pm

Hi @Rebse,

can you please try executing this command manually see if you get any error?

Also, please enable debug logs see if they provide further info?

Cheers,
Victor

Rebse · September 29, 2023, 1:55pm

Hi Victor,

i’ve executed your provided command, the output

C:\>"C:\Program Files\nodejs\node.exe" C:\Wks\Eclipse\2023-06.sonarlint\work\sonar.sonarlinttmp_9172488097942802011\bridge-bundle\package\bin\server 62746 127.0.0.1 C:\Wks\git\sonar-custom-rules\java-custom-rules true true
node:internal/modules/cjs/loader:998
  throw err;
  ^

Error: Cannot find module 'C:\Wks\Eclipse\2023-06.sonarlint\work\sonar.sonarlinttmp_9172488097942802011\bridge-bundle\package\bin\server'
←[90m    at Module._resolveFilename (node:internal/modules/cjs/loader:995:15)←[39m
←[90m    at Module._load (node:internal/modules/cjs/loader:841:27)←[39m
←[90m    at Function.executeUserEntryPoint [as runMain] (node:internal/modules/run_main:81:12)←[39m
←[90m    at node:internal/main/run_main_module:23:47←[39m {
  code: ←[32m'MODULE_NOT_FOUND'←[39m,
  requireStack: []
}

Node.js v18.12.1

The sonarlint console already runs with Verbose output and Analysis log

Gilbert

victor.diez · October 3, 2023, 9:48am

Hi @Rebse,

I tried to reproduce the error locally, but no luck. Are you able to provide a reproducer from a clean Eclipse install?

Cheers,
Victor

Rebse · October 9, 2023, 11:41am

Hi,

uninstalled Sonarlint for Eclipse 8.0.0.80157 and installed Sonarlint for Eclipse 8.1.0.80220
with Eclipse 2023-06.

It shows exactly the same behaviour as before, i tried also with a new workspace.
WRT to your script, i see only this path
c:\WKS\Eclipse\2023-06_2\.sonarlint\work\<mysonarhosturl>\.sonarlinttmp_660474986614344079\bridge-bundle

and the folder is empty.

Gilbert

Julien_HENRY · October 9, 2023, 12:21pm

This is interesting. Could it be caused by an anti-malware software on your machine? We had experience in the past of such tools wrongly classifying part of SonarLint as dangerous, and moving files to quarantine.

Rebse · November 17, 2023, 12:37pm

Hi,

i guess i’ve found the reason.
Our environment is very restrictive, we have no admin rights on our developer machines.
There’s a dedicated folder C:\WKS where i have more permissions for the Git repos, Eclipse and IntelliJ projects … etc. that is also excluded from virus scan.

I’ve did some more tests with the latest version SLE 9.0.1.81337 that showed the same behaviour as described above.

And i found this entry in c:\Wks\Eclipse\2023-06.metadata.log

!ENTRY org.eclipse.wildwebdeveloper.embedder.node 4 0 2023-11-17 13:18:15.533
!MESSAGE failed to create directory C:\Program Files\Eclipse\2023-06\.node\node-v18.16.0-win-x64
!STACK 0
java.io.IOException: failed to create directory C:\Program Files\Eclipse\2023-06\.node\node-v18.16.0-win-x64
	at org.eclipse.wildwebdeveloper.embedder.node.CompressUtils.extractArchive(CompressUtils.java:81)
	at org.eclipse.wildwebdeveloper.embedder.node.CompressUtils.unarchive(CompressUtils.java:52)
	at org.eclipse.wildwebdeveloper.embedder.node.NodeJSManager.getNodeJsLocation(NodeJSManager.java:83)
	at org.eclipse.wildwebdeveloper.jsts.JSTSLanguageServer.<init>(JSTSLanguageServer.java:50)
	at java.base/jdk.internal.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
	at java.base/jdk.internal.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:77)
	at java.base/jdk.internal.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
	at java.base/java.lang.reflect.Constructor.newInstanceWithCaller(Constructor.java:499)
	at java.base/java.lang.reflect.Constructor.newInstance(Constructor.java:480)
	at org.eclipse.core.internal.registry.osgi.RegistryStrategyOSGI.createExecutableExtension(RegistryStrategyOSGI.java:204)
	at org.eclipse.core.internal.registry.ExtensionRegistry.createExecutableExtension(ExtensionRegistry.java:920)
	at org.eclipse.core.internal.registry.ConfigurationElement.createExecutableExtension(ConfigurationElement.java:246)
	at org.eclipse.core.internal.registry.ConfigurationElementHandle.createExecutableExtension(ConfigurationElementHandle.java:63)
	at org.eclipse.lsp4e.LanguageServersRegistry$ExtensionLanguageServerDefinition.createConnectionProvider(LanguageServersRegistry.java:162)
	at org.eclipse.lsp4e.LanguageServerWrapper.lambda$0(LanguageServerWrapper.java:261)
	at java.base/java.util.concurrent.CompletableFuture$AsyncSupply.run(CompletableFuture.java:1768)
	at java.base/java.util.concurrent.CompletableFuture$AsyncSupply.exec(CompletableFuture.java:1760)
	at java.base/java.util.concurrent.ForkJoinTask.doExec(ForkJoinTask.java:373)
	at java.base/java.util.concurrent.ForkJoinPool$WorkQueue.topLevelExec(ForkJoinPool.java:1182)
	at java.base/java.util.concurrent.ForkJoinPool.scan(ForkJoinPool.java:1655)
	at java.base/java.util.concurrent.ForkJoinPool.runWorker(ForkJoinPool.java:1622)
	at java.base/java.util.concurrent.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:165)

!ENTRY org.eclipse.lsp4e 1 0 2023-11-17 13:18:15.676
!MESSAGE [Info]	ESLint server running in node v18.12.1

!ENTRY org.eclipse.lsp4e 1 0 2023-11-17 13:18:16.857
!MESSAGE [Info]	Using Typescript version (user-setting) 5.0.4 from path "C:\Program Files\Eclipse\2023-06\plugins\org.eclipse.wildwebdeveloper_1.0.7.202305232103\node_modules\typescript\lib\tsserver.js"

!ENTRY org.eclipse.lsp4e 1 0 2023-11-17 13:18:17.347
!MESSAGE [Info]	Typescript Server version info: {version=5.0.4, source=user-setting}

I have no permissions to create folder outside from C:\WKS and i’m quite sure that’s the reason for my problem.
Is there a solution for this ?

Gilbert

victor.diez · November 17, 2023, 3:08pm

Hello @Rebse,

The JS/TS plugin will install an embedded version if Node.js is not found in your system. If node is already in the system, but not found by SonarLint (not in PATH for example), you can set the property

sonar.nodejs.executable=/path/to/node/binary

In your first message, I see that Node.js property was set, so I guess this is a different issue?

Cheers,
Victor

Rebse · November 17, 2023, 3:28pm

Hi Victor,

i’ve tried different things.
As i wrote i have only limited permissions on the developer machine.

PATH has C:\Program Files\nodejs\node.exe and i assumed it may be possible that the virus scanner disturbs starting a node process outside the C:\WKS folder.

So i used Sonarlint settings like that

2023-11-17_16h16_59

and it is correctly resolved, Sonarlint console has

Node.js path provided by configuration: c:\Wks\NodeJS\node.exe
Checking node version…
Execute command ‘c:\Wks\NodeJS\node.exe -v’…
[…]
Command ‘c:\Wks\NodeJS\node.exe -v’ exited with 0
stdout: v18.12.1
Detected node version: 18.12.1

But nevertheless the ./metadata/.log file shows an attempt to install node.js to
C:\Program Files\Eclipse\2023-06.node\node-v18.16.0-win-x64 !?
I’ve cleaned the .log for my tests and the entry reappears when Sonarlint tries to start the node server
to analyze a *.js file.

To me it looks like this is initiated by the Sonarlint plugin because there is nothing else
running in Eclipse that addresses node.js

Gilbert

victor.diez · November 17, 2023, 3:37pm

Hi @Rebse,

if you want to avoid the embedded Node.js deployment altogether you can use:

sonar.nodejs.forceHost=true

In principle, if you provide a local Node.js binary it should not try to extract any other Node binary. We’ll check that behavior.

Additionally, you can change the home directory of the scanner to point to a writable directory:

sonar.userHome=C:\Wks\.sonar

The embedded Node.js binary path is a child path of that property.

Cheers,
Victor

victor.diez · November 17, 2023, 4:21pm

We created a Github issue to not deploy the embedded Node.js runtime when sonar.nodejs.executable is set.

Rebse · November 17, 2023, 6:22pm

Thanks for all the details and taking your time to look into!
This should be part of the Sonarlint documentation, at a first glance i didn’t see any hints for those properties.

btw kudos for the new Sonarlint documentation!!
Great it’s integrated into https://docs.sonarsource.com now.

We provide a customized Eclipse installation that is deployed to developer machines.
Is it possible to set those properties like sonar.nodejs.host and sonar.userHome in eclipse.ini ?
I want to avoid every developer having to set it themselves.

victor.diez · November 20, 2023, 9:41am

Hello @Rebse,

can you confirm setting these properties works?

sonar.nodejs.forceHost=true
sonar.userHome=C:\Wks\.sonar

Because looking again at the stack trace it seems you have Eclipse plugin which is also handling Node.js embedded runtimes:

!ENTRY org.eclipse.wildwebdeveloper.embedder.node 4 0 2023-11-17 13:18:15.533
!MESSAGE failed to create directory C:\Program Files\Eclipse\2023-06\.node\node-v18.16.0-win-x64
!STACK 0
java.io.IOException: failed to create directory C:\Program Files\Eclipse\2023-06\.node\node-v18.16.0-win-x64
	at org.eclipse.wildwebdeveloper.embedder.node.CompressUtils.extractArchive(CompressUtils.java:81)
	at org.eclipse.wildwebdeveloper.embedder.node.CompressUtils.unarchive(CompressUtils.java:52)
	at org.eclipse.wildwebdeveloper.embedder.node.NodeJSManager.getNodeJsLocation(NodeJSManager.java:83)

And I totally missed that the stack trace is not raised by Sonar, even if we also deploy an embedded runtime.

Can you please confirm?

tobias.hahnen · November 21, 2023, 10:48am

Hi @Rebse,

jumping in on the loop regarding your rolled-out Eclipse distribution (and not directly with my SonarLint for Eclipse developer hat on). I worked with a very restrictive developer machine before and we had similar issues but with different Eclipse plug-ins.

In order for not everyone to change their preferences after they set up Eclipse (or their workspace when switching) we had a plug-in implemented to always import some preferences, in your case maybe the SonarLint properties, from either a fixed .epf (we had it in the plug-in) or from something inside the project once it was added to the workspace - like it scans the project, once it finds a .epf file we import it. This was more handy than adding the .settings folder to the version control systems (or part of it) or mapping project files to files in the workspace metadata (I’ve seen that as well).

If you need some more information on that matter, please pm me as it is not directly part of this thread but rather one fix for your specific environment.

As a SonarLint for Eclipse developer speaking of course we would like to see SonarLint work out of the box and without restrictions but your case might be a corner case we cannot cover yet.

Best,
Tobias

Rebse · November 27, 2023, 2:24pm

Hi Victor,

sorry for late response, had to find time for further testing and talking to security.

Unfortunately no.

I’ve tested with a fresh installation of latest Eclipse 2023-09 and SLE 9.0.1, setup in C:\Wks,
no more errors from org.eclipse.wildwebdeveloper.embedder.node in .metadata/log

nodejs is on PATH (tried also with other nodejs versions and also nodejs path without blanks inside C:\WKS)

Node.js path provided by configuration: C:\Program Files\nodejs\node.exe
Checking node version...
Execute command 'C:\Program Files\nodejs\node.exe -v'...
Creating a new StorageFacade for storageRoot=C:\Wks\Eclipse\2023-09\.sonarlint\storage and workDir=C:\Wks\Eclipse\2023-09\.sonarlint\default
No connections configured, skipping binding suggestions.
Command 'C:\Program Files\nodejs\node.exe -v' exited with 0
stdout: v18.12.1
Detected node version: 18.12.1

Sonarlint settings

2023-11-27_13h39_26

you see i even increased the memory, even i used only this small file from sonar-scanning examples for the test

github.com

SonarSource/sonar-scanning-examples/blob/master/sonar-scanner/src/javascript/Person.js

var Person = function(first, last, middle) {
    this.first = first;
    this.middle = middle;
    this.last = last;
};

Person.prototype = {

    whoAreYou : function() {
        return this.first + (this.middle ? ' ' + this.middle: '') + ' ' + this.last;
    }

};

var a = NaN;

if (a === NaN) {  // Noncompliant; always false
  console.log("a is not a number");  // this is dead code
}
if (a !== NaN) { // Noncompliant; always true

This file has been truncated. show original

sle_console.txt (23.3 KB)

Output see attached sle_console.txt

I’m no nodejs expert, but i’ve tried to call the cli call directly with loglevel DEBUG,
set NODE_DEBUG=cluster,net,http,fs,tls,module,timers & "C:\Program Files\nodejs\node.exe" ...
see attached nodejs_out.txt , maybe it’s helpful !?
nodejs_out.txt (11.9 MB)

I’ve talked with our security team to rule out problems with the virus scanner, app blocker or similar.
But it shows the same behaviour with deactived virus scanner and the node process ain’t blocked.

The scan of the same project with the small Person.js file works just fine with
Sonarlint for IntelliJ 10.0.1 using exactly the same nodejs path C:\Program Files\nodejs\node.exe

Now I have no more ideas.

Gilbert

victor.diez · November 28, 2023, 11:01am

Hello @Rebse,

Thanks for providing those logs. I don’t see anything weird in them. Node.js correctly starts and listens:

DEBUG The bridge server is listening on port 57970

However after 15s without analysis request it will shutdown automatically. That is also expected:

DEBUG The bridge server shut down
DEBUG The worker thread exited with code 1

SonarLint uses HTTP protocol to communicate with the Node.js server. Can you check if that port is actually accessible? Is there any IP filtering which does not allow SonarLint to send HTTP requests? It’s possible that the 300 seconds timeout is due to some firewall policy.

Edit: Keep in mind the port is assigned randomly by the OS and will be different each time.

Cheers,
Victor