Report heap usage status with sonar.javascript.node.debugMemory (#4294

)

Co-authored-by: Yassin Kammoun <52890329+yassin-kammoun-sonarsource@users.noreply.github.com>

bin/server

@@ -20,11 +20,12 @@ const host = process.argv[3];
 const workDir = process.argv[4];
 const shouldUseTypeScriptParserForJS = process.argv[5] !== 'false';
 const sonarlint = process.argv[6] === 'true';
+const debugMemory = process.argv[7] === 'true';
 
 let bundles = [];
-if (process.argv[7]) {
-  bundles = process.argv[7].split(path.delimiter);
+if (process.argv[8]) {
+  bundles = process.argv[8].split(path.delimiter);
 }
 
-context.setContext({ workDir, shouldUseTypeScriptParserForJS, sonarlint, bundles });
+context.setContext({ workDir, shouldUseTypeScriptParserForJS, sonarlint, debugMemory, bundles });
 server.start(Number.parseInt(port), host).catch(() => {});

its/plugin/tests/src/test/java/com/sonar/javascript/it/plugin/EslintBasedRulesTest.java

@@ -266,6 +266,8 @@ void should_log_memory_config() {
       .setSourceEncoding("UTF-8")
       .setSourceDirs(".")
       .setProperty("sonar.javascript.node.maxspace", "500000")
+      .setProperty("sonar.javascript.node.debugMemory", "true")
+      .setDebugLogs(true)
       .setProjectDir(projectDir);
 
     var buildResult = orchestrator.executeBuild(build);
@@ -281,6 +283,7 @@ void should_log_memory_config() {
       Pattern.DOTALL
     );
     assertThat(buildResult.getLogs()).matches(warn);
+    assertThat(buildResult.getLogs()).contains("used_heap_size");
   }
 
   @NotNull

package.json

@@ -151,6 +151,7 @@
     "bin/"
   ],
   "_moduleAliases": {
+    "@sonar/bridge": "lib/bridge/src",
     "@sonar/css": "lib/css/src",
     "@sonar/html": "lib/html/src",
     "@sonar/jsts": "lib/jsts/src",

packages/bridge/src/memory.ts

@@ -21,7 +21,9 @@
 import * as v8 from 'v8';
 import * as os from 'os';
 import fs from 'fs';
-import { error, info, warn } from '@sonar/shared/helpers';
+import { debug, error, getContext, info, warn } from '@sonar/shared/helpers';
+import { constants, PerformanceObserver } from 'node:perf_hooks';
+import { NodeGCPerformanceDetail } from 'perf_hooks';
 
 const MB = 1024 * 1024;
 
@@ -83,3 +85,26 @@ export function logMemoryError(err: any) {
       break;
   }
 }
+
+export function registerGarbageCollectionObserver() {
+  const obs = new PerformanceObserver(items => {
+    items
+      .getEntries()
+      .filter(
+        item =>
+          (item.detail as NodeGCPerformanceDetail)?.kind === constants.NODE_PERFORMANCE_GC_MAJOR,
+      )
+      .forEach(item => {
+        debug(`Major GC event`);
+        debug(JSON.stringify(item));
+        logHeapStatistics();
+      });
+  });
+  obs.observe({ entryTypes: ['gc'] });
+}
+
+export function logHeapStatistics() {
+  if (getContext().debugMemory) {
+    debug(JSON.stringify(v8.getHeapStatistics()));
+  }
+}

packages/bridge/src/server.ts

@@ -32,7 +32,11 @@ import { debug, getContext } from '@sonar/shared/helpers';
 import { timeoutMiddleware } from './timeout';
 import { AddressInfo } from 'net';
 import { Worker } from 'worker_threads';
-import { logMemoryConfiguration, logMemoryError } from './memory';
+import {
+  registerGarbageCollectionObserver,
+  logMemoryConfiguration,
+  logMemoryError,
+} from './memory';
 
 /**
  * The maximum request body size
@@ -73,7 +77,7 @@ let worker: Worker;
  * which embeds it or directly with SonarLint.
  *
  * @param port the port to listen to
- * @param host only for usage from outside of NodeJS - Java plugin, SonarLint, ...
+ * @param host only for usage from outside of Node.js - Java plugin, SonarLint, ...
  * @param timeout timeout in ms to shut down the server if unresponsive
  * @returns an http server
  */
@@ -83,6 +87,9 @@ export function start(
   timeout = SHUTDOWN_TIMEOUT,
 ): Promise<http.Server> {
   logMemoryConfiguration();
+  if (getContext().debugMemory) {
+    registerGarbageCollectionObserver();
+  }
   return new Promise(resolve => {
     debug('Starting the bridge server');
 
@@ -145,7 +152,7 @@ export function start(
     });
 
     server.on('close', () => {
-      debug('The bridge server shutted down');
+      debug('The bridge server shut down');
       orphanTimeout.stop();
     });
 

packages/bridge/src/worker.js

@@ -35,6 +35,7 @@ const { analyzeCSS } = require('@sonar/css');
 const { analyzeHTML } = require('@sonar/html');
 const { analyzeYAML } = require('@sonar/yaml');
 const { APIError, ErrorCode } = require('@sonar/shared/errors');
+const { logHeapStatistics } = require('@sonar/bridge/memory');
 
 /**
  * Delegate the handling of an HTTP request to a worker thread
@@ -109,6 +110,7 @@ if (parentPort) {
 
         case 'on-create-program': {
           const { tsConfig } = data;
+          logHeapStatistics();
           const { programId, files, projectReferences, missingTsConfig } =
             createAndSaveProgram(tsConfig);
           parentThread.postMessage({
@@ -128,6 +130,7 @@ if (parentPort) {
         case 'on-delete-program': {
           const { programId } = data;
           deleteProgram(programId);
+          logHeapStatistics();
           parentThread.postMessage({ type: 'success', result: 'OK!' });
           break;
         }

packages/bridge/tests/server.test.ts

@@ -146,7 +146,7 @@ describe('server', () => {
     await new Promise(r => setTimeout(r, 600));
     expect(server.listening).toBeFalsy();
 
-    expect(console.log).toHaveBeenCalledWith('DEBUG The bridge server shutted down');
+    expect(console.log).toHaveBeenCalledWith('DEBUG The bridge server shut down');
   });
 });
 

packages/shared/src/helpers/context.ts

@@ -30,6 +30,7 @@ export interface Context {
   workDir: string;
   shouldUseTypeScriptParserForJS: boolean;
   sonarlint: boolean;
+  debugMemory?: boolean;
   bundles: string[];
 }
 

sonar-plugin/sonar-javascript-plugin/src/main/java/org/sonar/plugins/javascript/bridge/BridgeServerImpl.java

@@ -71,6 +71,7 @@ private enum Status {
   // internal property to set "--max-old-space-size" for Node process running this server
   private static final String MAX_OLD_SPACE_SIZE_PROPERTY = "sonar.javascript.node.maxspace";
   private static final String ALLOW_TS_PARSER_JS_FILES = "sonar.javascript.allowTsParserJsFiles";
+  private static final String DEBUG_MEMORY = "sonar.javascript.node.debugMemory";
   public static final String SONARJS_EXISTING_NODE_PROCESS_PORT =
     "SONARJS_EXISTING_NODE_PROCESS_PORT";
   private static final Gson GSON = new Gson();
@@ -183,13 +184,12 @@ void startServer(SensorContext context, List<Path> deployedBundles) throws IOExc
       );
     }
 
+    LOG.debug("Creating Node.js process to start the bridge server on port " + port);
     String bundles = deployedBundles
       .stream()
       .map(Path::toString)
       .collect(Collectors.joining(File.pathSeparator));
-    initNodeCommand(context, scriptFile, context.fileSystem().workDir(), bundles);
-
-    LOG.debug("Creating Node.js process to start the bridge server on port " + port);
+    nodeCommand = initNodeCommand(context, scriptFile, bundles);
     nodeCommand.start();
 
     if (!waitServerToStart(timeoutSeconds * 1000)) {
@@ -221,24 +221,21 @@ boolean waitServerToStart(int timeoutMs) {
     return true;
   }
 
-  private void initNodeCommand(
-    SensorContext context,
-    File scriptFile,
-    File workDir,
-    String bundles
-  ) throws IOException {
-    boolean allowTsParserJsFiles = context
-      .config()
-      .getBoolean(ALLOW_TS_PARSER_JS_FILES)
-      .orElse(true);
-    boolean isSonarLint = context.runtime().getProduct() == SonarProduct.SONARLINT;
+  private NodeCommand initNodeCommand(SensorContext context, File scriptFile, String bundles)
+    throws IOException {
+    var workdir = context.fileSystem().workDir().getAbsolutePath();
+    var config = context.config();
+    var allowTsParserJsFiles = config.getBoolean(ALLOW_TS_PARSER_JS_FILES).orElse(true);
+    var isSonarLint = context.runtime().getProduct() == SonarProduct.SONARLINT;
     if (isSonarLint) {
       LOG.info("Running in SonarLint context, metrics will not be computed.");
     }
+    var debugMemory = config.getBoolean(DEBUG_MEMORY).orElse(false);
+
+    // enable per rule performance tracking https://eslint.org/docs/1.0.0/developer-guide/working-with-rules#per-rule-performance
     var outputConsumer = monitoring.isMonitoringEnabled()
       ? new LogOutputConsumer().andThen(new MonitoringOutputConsumer(monitoring))
       : new LogOutputConsumer();
-    // enable per rule performance tracking https://eslint.org/docs/1.0.0/developer-guide/working-with-rules#per-rule-performance
 
     nodeCommandBuilder
       .outputConsumer(outputConsumer)
@@ -250,9 +247,10 @@ private void initNodeCommand(
       .scriptArgs(
         String.valueOf(port),
         hostAddress,
-        workDir.getAbsolutePath(),
+        workdir,
         String.valueOf(allowTsParserJsFiles),
         String.valueOf(isSonarLint),
+        String.valueOf(debugMemory),
         bundles
       )
       .env(getEnv());
@@ -262,7 +260,7 @@ private void initNodeCommand(
       .getInt(MAX_OLD_SPACE_SIZE_PROPERTY)
       .ifPresent(nodeCommandBuilder::maxOldSpaceSize);
 
-    nodeCommand = nodeCommandBuilder.build();
+    return nodeCommandBuilder.build();
   }
 
   private Map<String, String> getEnv() {

sonar-plugin/sonar-javascript-plugin/src/test/java/org/sonar/plugins/javascript/bridge/BridgeServerImplTest.java

@@ -649,6 +649,17 @@ void should_skip_metrics_on_sonarlint() throws Exception {
     assertThat(logTester.logs()).contains("sonarlint: true");
   }
 
+  @Test
+  void should_pass_debug_memory_option() throws Exception {
+    bridgeServer = createBridgeServer(START_SERVER_SCRIPT);
+    bridgeServer.deploy();
+    context.setSettings(new MapSettings().setProperty("sonar.javascript.node.debugMemory", "true"));
+    bridgeServer.startServer(context, Arrays.asList(Paths.get("bundle1"), Paths.get("bundle2")));
+    bridgeServer.stop();
+
+    assertThat(logTester.logs()).contains("debugMemory: true");
+  }
+
   @Test
   void should_use_default_timeout() {
     bridgeServer =

sonar-plugin/sonar-javascript-plugin/src/test/resources/mock-bridge/startServer.js

@@ -6,7 +6,8 @@ const host = process.argv[3];
 
 console.log(`allowTsParserJsFiles: ${process.argv[5]}`);
 console.log(`sonarlint: ${process.argv[6]}`);
-console.log(`additional rules: [${process.argv[7]}]`);
+console.log(`debugMemory: ${process.argv[7]}`);
+console.log(`additional rules: [${process.argv[8]}]`);
 
 const requestHandler = (request, response) => {
   let data = "";