SonarCloud analysis very slow analysing typescript with JsSecuritySensorV2 (jasmin)

SonarQube Cloud
1

ALM used: GitHub

CI system used: CircleCI

Scanner command used:


sonar-scanner -D"sonar.organization=$env:ORG" -D"sonar.projectKey=$env:SONAR_PROJECT" -D"sonar.sources=." -D"sonar.sourceEncoding=UTF-8" -D"sonar.host.url=https://sonarcloud.io" -D"sonar.branch.name=$env:CIRCLE_BRANCH" -D"sonar.ws.timeout=120" -D"sonar.projectBaseDir=$pwd"

Languages of the repository: TypeScript, Less

Problem Summary

We’ve observed a dramatic increase in scan duration since the Jasmin / JS security sensor v2 engine was enabled in SonarCloud around June 18:

  • Before (June 17): 280s total scan time

  • After (June 18): 690s total scan time

  • No changes were made to scanner version, configuration, or environment on our end.

Steps to Reproduce

  1. Trigger scan via CircleCI using the command above

  2. Observe extended scan time

Potential Workaround

We’ve tried:

  • Setting sonar.jasmin.internal.disabled=true → This causes the scan to take 45s. It completely skips the old analysis. Compare the sonar-scanner-pre-jasmin.log and sonar-scanner-post-jasmin-jasmin-disabled.log files.

Logs

Verbose log from after jasmin introduced (10+ min duration):
sonar-scanner-post-jasmin-verbose.log (1.9 MB)

Non-verbose log from before jasmin (4 min duration):
sonar-scanner-pre-jasmin.log (28.2 KB)

Full verbose log after jasmin with jasmin disabled (<1 min duration):
sonar-scanner-post-jasmin-jasmin-disabled.log (1.8 MB)

3

Hey @smcmanis ,

Thank you for your report and for the helpful log files! :folded_hands:

We recently rolled out a new JS/TS security analysis engine. It performs a substantially deeper and better analysis to detect security vulnerabilities than the old one, and this is why it takes longer.

In your first file (post-jasmin), with the new sensor enabled, you can see:

Sensor JsSecuritySensorV2 [jasmin] (done) | time=466593ms

In the second file (pre-jasmin), with the old sensor, you can see:

Sensor JsSecuritySensor [security] (done) | time=69237ms

Hence, the new security sensor takes 467s where the old one took 69s. I do understand that ~7x increase of the sensor time is far from ideal, and we are looking into this.

With the switch you used, sonar.jasmin.internal.disabled=true, you can switch back to the old engine. In your third file (post-jasmin-jasmin-disabled), the reported time is:

Sensor JsSecuritySensor [security] (done) | time=1809ms

This is substantially shorter than in the pre-jasmin case, however, the sensor was not just skipped: It simply used analysis data that was available in the cache to give you a faster analysis.

You can see this in your third file (post-jasmin-jasmin-disabled):

04:29:02.569 INFO 1868/1868 source files have been analyzed
04:29:02.570 INFO Hit the cache for 1854 out of 1868
04:29:02.571 INFO Miss the cache for 14 out of 1868: FILE_CHANGED [14/1868]

That is, in this case, only 14 out of 1868 needed to be re-analyzed. For the rest, cached data was used. This is why it was so fast.

In your second file (pre-jasmin), you can see the cache was not used, so the old sensor did a full run:

05:40:32.397 INFO 1867/1867 source files have been analyzed
05:40:32.398 INFO Hit the cache for 0 out of 1867
05:40:32.399 INFO Miss the cache for 1867 out of 1867: ANALYSIS_MODE_INELIGIBLE [1867/1867]

I can’t be sure why the cache was not used in this case. It is possible that this was not a PR analysis, but a branch analysis, and this is why the cache was not used. Another possibility: At the same time as the new JS/TS security sensor was released, we also made some improvements to the caching mechanism (this is independent of the new sensor): It may also be that it was not correctly working before for some reason.

All in all, with sonar.jasmin.internal.disabled=true, you should be fine, though. If you want to double-check the timings with the caching mechanism disabled, you can disable it with sonar.analysisCache.enabled=false. Also see Incremental analysis setup & SonarQube.

I hope this helps you around the issue. :slightly_smiling_face:

I would be grateful if you could provide us with more information to help resolve your issue with the new JS security sensor. In particular, it would be very helpful if you could provide:

  1. For the pre-jasmin run: The contents of the .scannerwork directory (according to your logs, in E:\projects\q\q\SharedWebUi\modules\.scannerwork) if you still have it. You can zip it and send it to me as a PM.
  2. For the post-jasmin run: If possible, would it be possible for you to provide (also via PM) an unredacted version of the logs? Seeing the file names might provide us with some clue into what the problem might be.

With this information, I would be happy to take a deeper look into what might be the problem in your case. :folded_hands:

5

Thanks Malte.

Unfortunately, we do not have the records from previous runs.

Sure, I have sent these to you via PM. You’ll notice there is a group of ~30 files that took 7 minutes to scan. However, when I isolate and scan only those files, the analysis completes very quickly, suggesting that the slowdown isn’t due to those specific files themselves, but rather emerges in the context of a full project scan.

I can confirm that setting sonar.jasmin.internal.disabled=true works as you specified. I was suprised because it runs much faster on PRs than it did previously (~1 minute), but that is likely explained by the improvements to the caching mechanism.

That said, it looks like the new engine using the abstract syntax tree doesn’t leverage caching. Previously, PRs took <2 minutes; now they consistently take 10+ minutes. Can you confirm if this behavior is expected? By the way, the sonar-scanner-post-jasmin-verbose.log is actually from a PR.

1 Like
6

Hey Simon,

thank you for sharing the logs with me! It will help us to investigate the issue further.

That said, it looks like the new engine using the abstract syntax tree doesn’t leverage caching. Previously, PRs took <2 minutes; now they consistently take 10+ minutes. Can you confirm if this behavior is expected?

Yes, in fact, if some files are changed, then it is absolutely possible that the engine still needs to analyze some unchanged files — even if they were analyzed previously — because these unchanged files are required by the changed files and the engine needs to understand their effect on the changed files.

In fact, for this reason, I am myself a bit surprised that the old engine is now so fast in the same situation, even if we did improve the caching mechanism. There is something to dig here, but even better would be to fix the issue in the new engine. Still, I will double-check that with the team to see if this is expected, and get back to you.

9

Hi Malte,

Actually, we are seeing the engine scanning all files (and taking 10m to do so) even when there are no files changed.

10

Hey Simon,

I wanted to give you a quick update on the caching problems.

There are two separate concerns here.

The first concern is that the analysis was unexpectedly fast when you switched back to the old sensor, as the caching mechanism came in and made the sensor analyze only a small subset of changed files. As I shared before, even though that sounds good at first and we also implemented some improvements to the caching mechanism, this surprised me. Indeed, due to the fact that this the security analysis is a cross-file analysis, even if only 14 files were changed, the engine still needs to consider the interaction of those 14 files with other files, and so it should not be that fast. It turns out this is due to an incompabibility between the analysis cache between the old and new security sensors: Your last analysis on your main branch was probably with the new security sensor, and then you created a PR where you used the old security sensor. Due to this incompatibility, the caching mechanism does not work quite right and incorrectly does not perform a full analysis. This is a bit of an edge case, as we do not expect users to switch back and forth between the two sensors frequently.

If you switch back to the old sensor on your main branch and then do an analysis with the old sensor in a PR, you should be able to see that the old engine performs a full analysis again, as it should be.

The second concern is that even when you did not change any JS/TS files, the new sensor still performs a full analysis. This is simply a missing feature in the new securty sensor: Usually, if you did not change any code files, the security sensor should just re-use the analysis results from the cache and not perform another full analysis. The old sensor does that, but the new one does not do so (yet). It should be a quick win to implement that, and we will do so in the next release of the new sensor (where we also anticipate to implement some additional performance improvements). I expect within the next 2 weeks. :slightly_smiling_face:

1 Like
11

Hey Simon,

Quick status update on the longer analysis time taken by the new sensor.

After some investigation following a small reproducer from another user who ran into the same problem here, we identified a bug in the new sensor involving the analysis of promise chains. Does your project use such promise chains? If yes, it is not unlikely that the analysis took longer due to this.

We also implemented another general performance improvement that helps to boost performance in certain situations.

Both of these will be released to SonarQube Cloud within the next 24 hours. I will let you know when this is available and I would appreciate your feedback whether you are seeing a performance improvement. :slight_smile:

12

@smcmanis As announced yesterday, we released a new version on SQC today that fixes some known issues. Could you try another scan with the new sensor and let me know if your problem is fixed?