Exact 10 second delay between files analyzed?

We are seeing a strange thing with one of our projects, there is exactly a 10 second delay between files analyzed. There is a total of 310 files, each one starting 10 seconds after the last. This adds up to 52 minutes. Any idea what is causing the 10 second per file delay?
Here is a sample from the logs:
2021-08-30T20:32:58.0203073Z INFO: Java Main Files AST scan
2021-08-30T20:32:58.0231809Z INFO: 310 source files to be analyzed
2021-08-30T20:33:08.0317099Z INFO: 1/310 file analyzed, current file: core/src/main/java/com/slm/core/services/impl/SendEmailServiceImpl.java
2021-08-30T20:33:18.0454066Z INFO: 1/310 file analyzed, current file: core/src/main/java/com/slm/core/services/impl/SendEmailServiceImpl.java
2021-08-30T20:33:28.0590981Z INFO: 2/310 files analyzed, current file: core/src/test/java/com/slm/core/services/impl/LoanInformationServiceImplTest.java
2021-08-30T20:33:38.0728258Z INFO: 3/310 files analyzed, current file: core/src/main/java/com/slm/core/services/CALMRequestProcessService.java
2021-08-30T20:33:48.0853039Z INFO: 4/310 files analyzed, current file: core/src/main/java/com/slm/core/models/Variable.java
2021-08-30T20:33:58.0990077Z INFO: 4/310 files analyzed, current file: core/src/main/java/com/slm/core/models/Variable.java
2021-08-30T20:34:08.1079511Z INFO: 5/310 files analyzed, current file: core/src/main/java/com/slm/core/services/CryptoService.java

We are running SonarQube 8.9.

Is it normal for SonarQube to take 10 seconds per Java file analyzed, or at least to log it?
I found the following log (from another issue by a SonarQube community member, and all the java file analyzed were logged exactly 10 seconds apart. [(Sonar Scanner was stuck)

Hi @bufbooth,

It is expected that you get a log message every ten seconds indicating the current progress. It is not expected that each of those messages corresponds to exactly one file and indeed that is not the case in your logs either. If you look at the numbers in the messages, files 1 and 4 actually took more than 10 seconds, which is why they’re mentioned twice and why after one minute it’s still on file 5.

So it is expected that you get a log message every 10 seconds, but it is not expected that it seems to be progressing at a pace of less than one file per 10 seconds. Usually you’d expect the counter to increase by several files between log messages.

Sadly, I can not tell you why your analysis is this slow just based on those logs. If you run your analysis with the property sonar.java.performance.measure set to true, it will create a file performance-metrics.json which will contain information about which rules took how much of the time. So if the performance problem is caused by a particular rule, that should show up in this file. Note that generating these metrics may slow down your analysis even further, so you should not keep it enabled afterwards.

Cheers,
Sebastian

1 Like

This topic was automatically closed 7 days after the last reply. New replies are no longer allowed.