SonarCloud, JsSecuritySensor taking several minutes suddenly

DanielVinkSpotler · February 5, 2024, 10:33am

Since last week (january 29) SonarCloud is taking about 8 minutes longer to scan our TypeScript repository. More specifically this step:

INFO: Sensor JsSecuritySensor [security] (done) | time=446197ms

We didn’t make any changes to our quality profile or any other settings. To fix this we temporarily disabled some rules, similar to what was mentioned in this post.

Any suggestions or insights on how to address this problem would be greatly appreciated.

Must-share information (formatted with Markdown):

we are using sonarsource/sonarqube-scan-action@master
Sonar host url https://sonarcloud.io

Please let me know what more information I might provide, such as additional log output etc

ganncamp · February 5, 2024, 6:53pm

Hi,

We upgraded JS/TS analysis last week and that upgrade ended up taking additional memory for some analyses. Can you try increasing the Node.js memory and let us know if that helps?

Thx,
Ann

DanielVinkSpotler · February 6, 2024, 12:44pm

Thank you for the suggestion Ann, unfortunately it didn’t solve the problem. Anything else we can try?

ganncamp · February 6, 2024, 3:25pm

Hi,

Did you see any movement at all?

There may not be anything here to be done, but can you provide a debug analysis log?

The analysis / scanner log is what’s output from the analysis command. Hopefully, the log you provide - redacted as necessary - will include that command as well.

This guide will help you find them.

Ann

DanielVinkSpotler · February 6, 2024, 4:14pm

There was no movement noticeable unfortunately. I’ve enabled DEBUG output for analysis but our entire log is now more than 25000 lines, not sure which part would be most useful? The part that is now all of a sudden taking much longer is this:

INFO: Taint analysis for js: Starting
INFO: 0 / 14566 UCFGs simulated, memory usage: 461 MB
INFO: 242 / 14566 UCFGs simulated, memory usage: 516 MB
INFO: 397 / 14566 UCFGs simulated, memory usage: 795 MB
INFO: 615 / 14566 UCFGs simulated, memory usage: 663 MB
INFO: 860 / 14566 UCFGs simulated, memory usage: 451 MB
INFO: 1055 / 14566 UCFGs simulated, memory usage: 791 MB
INFO: 1264 / 14566 UCFGs simulated, memory usage: 416 MB
INFO: 1492 / 14566 UCFGs simulated, memory usage: 474 MB
INFO: 1731 / 14566 UCFGs simulated, memory usage: 798 MB
INFO: 2023 / 14566 UCFGs simulated, memory usage: 519 MB
INFO: 2229 / 14566 UCFGs simulated, memory usage: 1327 MB
INFO: 2505 / 14566 UCFGs simulated, memory usage: 1339 MB
INFO: 2723 / 14566 UCFGs simulated, memory usage: 1357 MB
INFO: 2955 / 14566 UCFGs simulated, memory usage: 1340 MB
INFO: 3143 / 14566 UCFGs simulated, memory usage: 1117 MB
INFO: 3409 / 14566 UCFGs simulated, memory usage: 1565 MB
INFO: 3650 / 14566 UCFGs simulated, memory usage: 1671 MB
INFO: 3950 / 14566 UCFGs simulated, memory usage: 899 MB
INFO: 4210 / 14566 UCFGs simulated, memory usage: 1755 MB
INFO: 4490 / 14566 UCFGs simulated, memory usage: 1353 MB
INFO: 4704 / 14566 UCFGs simulated, memory usage: 1784 MB
INFO: 4953 / 14566 UCFGs simulated, memory usage: 1527 MB
INFO: 5174 / 14566 UCFGs simulated, memory usage: 1660 MB
INFO: 5385 / 14566 UCFGs simulated, memory usage: 1836 MB
INFO: 5631 / 14566 UCFGs simulated, memory usage: 2408 MB
INFO: 5879 / 14566 UCFGs simulated, memory usage: 1632 MB
INFO: 6071 / 14566 UCFGs simulated, memory usage: 3522 MB
INFO: 6183 / 14566 UCFGs simulated, memory usage: 1846 MB
INFO: Taint analysis for js: Time spent was 00:07:54.170

and

16:10:06.575 INFO: js security sensor: Begin: 2024-02-06T16:02:34.305985129Z, End: 2024-02-06T16:10:06.573727929Z, Duration: 00:07:32.267
  Load type hierarchy and UCFGs: Begin: 2024-02-06T16:02:34.306127326Z, End: 2024-02-06T16:02:36.593879436Z, Duration: 00:00:02.287
    Load type hierarchy: Begin: 2024-02-06T16:02:34.306139028Z, End: 2024-02-06T16:02:34.330711981Z, Duration: 00:00:00.024
    Load UCFGs: Begin: 2024-02-06T16:02:34.330819102Z, End: 2024-02-06T16:02:36.593681144Z, Duration: 00:00:02.262
  Check cache: Begin: 2024-02-06T16:02:36.593952383Z, End: 2024-02-06T16:02:36.594273205Z, Duration: 00:00:00.000
    Load cache: Begin: 2024-02-06T16:02:36.593974304Z, End: 2024-02-06T16:02:36.594008217Z, Duration: 00:00:00.000
  Create runtime call graph: Begin: 2024-02-06T16:02:36.594324250Z, End: 2024-02-06T16:02:37.537303496Z, Duration: 00:00:00.942
    Variable Type Analysis #1: Begin: 2024-02-06T16:02:36.594781447Z, End: 2024-02-06T16:02:37.111796873Z, Duration: 00:00:00.517
      Create runtime type propagation graph: Begin: 2024-02-06T16:02:36.595307624Z, End: 2024-02-06T16:02:36.951013563Z, Duration: 00:00:00.355
      Run SCC (Tarjan) on 68362 nodes: Begin: 2024-02-06T16:02:36.951375873Z, End: 2024-02-06T16:02:37.029664533Z, Duration: 00:00:00.078
      Propagate runtime types to strongly connected components: Begin: 2024-02-06T16:02:37.029836325Z, End: 2024-02-06T16:02:37.111654166Z, Duration: 00:00:00.081
    Variable Type Analysis #2: Begin: 2024-02-06T16:02:37.113541513Z, End: 2024-02-06T16:02:37.529354598Z, Duration: 00:00:00.415
      Create runtime type propagation graph: Begin: 2024-02-06T16:02:37.113573032Z, End: 2024-02-06T16:02:37.402006013Z, Duration: 00:00:00.288
      Run SCC (Tarjan) on 68362 nodes: Begin: 2024-02-06T16:02:37.402151015Z, End: 2024-02-06T16:02:37.459539119Z, Duration: 00:00:00.057
      Propagate runtime types to strongly connected components: Begin: 2024-02-06T16:02:37.459704439Z, End: 2024-02-06T16:02:37.529228883Z, Duration: 00:00:00.069
  Load config: Begin: 2024-02-06T16:02:37.537397572Z, End: 2024-02-06T16:02:37.601410540Z, Duration: 00:00:00.064
  Compute entry points: Begin: 2024-02-06T16:02:37.601511760Z, End: 2024-02-06T16:02:39.507917334Z, Duration: 00:00:01.906
  Slice call graph: Begin: 2024-02-06T16:02:39.508038419Z, End: 2024-02-06T16:02:39.508048228Z, Duration: 00:00:00.000
  Live variable analysis: Begin: 2024-02-06T16:02:39.508071892Z, End: 2024-02-06T16:02:40.335756909Z, Duration: 00:00:00.827
  Taint analysis for js: Begin: 2024-02-06T16:02:40.336039689Z, End: 2024-02-06T16:10:06.531023452Z, Duration: 00:07:26.194
  Report issues: Begin: 2024-02-06T16:10:06.531159607Z, End: 2024-02-06T16:10:06.534091686Z, Duration: 00:00:00.002
  Store cache: Begin: 2024-02-06T16:10:06.534126561Z, End: 2024-02-06T16:10:06.573640655Z, Duration: 00:00:00.039
16:10:06.575 INFO: js security sensor peak memory: 6172 MB
16:10:06.575 DEBUG: Debug information:
  Apply callee summaries: Invocations: 8692, Total: 00:06:46.647, Average: 00:00:00.046, Min: 00:00:00.000, Max: 00:03:45.326
    Clone callee summaries: Invocations: 8692, Total: 00:00:01.870, Average: 00:00:00.000, Min: 00:00:00.000, Max: 00:00:00.433
    Apply field writes: Invocations: 8692, Total: 00:00:15.710, Average: 00:00:00.001, Min: 00:00:00.000, Max: 00:00:00.380
    Apply array writes: Invocations: 8692, Total: 00:00:00.021, Average: 00:00:00.000, Min: 00:00:00.000, Max: 00:00:00.000
    Apply parameter by reference writes: Invocations: 8692, Total: 00:00:00.002, Average: 00:00:00.000, Min: 00:00:00.000, Max: 00:00:00.000
    Assigning return values: Invocations: 2657, Total: 00:00:00.034, Average: 00:00:00.000, Min: 00:00:00.000, Max: 00:00:00.002
    Processing uncalled functions: Invocations: 6035, Total: 00:06:28.994, Average: 00:00:00.064, Min: 00:00:00.000, Max: 00:03:44.892
  Merging block summaries: Invocations: 7596, Total: 00:00:00.038, Average: 00:00:00.000, Min: 00:00:00.000, Max: 00:00:00.001
    Merging generic summary data: Invocations: 7596, Total: 00:00:00.013, Average: 00:00:00.000, Min: 00:00:00.000, Max: 00:00:00.000
    Merging variable flows: Invocations: 7596, Total: 00:00:00.021, Average: 00:00:00.000, Min: 00:00:00.000, Max: 00:00:00.000
16:10:06.575 INFO: Sensor JsSecuritySensor [security] (done) | time=452270ms

turkeytrot22 · February 6, 2024, 4:18pm

Yes–I noticed this issue yesterday too. I’m unable to use this in GitHub actions because it keeps running out of memory and wasting a lot of the minutes I pay for on GitHub actions too because it takes so long before it finally quits.

ganncamp · February 6, 2024, 4:21pm

Hi,

Okay, thanks for the detail.

I’ve flagged this for more expert eyes.

Ann

saberduck · February 9, 2024, 1:46pm

Hi @DanielVinkSpotler, @turkeytrot22 ,

could you please share full logs? I think that the important part happens before the analysis gets stuck. Also, could you share the logs from the time when the analysis was fast?

DanielVinkSpotler · February 12, 2024, 12:20pm

Hi Tibor, I have some more logs below. I did strip some content (stuff that we would rather not place online).

First the log from before (when scanning was still fast):

Run sonarsource/sonarqube-scan-action@master
...
INFO: Scanner configuration file: /opt/sonar-scanner/conf/sonar-scanner.properties
INFO: Project root configuration file: /github/workspace/sonar-project.properties
INFO: SonarScanner 5.0.1.3006
INFO: Java 17.0.8 Alpine (64-bit)
INFO: Linux 6.2.0-1018-azure amd64
INFO: User cache: /opt/sonar-scanner/.sonar/cache
INFO: Analyzing on SonarQube server 8.0.0.52135
INFO: Default locale: "en_US", source code encoding: "UTF-8" (analysis is platform dependent)
INFO: Load global settings
INFO: Load global settings (done) | time=410ms
INFO: User cache: /opt/sonar-scanner/.sonar/cache
INFO: Loading required plugins
INFO: Load plugins index
INFO: Load plugins index (done) | time=377ms
INFO: Load/download plugins
INFO: Load/download plugins (done) | time=963ms
INFO: Found an active CI vendor: 'Github Actions'
INFO: Process project properties
INFO: Base dir: /github/workspace
INFO: Working dir: /github/workspace/.scannerwork
INFO: Load project branches
INFO: Load project branches (done) | time=404ms
INFO: Detected project binding: NOT_BOUND
INFO: Load project pull requests
INFO: Load project pull requests (done) | time=358ms
INFO: Load branch configuration
INFO: Load branch configuration (done) | time=1ms
INFO: Load quality profiles
INFO: Load quality profiles (done) | time=464ms
INFO: Load active rules
INFO: Load active rules (done) | time=6090ms
INFO: Preprocessing files...
INFO: 3 languages detected in 1757 preprocessed files
INFO: 1936 files ignored because of inclusion/exclusion patterns
INFO: 0 files ignored because of scm ignore settings
INFO: Loading plugins for detected languages
INFO: Load/download plugins
INFO: Load/download plugins (done) | time=111ms
INFO: Load project repositories
INFO: Load project repositories (done) | time=956ms
INFO: SCM collecting changed files in the branch
WARN: Could not find ref: master in refs/heads, refs/remotes/upstream or refs/remotes/origin
INFO: SCM collecting changed files in the branch (done) | time=9ms
INFO: Indexing files...
INFO: Project configuration:
INFO:   Excluded sources: **/build-wrapper-dump.json, **/*.spec.ts, **/tests/**/*, **.scss, **.html, **/global-templates/*.ts, src/pendo.js, src/delighted.js, **/node_modules/**
INFO:   Excluded tests: **/*.spec.ts, **/tests/**/*
INFO:   Excluded sources for coverage: **.js, **.spec.ts, **.module.ts, **/environment.*.ts, **/routes.ts, **/main.ts, **/index.ts, **/tests/**/*
INFO: 1757 files indexed
INFO: Quality profile for docker: Sonar way
INFO: Quality profile for json: Sonar way
INFO: Quality profile for ts: Sonar way
INFO: Load metrics repository
INFO: Load metrics repository (done) | time=371ms
INFO: Sensor cache enabled
INFO: Load sensor cache
INFO: Load sensor cache (2 MB) | time=1614ms
INFO: Sensor JaCoCo XML Report Importer [jacoco]
INFO: 'sonar.coverage.jacoco.xmlReportPaths' is not defined. Using default locations: target/site/jacoco/jacoco.xml,target/site/jacoco-it/jacoco.xml,build/reports/jacoco/test/jacocoTestReport.xml
INFO: No report imported, no coverage information will be imported by JaCoCo XML Report Importer
INFO: Sensor JaCoCo XML Report Importer [jacoco] (done) | time=1ms
INFO: Sensor IaC CloudFormation Sensor [iac]
INFO: 0 source files to be analyzed
INFO: 0/0 source files have been analyzed
INFO: Sensor IaC CloudFormation Sensor [iac] (done) | time=17ms
INFO: Sensor IaC AzureResourceManager Sensor [iac]
INFO: 0 source files to be analyzed
INFO: 0/0 source files have been analyzed
INFO: Sensor IaC AzureResourceManager Sensor [iac] (done) | time=68ms
INFO: Sensor TextAndSecretsSensor [text]
INFO: 1694 source files to be analyzed
INFO: 1694/1694 source files have been analyzed
INFO: Sensor TextAndSecretsSensor [text] (done) | time=6789ms
INFO: Sensor JavaScript/TypeScript analysis [javascript]
INFO: Detected os: Linux arch: amd64 alpine: true. Platform: UNSUPPORTED
INFO: Using Node.js executable: 'node'.
INFO: Memory configuration: OS (32084 MB), Node.js (4144 MB).
INFO: Found 1 tsconfig.json file(s): [/github/workspace/tsconfig.json]
INFO: Creating TypeScript program
INFO: 1692 source files to be analyzed
INFO: TypeScript configuration file /github/workspace/tsconfig.json
INFO: Creating TypeScript program (done) | time=4834ms
INFO: Starting analysis with current program
INFO: 89/1692 files analyzed, current file: ...
INFO: 371/1692 files analyzed, current file: ...
INFO: 731/1692 files analyzed, current file: ...
INFO: 1049/1692 files analyzed, current file: ...
INFO: 1389/1692 files analyzed, current file: ...
INFO: Analyzed 1692 file(s) with current program
INFO: 1692/1692 source files have been analyzed
INFO: Hit the cache for 0 out of 1692
INFO: Miss the cache for 1692 out of 1692: ANALYSIS_MODE_INELIGIBLE [1692/1692]
INFO: Sensor JavaScript/TypeScript analysis [javascript] (done) | time=66133ms
INFO: Sensor CSS Rules [javascript]
INFO: No CSS, PHP, HTML or VueJS files are found in the project. CSS analysis is skipped.
INFO: Sensor CSS Rules [javascript] (done) | time=3ms
INFO: Sensor JavaScript/TypeScript Coverage [javascript]
INFO: Analysing [/github/workspace/coverage/lcov.info]
WARN: Could not resolve 703 file paths in [/github/workspace/coverage/lcov.info]
WARN: First unresolved path: src/app/app.component.html (Run in DEBUG mode to get full list of unresolved paths)
INFO: Sensor JavaScript/TypeScript Coverage [javascript] (done) | time=173ms
INFO: Sensor IaC Docker Sensor [iac]
INFO: 1 source file to be analyzed
INFO: 1/1 source file has been analyzed
INFO: Sensor IaC Docker Sensor [iac] (done) | time=81ms
INFO: Sensor Serverless configuration file sensor [security]
INFO: 0 Serverless function entries were found in the project
INFO: 0 Serverless function handlers were kept as entrypoints
INFO: Sensor Serverless configuration file sensor [security] (done) | time=4ms
INFO: Sensor AWS SAM template file sensor [security]
INFO: Sensor AWS SAM template file sensor [security] (done) | time=1ms
INFO: Sensor AWS SAM Inline template file sensor [security]
INFO: Sensor AWS SAM Inline template file sensor [security] (done) | time=1ms
INFO: Sensor JavaSecuritySensor [security]
INFO: Enabled taint analysis rules: S2076, S2078, S2083, S2091, S2631, S3649, S5131, S5135, S5144, S5145, S5146, S5147, S5334, S5883, S6096, S6173, S6287, S6350, S6384, S6390, S6398, S6399, S6547, S6549
INFO: Load type hierarchy and UCFGs: Starting
INFO: Load type hierarchy: Starting
INFO: Reading type hierarchy from: /github/workspace/.scannerwork/ucfg2/java
INFO: Read 0 type definitions
INFO: Load type hierarchy: Time spent was 00:00:00.001
INFO: Load UCFGs: Starting
INFO: Load UCFGs: Time spent was 00:00:00.000
INFO: Load type hierarchy and UCFGs: Time spent was 00:00:00.002
INFO: No UCFGs have been included for analysis.
INFO: java security sensor: Time spent was 00:00:00.004
INFO: Sensor JavaSecuritySensor [security] (done) | time=12ms
INFO: Sensor CSharpSecuritySensor [security]
INFO: Enabled taint analysis rules: S2076, S2078, S2083, S2091, S2631, S3649, S5131, S5135, S5144, S5145, S5146, S5334, S5883, S6096, S6173, S6287, S6350, S6399, S6639, S6641
INFO: Load type hierarchy and UCFGs: Starting
INFO: Load type hierarchy: Starting
INFO: Reading type hierarchy from: /github/workspace/ucfg2/cs
INFO: Read 0 type definitions
INFO: Load type hierarchy: Time spent was 00:00:00.000
INFO: Load UCFGs: Starting
INFO: Load UCFGs: Time spent was 00:00:00.000
INFO: Load type hierarchy and UCFGs: Time spent was 00:00:00.000
INFO: No UCFGs have been included for analysis.
INFO: csharp security sensor: Time spent was 00:00:00.000
INFO: Sensor CSharpSecuritySensor [security] (done) | time=1ms
INFO: Sensor PhpSecuritySensor [security]
INFO: Enabled taint analysis rules: S2076, S2078, S2083, S2091, S2631, S3649, S5131, S5135, S5144, S5145, S5146, S5334, S5335, S5883, S6173, S6287, S6350
INFO: Load type hierarchy and UCFGs: Starting
INFO: Load type hierarchy: Starting
INFO: Reading type hierarchy from: /github/workspace/.scannerwork/ucfg2/php
INFO: Read 0 type definitions
INFO: Load type hierarchy: Time spent was 00:00:00.000
INFO: Load UCFGs: Starting
INFO: Load UCFGs: Time spent was 00:00:00.000
INFO: Load type hierarchy and UCFGs: Time spent was 00:00:00.000
INFO: No UCFGs have been included for analysis.
INFO: php security sensor: Time spent was 00:00:00.000
INFO: Sensor PhpSecuritySensor [security] (done) | time=1ms
INFO: Sensor PythonSecuritySensor [security]
INFO: Enabled taint analysis rules: S2076, S2078, S2083, S2091, S2631, S3649, S5131, S5135, S5144, S5145, S5146, S5147, S5334, S5496, S6287, S6350, S6639, S6680, S6776, S6839
INFO: Load type hierarchy and UCFGs: Starting
INFO: Load type hierarchy: Starting
INFO: Reading type hierarchy from: /github/workspace/.scannerwork/ucfg2/python
INFO: Read 0 type definitions
INFO: Load type hierarchy: Time spent was 00:00:00.000
INFO: Load UCFGs: Starting
INFO: Load UCFGs: Time spent was 00:00:00.000
INFO: Load type hierarchy and UCFGs: Time spent was 00:00:00.000
INFO: No UCFGs have been included for analysis.
INFO: python security sensor: Time spent was 00:00:00.000
INFO: Sensor PythonSecuritySensor [security] (done) | time=1ms
INFO: Sensor JsSecuritySensor [security]
INFO: Enabled taint analysis rules: S2083, S5131, S5146, S2076, S5696, S5334, S2631, S6105, S6350, S5147, S6096, S5883, S3649, S5144, S6287
INFO: Load type hierarchy and UCFGs: Starting
INFO: Load type hierarchy: Starting
INFO: Reading type hierarchy from: /github/workspace/.scannerwork/ucfg2/js
INFO: Read 0 type definitions
INFO: Load type hierarchy: Time spent was 00:00:00.000
INFO: Load UCFGs: Starting
INFO: Load UCFGs: Time spent was 00:00:00.000
INFO: Load type hierarchy and UCFGs: Time spent was 00:00:00.000
INFO: No UCFGs have been included for analysis.
INFO: js security sensor: Time spent was 00:00:00.000
INFO: Sensor JsSecuritySensor [security] (done) | time=1ms
INFO: ------------- Run sensors on project
INFO: Sensor Zero Coverage Sensor
INFO: Sensor Zero Coverage Sensor (done) | time=13ms
INFO: SCM Publisher SCM provider for this project is: git
INFO: SCM Publisher 24 source files to be analyzed
WARN: Shallow clone detected, no blame information will be provided. You can convert to non-shallow with 'git fetch --unshallow'.
INFO: SCM Publisher 0/24 source files have been analyzed (done) | time=3ms
WARN: Missing blame information for the following files:
...
WARN: This may lead to missing/broken features in SonarCloud
INFO: CPD Executor 373 files had no CPD blocks
INFO: CPD Executor Calculating CPD for 1319 files
INFO: CPD Executor CPD calculation finished (done) | time=216ms
INFO: SCM writing changed lines
INFO: SCM writing changed lines (done) | time=3ms
INFO: Analysis report generated in 176ms, dir size=1 MB
INFO: Analysis report compressed in 1718ms, zip size=1 MB
INFO: Analysis report uploaded in 1519ms
INFO: ANALYSIS SUCCESSFUL, you can find the results at: 
INFO: Note that you will be able to access the updated dashboard once the server has processed the submitted analysis report
INFO: More about the report processing at https://sonarcloud.io/api/ce/task?id=AY1B
INFO: Sensor cache published successfully
INFO: Analysis total time: 1:38.800 s
INFO: ------------------------------------------------------------------------
INFO: EXECUTION SUCCESS
INFO: ------------------------------------------------------------------------
INFO: Total time: 1:44.216s
INFO: Final Memory: 21M/108M
INFO: ------------------------------------------------------------------------

And more recent logs, when scanning became slow:

Run sonarsource/sonarqube-scan-action@master
...
INFO: Scanner configuration file: /opt/sonar-scanner/conf/sonar-scanner.properties
INFO: Project root configuration file: /github/workspace/sonar-project.properties
INFO: SonarScanner 5.0.1.3006
INFO: Java 17.0.8 Alpine (64-bit)
INFO: Linux 6.2.0-1018-azure amd64
INFO: User cache: /opt/sonar-scanner/.sonar/cache
INFO: Analyzing on SonarQube server 8.0.0.52293
INFO: Default locale: "en_US", source code encoding: "UTF-8" (analysis is platform dependent)
INFO: Load global settings
INFO: Load global settings (done) | time=402ms
INFO: User cache: /opt/sonar-scanner/.sonar/cache
INFO: Loading required plugins
INFO: Load plugins index
INFO: Load plugins index (done) | time=380ms
INFO: Load/download plugins
INFO: Load/download plugins (done) | time=579ms
INFO: Found an active CI vendor: 'Github Actions'
INFO: Process project properties
INFO: Base dir: /github/workspace
INFO: Working dir: /github/workspace/.scannerwork
INFO: Load project branches
INFO: Load project branches (done) | time=395ms
INFO: Load project pull requests
INFO: Load project pull requests (done) | time=356ms
INFO: Load branch configuration
INFO: Load branch configuration (done) | time=1ms
INFO: Load quality profiles
INFO: Load quality profiles (done) | time=428ms
INFO: Load active rules
INFO: Load active rules (done) | time=6449ms
INFO: Preprocessing files...
INFO: 3 languages detected in 1754 preprocessed files
INFO: 1932 files ignored because of inclusion/exclusion patterns
INFO: 0 files ignored because of scm ignore settings
INFO: Loading plugins for detected languages
INFO: Load/download plugins
INFO: Load/download plugins (done) | time=527ms
INFO: Load project repositories
INFO: Load project repositories (done) | time=1002ms
INFO: SCM collecting changed files in the branch
WARN: Could not find ref: master in refs/heads, refs/remotes/upstream or refs/remotes/origin
INFO: SCM collecting changed files in the branch (done) | time=7ms
INFO: Indexing files...
INFO: Project configuration:
INFO:   Excluded sources: **/build-wrapper-dump.json, **/*.spec.ts, **/tests/**/*, **.scss, **.html, **/global-templates/*.ts, src/pendo.js, src/delighted.js, **/node_modules/**
INFO:   Excluded tests: **/*.spec.ts, **/tests/**/*
INFO:   Excluded sources for coverage: **.js, **.spec.ts, **.module.ts, **/environment.*.ts, **/routes.ts, **/main.ts, **/index.ts, **/tests/**/*
INFO: 1754 files indexed
INFO: Quality profile for docker: Sonar way
INFO: Quality profile for json: Sonar way
INFO: Quality profile for ts: Sonar way
INFO: Load metrics repository
INFO: Load metrics repository (done) | time=352ms
INFO: Sensor cache enabled
INFO: Load sensor cache
INFO: Load sensor cache (404) | time=393ms
INFO: Sensor JaCoCo XML Report Importer [jacoco]
INFO: 'sonar.coverage.jacoco.xmlReportPaths' is not defined. Using default locations: target/site/jacoco/jacoco.xml,target/site/jacoco-it/jacoco.xml,build/reports/jacoco/test/jacocoTestReport.xml
INFO: No report imported, no coverage information will be imported by JaCoCo XML Report Importer
INFO: Sensor JaCoCo XML Report Importer [jacoco] (done) | time=1ms
INFO: Sensor IaC CloudFormation Sensor [iac]
INFO: 0 source files to be analyzed
INFO: 0/0 source files have been analyzed
INFO: Sensor IaC CloudFormation Sensor [iac] (done) | time=21ms
INFO: Sensor IaC AzureResourceManager Sensor [iac]
INFO: 0 source files to be analyzed
INFO: 0/0 source files have been analyzed
INFO: Sensor IaC AzureResourceManager Sensor [iac] (done) | time=69ms
INFO: Sensor TextAndSecretsSensor [text]
INFO: 1691 source files to be analyzed
INFO: 1691/1691 source files have been analyzed
INFO: Sensor TextAndSecretsSensor [text] (done) | time=7088ms
INFO: Sensor JavaScript/TypeScript analysis [javascript]
INFO: Detected os: Linux arch: amd64 alpine: true. Platform: UNSUPPORTED
INFO: Using Node.js executable: 'node'.
INFO: Memory configuration: OS (32084 MB), Node.js (4144 MB).
INFO: Found 1 tsconfig.json file(s): [/github/workspace/tsconfig.json]
INFO: Creating TypeScript program
INFO: 1689 source files to be analyzed
INFO: TypeScript configuration file /github/workspace/tsconfig.json
INFO: Creating TypeScript program (done) | time=4875ms
INFO: Starting analysis with current program
INFO: 61/1689 files analyzed, current file: 
INFO: 236/1689 files analyzed, current file: 
INFO: 502/1689 files analyzed, current file: 
INFO: 739/1689 files analyzed, current file: 
INFO: 951/1689 files analyzed, current file: 
INFO: 1188/1689 files analyzed, current file: 
INFO: 1410/1689 files analyzed, current file: 
INFO: 1623/1689 files analyzed, current file: 
INFO: Analyzed 1689 file(s) with current program
INFO: 1689/1689 source files have been analyzed
INFO: Hit the cache for 0 out of 1689
INFO: Miss the cache for 1689 out of 1689: ANALYSIS_MODE_INELIGIBLE [1689/1689]
INFO: Sensor JavaScript/TypeScript analysis [javascript] (done) | time=89721ms
INFO: Sensor CSS Rules [javascript]
INFO: No CSS, PHP, HTML or VueJS files are found in the project. CSS analysis is skipped.
INFO: Sensor CSS Rules [javascript] (done) | time=3ms
INFO: Sensor JavaScript/TypeScript Coverage [javascript]
INFO: Analysing [/github/workspace/coverage/lcov.info]
WARN: Could not resolve 701 file paths in [/github/workspace/coverage/lcov.info]
WARN: First unresolved path: src/app/app.component.html (Run in DEBUG mode to get full list of unresolved paths)
INFO: Sensor JavaScript/TypeScript Coverage [javascript] (done) | time=191ms
INFO: Sensor IaC Docker Sensor [iac]
INFO: 1 source file to be analyzed
INFO: 1/1 source file has been analyzed
INFO: Sensor IaC Docker Sensor [iac] (done) | time=97ms
INFO: Sensor Serverless configuration file sensor [security]
INFO: 0 Serverless function entries were found in the project
INFO: 0 Serverless function handlers were kept as entrypoints
INFO: Sensor Serverless configuration file sensor [security] (done) | time=4ms
INFO: Sensor AWS SAM template file sensor [security]
INFO: Sensor AWS SAM template file sensor [security] (done) | time=1ms
INFO: Sensor AWS SAM Inline template file sensor [security]
INFO: Sensor AWS SAM Inline template file sensor [security] (done) | time=1ms
INFO: Sensor JavaSecuritySensor [security]
INFO: Enabled taint analysis rules: S2076, S2078, S2083, S2091, S2631, S3649, S5131, S5135, S5144, S5145, S5146, S5147, S5334, S5883, S6096, S6173, S6287, S6350, S6384, S6390, S6398, S6399, S6547, S6549
INFO: Load type hierarchy and UCFGs: Starting
INFO: Load type hierarchy: Starting
INFO: Reading type hierarchy from: /github/workspace/.scannerwork/ucfg2/java
INFO: Read 0 type definitions
INFO: Load type hierarchy: Time spent was 00:00:00.001
INFO: Load UCFGs: Starting
INFO: Load UCFGs: Time spent was 00:00:00.000
INFO: Load type hierarchy and UCFGs: Time spent was 00:00:00.002
INFO: No UCFGs have been included for analysis.
INFO: java security sensor: Time spent was 00:00:00.004
INFO: Sensor JavaSecuritySensor [security] (done) | time=14ms
INFO: Sensor CSharpSecuritySensor [security]
INFO: Enabled taint analysis rules: S2076, S2078, S2083, S2091, S2631, S3649, S5131, S5135, S5144, S5145, S5146, S5334, S5883, S6096, S6173, S6287, S6350, S6399, S6639, S6641
INFO: Load type hierarchy and UCFGs: Starting
INFO: Load type hierarchy: Starting
INFO: Reading type hierarchy from: /github/workspace/ucfg2/cs
INFO: Read 0 type definitions
INFO: Load type hierarchy: Time spent was 00:00:00.000
INFO: Load UCFGs: Starting
INFO: Load UCFGs: Time spent was 00:00:00.000
INFO: Load type hierarchy and UCFGs: Time spent was 00:00:00.000
INFO: No UCFGs have been included for analysis.
INFO: csharp security sensor: Time spent was 00:00:00.000
INFO: Sensor CSharpSecuritySensor [security] (done) | time=1ms
INFO: Sensor PhpSecuritySensor [security]
INFO: Enabled taint analysis rules: S2076, S2078, S2083, S2091, S2631, S3649, S5131, S5135, S5144, S5145, S5146, S5334, S5335, S5883, S6173, S6287, S6350
INFO: Load type hierarchy and UCFGs: Starting
INFO: Load type hierarchy: Starting
INFO: Reading type hierarchy from: /github/workspace/.scannerwork/ucfg2/php
INFO: Read 0 type definitions
INFO: Load type hierarchy: Time spent was 00:00:00.000
INFO: Load UCFGs: Starting
INFO: Load UCFGs: Time spent was 00:00:00.000
INFO: Load type hierarchy and UCFGs: Time spent was 00:00:00.000
INFO: No UCFGs have been included for analysis.
INFO: php security sensor: Time spent was 00:00:00.000
INFO: Sensor PhpSecuritySensor [security] (done) | time=1ms
INFO: Sensor PythonSecuritySensor [security]
INFO: Enabled taint analysis rules: S2076, S2078, S2083, S2091, S2631, S3649, S5131, S5135, S5144, S5145, S5146, S5147, S5334, S5496, S6287, S6350, S6639, S6680, S6776, S6839
INFO: Load type hierarchy and UCFGs: Starting
INFO: Load type hierarchy: Starting
INFO: Reading type hierarchy from: /github/workspace/.scannerwork/ucfg2/python
INFO: Read 0 type definitions
INFO: Load type hierarchy: Time spent was 00:00:00.000
INFO: Load UCFGs: Starting
INFO: Load UCFGs: Time spent was 00:00:00.000
INFO: Load type hierarchy and UCFGs: Time spent was 00:00:00.000
INFO: No UCFGs have been included for analysis.
INFO: python security sensor: Time spent was 00:00:00.000
INFO: Sensor PythonSecuritySensor [security] (done) | time=1ms
INFO: Sensor JsSecuritySensor [security]
INFO: Enabled taint analysis rules: S3649, S2076, S6096, S6350, S5883, S5131, S5144, S5147, S5334, S6105, S2631, S5696, S5146, S6287, S2083
INFO: Load type hierarchy and UCFGs: Starting
INFO: Load type hierarchy: Starting
INFO: Reading type hierarchy from: /github/workspace/.scannerwork/ucfg2/js
INFO: Read 0 type definitions
INFO: Load type hierarchy: Time spent was 00:00:00.026
INFO: Load UCFGs: Starting
INFO: Reading UCFGs from: /github/workspace/.scannerwork/ucfg2/js
INFO: Load UCFGs: Time spent was 00:00:01.944
INFO: Load type hierarchy and UCFGs: Time spent was 00:00:01.971
INFO: Analyzing 14525 UCFGs to detect vulnerabilities.
INFO: Check cache: Starting
INFO: Load cache: Starting
INFO: Load cache: Time spent was 00:00:00.000
INFO: Check cache: Time spent was 00:00:00.000
INFO: Create runtime call graph: Starting
INFO: Variable Type Analysis #1: Starting
INFO: Create runtime type propagation graph: Starting
INFO: Create runtime type propagation graph: Time spent was 00:00:00.328
INFO: Run SCC (Tarjan) on 68192 nodes: Starting
INFO: Run SCC (Tarjan) on 68192 nodes: Time spent was 00:00:00.055
INFO: Tarjan found 68191 strongly connected components
INFO: Propagate runtime types to strongly connected components: Starting
INFO: Propagate runtime types to strongly connected components: Time spent was 00:00:00.090
INFO: Variable Type Analysis #1: Time spent was 00:00:00.475
INFO: Variable Type Analysis #2: Starting
INFO: Create runtime type propagation graph: Starting
INFO: Create runtime type propagation graph: Time spent was 00:00:00.220
INFO: Run SCC (Tarjan) on 68192 nodes: Starting
INFO: Run SCC (Tarjan) on 68192 nodes: Time spent was 00:00:00.064
INFO: Tarjan found 68191 strongly connected components
INFO: Propagate runtime types to strongly connected components: Starting
INFO: Propagate runtime types to strongly connected components: Time spent was 00:00:00.097
INFO: Variable Type Analysis #2: Time spent was 00:00:00.383
INFO: Create runtime call graph: Time spent was 00:00:00.870
INFO: Load config: Starting
INFO: Load config: Time spent was 00:00:00.071
INFO: Compute entry points: Starting
INFO: Compute entry points: Time spent was 00:00:01.897
INFO: All rules entry points : 1690
INFO: Slice call graph: Starting
INFO: Slice call graph: Time spent was 00:00:00.000
INFO: Live variable analysis: Starting
INFO: Live variable analysis: Time spent was 00:00:00.794
INFO: Taint analysis for js: Starting
INFO: 0 / 14525 UCFGs simulated, memory usage: 266 MB
INFO: 242 / 14525 UCFGs simulated, memory usage: 302 MB
INFO: 397 / 14525 UCFGs simulated, memory usage: 555 MB
INFO: 616 / 14525 UCFGs simulated, memory usage: 856 MB
INFO: 859 / 14525 UCFGs simulated, memory usage: 555 MB
INFO: 1048 / 14525 UCFGs simulated, memory usage: 915 MB
INFO: 1258 / 14525 UCFGs simulated, memory usage: 1019 MB
INFO: 1483 / 14525 UCFGs simulated, memory usage: 863 MB
INFO: 1721 / 14525 UCFGs simulated, memory usage: 840 MB
INFO: 2009 / 14525 UCFGs simulated, memory usage: 494 MB
INFO: 2223 / 14525 UCFGs simulated, memory usage: 1308 MB
INFO: 2496 / 14525 UCFGs simulated, memory usage: 1389 MB
INFO: 2715 / 14525 UCFGs simulated, memory usage: 987 MB
INFO: 2945 / 14525 UCFGs simulated, memory usage: 1629 MB
INFO: 3150 / 14525 UCFGs simulated, memory usage: 1664 MB
INFO: 3395 / 14525 UCFGs simulated, memory usage: 885 MB
INFO: 3652 / 14525 UCFGs simulated, memory usage: 1383 MB
INFO: 3943 / 14525 UCFGs simulated, memory usage: 1043 MB
INFO: 4199 / 14525 UCFGs simulated, memory usage: 1285 MB
INFO: 4482 / 14525 UCFGs simulated, memory usage: 1964 MB
INFO: 4698 / 14525 UCFGs simulated, memory usage: 2430 MB
INFO: 4940 / 14525 UCFGs simulated, memory usage: 1263 MB
INFO: 5165 / 14525 UCFGs simulated, memory usage: 1787 MB
INFO: 5380 / 14525 UCFGs simulated, memory usage: 1947 MB
INFO: 5624 / 14525 UCFGs simulated, memory usage: 2504 MB
INFO: 5869 / 14525 UCFGs simulated, memory usage: 2610 MB
INFO: 6060 / 14525 UCFGs simulated, memory usage: 2141 MB
INFO: 6162 / 14525 UCFGs simulated, memory usage: 1808 MB
INFO: Taint analysis for js: Time spent was 00:07:20.550
INFO: Report issues: Starting
INFO: Report issues: Time spent was 00:00:00.002
INFO: Store cache: Starting
INFO: Store cache: Time spent was 00:00:00.035
INFO: js security sensor: Time spent was 00:07:26.196
INFO: js security sensor: Begin: 2024-01-29T13:26:32.418144578Z, End: 2024-01-29T13:33:58.614345473Z, Duration: 00:07:26.196
  Load type hierarchy and UCFGs: Begin: 2024-01-29T13:26:32.418322702Z, End: 2024-01-29T13:26:34.389412490Z, Duration: 00:00:01.971
    Load type hierarchy: Begin: 2024-01-29T13:26:32.418358228Z, End: 2024-01-29T13:26:32.444471530Z, Duration: 00:00:00.026
    Load UCFGs: Begin: 2024-01-29T13:26:32.444622513Z, End: 2024-01-29T13:26:34.389198219Z, Duration: 00:00:01.944
  Check cache: Begin: 2024-01-29T13:26:34.389500635Z, End: 2024-01-29T13:26:34.389997026Z, Duration: 00:00:00.000
    Load cache: Begin: 2024-01-29T13:26:34.389526023Z, End: 2024-01-29T13:26:34.389565978Z, Duration: 00:00:00.000
  Create runtime call graph: Begin: 2024-01-29T13:26:34.390076705Z, End: 2024-01-29T13:26:35.260294041Z, Duration: 00:00:00.870
    Variable Type Analysis #1: Begin: 2024-01-29T13:26:34.390695064Z, End: 2024-01-29T13:26:34.866631442Z, Duration: 00:00:00.475
      Create runtime type propagation graph: Begin: 2024-01-29T13:26:34.391343780Z, End: 2024-01-29T13:26:34.719538443Z, Duration: 00:00:00.328
      Run SCC (Tarjan) on 68192 nodes: Begin: 2024-01-29T13:26:34.720036507Z, End: 2024-01-29T13:26:34.775238569Z, Duration: 00:00:00.055
      Propagate runtime types to strongly connected components: Begin: 2024-01-29T13:26:34.775466857Z, End: 2024-01-29T13:26:34.866457276Z, Duration: 00:00:00.090
    Variable Type Analysis #2: Begin: 2024-01-29T13:26:34.868324485Z, End: 2024-01-29T13:26:35.252286816Z, Duration: 00:00:00.383
      Create runtime type propagation graph: Begin: 2024-01-29T13:26:34.868363308Z, End: 2024-01-29T13:26:35.089182146Z, Duration: 00:00:00.220
      Run SCC (Tarjan) on 68192 nodes: Begin: 2024-01-29T13:26:35.089357495Z, End: 2024-01-29T13:26:35.154253532Z, Duration: 00:00:00.064
      Propagate runtime types to strongly connected components: Begin: 2024-01-29T13:26:35.154493733Z, End: 2024-01-29T13:26:35.252124843Z, Duration: 00:00:00.097
  Load config: Begin: 2024-01-29T13:26:35.260380353Z, End: 2024-01-29T13:26:35.331635370Z, Duration: 00:00:00.071
  Compute entry points: Begin: 2024-01-29T13:26:35.331780803Z, End: 2024-01-29T13:26:37.229195379Z, Duration: 00:00:01.897
  Slice call graph: Begin: 2024-01-29T13:26:37.229352483Z, End: 2024-01-29T13:26:37.229372200Z, Duration: 00:00:00.000
  Live variable analysis: Begin: 2024-01-29T13:26:37.229415722Z, End: 2024-01-29T13:26:38.024197438Z, Duration: 00:00:00.794
  Taint analysis for js: Begin: 2024-01-29T13:26:38.024534619Z, End: 2024-01-29T13:33:58.575320510Z, Duration: 00:07:20.550
  Report issues: Begin: 2024-01-29T13:33:58.575512310Z, End: 2024-01-29T13:33:58.578325050Z, Duration: 00:00:00.002
  Store cache: Begin: 2024-01-29T13:33:58.578385924Z, End: 2024-01-29T13:33:58.614217283Z, Duration: 00:00:00.035
INFO: js security sensor peak memory: 4943 MB
INFO: Sensor JsSecuritySensor [security] (done) | time=446197ms
INFO: ------------- Run sensors on project
INFO: Sensor Zero Coverage Sensor
INFO: Sensor Zero Coverage Sensor (done) | time=12ms
INFO: CPD Executor 373 files had no CPD blocks
INFO: CPD Executor Calculating CPD for 1316 files
INFO: CPD Executor CPD calculation finished (done) | time=188ms
INFO: SCM writing changed lines
WARN: Could not find ref: master in refs/heads, refs/remotes/upstream or refs/remotes/origin
INFO: SCM writing changed lines (done) | time=4ms
INFO: Analysis report generated in 189ms, dir size=1 MB
INFO: Analysis report compressed in 1696ms, zip size=1 MB
INFO: Analysis report uploaded in 1528ms
INFO: ANALYSIS SUCCESSFUL, you can find the results at:
INFO: Note that you will be able to access the updated dashboard once the server has processed the submitted analysis report
INFO: More about the report processing at https://sonarcloud.io/api/ce/task?id=AY1Vb
INFO: Sensor cache published successfully
INFO: Analysis total time: 9:29.504 s
INFO: ------------------------------------------------------------------------
INFO: EXECUTION SUCCESS
INFO: ------------------------------------------------------------------------
INFO: Total time: 9:34.407s
INFO: Final Memory: 1306M/4400M
INFO: ------------------------------------------------------------------------

saberduck · February 12, 2024, 4:08pm

Hi @DanielVinkSpotler,

it’s interesting, what you have now is correct behavior, when the “ucfgs” files are getting analyzed. This is a bit deeper analysis of security issues. I don’t understand why you didn’t have this step before (in the before logs there is this line “No UCFG files to be analyzed”), this is “a bug” and the new behavior is fixing it.

For the duration of the analysis, it seems a bit long indeed. How much memory is available on the machine? Increasing the available memory could speed things up.

In theory, if you want the previous behavior, you could disable “taint rules”, rule keys are in this log line

Enabled taint analysis rules: S3649, S2076, S6096, S6350, S5883, S5131, S5144, S5147, S5334, S6105, S2631, S5696, S5146, S6287, S2083

However, I would not recommend it, because this is the kind of rules you typically want to have checked.

DanielVinkSpotler · February 28, 2024, 9:53am

Sorry for the late reply @saberduck. The machine has 32gb of memory. I assume it should be enough?

saberduck · March 4, 2024, 1:28pm

hi @DanielVinkSpotler , sorry for the late response, I pinged the team who should take care of this.

Malte · April 12, 2024, 2:03pm

Hey @DanielVinkSpotler,

Sorry for the late answer. I had a look into the logs you provided.

I can confirm what @saberduck said. In the logs before (when it was still running fast), you had this (I leave only the relevant parts):

INFO: Sensor JavaScript/TypeScript analysis [javascript]
...
INFO: 1692 source files to be analyzed
...
INFO: Sensor JsSecuritySensor [security]
INFO: Enabled taint analysis rules: S2083, S5131, S5146, S2076, S5696, S5334, S2631, S6105, S6350, S5147, S6096, S5883, S3649, S5144, S6287
...
INFO: Reading type hierarchy from: /github/workspace/.scannerwork/ucfg2/js
...
INFO: No UCFGs have been included for analysis.
INFO: js security sensor: Time spent was 00:00:00.000

In the logs after, by comparison, you have:

INFO: Sensor JavaScript/TypeScript analysis [javascript]
...
INFO: 1689 source files to be analyzed
...
INFO: Sensor JsSecuritySensor [security]
INFO: Enabled taint analysis rules: S3649, S2076, S6096, S6350, S5883, S5131, S5144, S5147, S5334, S6105, S2631, S5696, S5146, S6287, S2083
...
INFO: Reading type hierarchy from: /github/workspace/.scannerwork/ucfg2/js
...
INFO: Analyzing 14525 UCFGs to detect vulnerabilities.
...
INFO: js security sensor: Time spent was 00:07:26.196

We can conclude that:

You had roughly the same number of files to be analyzed, no substantial changes here (1692 vs. 1689)
You had the same taint analysis rules enabled in both runs.
You brought my attention to the fact that the enabled taint rules for JS/TS are displayed in a non-deterministic order in the logs. This is due to the fact that they are internally stored in a set. I think that’s very confusing and we are going to fix that (I just created a ticket for it & will push a PR soon). Thank you! However, this is just a cosmetic issue and it has nothing to do with your problem.
The UCFGs are read from the same (correct) location in both runs: /github/workspace/.scannerwork/ucfg2/js
Nevertheless, no UCFGs were analyzed in the first run, whereas the UCFGs were successfully analyzed in the second run.

I do not know why the UCFGs were not read in the earlier run, but this was definitely not correct. They should have been read. Without the UCFGs, no taint analysis took place, so this is why the earlier run was faster.

Taint analysis is a complex analysis that detects vulnerabilities in your code. Due to its complexity, it takes some time, and ~8 minutes for ~1500 files is within expectations.

In the earlier run, no taint analysis took place (since no UCFGs were read), so of course it was faster, but you also had no taint analysis (and therefore could miss vulnerabilities in your code). By disabling the taint rules as you did, you got back to exactly the same situation as in the earlier run: It is faster of course, but you also have no taint analysis and could miss vulnerabilities.

Unfortunately, there is not much that can be done here. However, do note that taint analysis rules are only relevant for web applications (usually written with Express in the case of JS/TS). If your application is not a web application, it is fine to leave the taint rules disabled: You are not missing out in this case. If your web application is a web application, however, I would urge you to consider that it may be worth spending 8 minutes of analysis time to detect vulnerabilities. If vulnerabilities go unnoticed, they can be significantly more expensive later on.

DanielVinkSpotler · April 16, 2024, 7:03am

Thanks for the analysis and explanation @Malte. Analysis is indeed for a web application. It’s good to know what our options and choices are. Perhaps we can look into only running certain analysis on our main branch vs every PR.