search

spotbugs / sonar-findbugs

SpotBugs plugin for SonarQube
357 stars 137 forks source link

SonarQube (6.7) analysis gets hung (stuck) in FindBugs sensor step #318

Open rngh101 opened 4 years ago

rngh101 commented 4 years ago

Issue Description

While running SonarQube analysis of a multi-language large codebase project using sonar-scanner-cli, the analysis seems to be getting stuck in FindBugs sensor step. The analysis does not proceed either to successful completion, nor does it terminate abruptly with any error message. It stays hung.

To reduce the scope, we excluded a few languages like Java, Go, Perl, Typescript etc.

java -jar /tmp/sonar-scanner-4.3.0.2102-linux/lib/sonar-scanner-cli-4.3.0.2102.jar -X -e -Dsonar.host.url=<SONARQUBE_SERVER_URL> -Dsonar.issuesReport.html.enable=true -Dsonar.nodejs.executable=/Tools/nodejs-12.16.2/bin/ -Dsonar.excludePlugins=web,perl,ts,go -Dsonar.issuesReport.html.location=$SONAR_LOG_DIR -Dsonar.issuesReport.html.name=issue-report -Dsonar.projectName=$SONAR_PROJECT -Dsonar.projectVersion=$SONAR_PROJECT_VERSION  -Dsonar.verbose=false -Dsonar.log.level=INFO -Dsonar.projectKey=$SONAR_PROJECT_KEY -Dsonar.cfamily.build-wrapper-output=./sq-log -Dsonar.cppcheck.reportPath=./sq-log/cppcheck.xml -Dsonar.sources=. -Dsonar.projectBaseDir=. -Dsonar.exclusions=$SONAR_EXCLUSIONS -Dsonar.inclusions=$SONAR_INCLUSIONS -Dsonar.java.binaries=. -Dsonar.analysis.mode=publish -Dsonar.issuesReport.console.enable=true -Dsonar.login=<TOKENVALUE> -Dsonar.working.directory=.scannerwork
21:03:23.413 INFO: Option -e/--errors is no longer supported and will be ignored
21:03:23.418 INFO: Scanner configuration file: NONE
21:03:23.422 INFO: Project root configuration file: NONE
21:03:23.437 INFO: SonarScanner 4.3.0.2102
21:03:23.437 INFO: Java 1.8.0_171 Oracle Corporation (64-bit)
21:03:23.437 INFO: Linux 4.4.136-4.NSN.el7.x86_64 amd64
21:03:23.570 DEBUG: keyStore is : 
21:03:23.570 DEBUG: keyStore type is : jks
21:03:23.570 DEBUG: keyStore provider is : 
21:03:23.570 DEBUG: init keystore
21:03:23.570 DEBUG: init keymanager of type SunX509
21:03:23.625 DEBUG: Create: /home/<USERNAME>/.sonar/cache
21:03:23.626 INFO: User cache: /home/<USERNAME>/.sonar/cache
21:03:23.626 DEBUG: Create: /home/<USERNAME>/.sonar/cache/_tmp
21:03:23.629 DEBUG: Extract sonar-scanner-api-batch in temp...
21:03:23.636 DEBUG: Get bootstrap index...
21:03:23.636 DEBUG: Download: https://<SERVER>/batch/index
21:03:24.653 DEBUG: Get bootstrap completed
21:03:24.661 DEBUG: Create isolated classloader...
21:03:24.668 DEBUG: Start temp cleaning...
21:03:24.678 DEBUG: Temp cleaning done
21:03:24.678 INFO: Scanner configuration file: NONE
21:03:24.678 INFO: Project root configuration file: NONE
21:03:24.679 DEBUG: Execution getVersion
21:03:24.681 INFO: Analyzing on SonarQube server 6.7.7
21:03:24.682 INFO: Default locale: "en_US", source code encoding: "UTF-8" (analysis is platform dependent)
21:03:24.682 DEBUG: Work directory: <PATHPREFIX>/.scannerwork
21:03:24.683 DEBUG: Execution execute
21:03:24.981 INFO: Publish mode
21:03:25.349 INFO: Load global settings
21:03:26.347 INFO: Load global settings (done) | time=945ms
21:03:26.357 INFO: Server id: <ServerID>
21:03:27.118 INFO: Load plugins index
21:03:28.073 INFO: Load plugins index (done) | time=955ms
21:03:30.141 INFO: Process project properties
21:03:30.153 INFO: Load branch configuration
21:03:30.154 INFO: Load branch configuration (done) | time=1ms
21:03:30.154 INFO: Load project repositories
21:03:31.146 INFO: Load project repositories (done) | time=992ms
21:03:31.215 INFO: Execute project builders
21:03:31.221 INFO: Execute project builders (done) | time=6ms
21:03:31.454 INFO: Load quality profiles
21:03:32.375 INFO: Load quality profiles (done) | time=921ms
21:03:32.388 INFO: Load active rules
21:04:01.133 INFO: Load active rules (done) | time=28744ms
21:04:01.135 INFO: Load metrics repository
21:04:02.037 INFO: Load metrics repository (done) | time=902ms
21:04:02.116 INFO: Project key: <project key>
21:04:02.117 INFO: -------------  Scan <project name>
21:04:04.258 INFO: Base dir: <basedir>
21:04:04.258 INFO: Working dir: <basedir>/.scannerwork
21:04:04.259 INFO: Source paths: .
21:04:04.260 INFO: Source encoding: UTF-8, default locale: en_US
21:04:04.294 INFO: Load server rules
21:04:07.064 INFO: Load server rules (done) | time=2770ms
21:04:07.199 INFO: Index files
21:04:07.202 INFO: Included sources: 
21:04:07.203 INFO:   **/prj_cmrepo/**/*
21:04:07.203 INFO:   **/prj_common/**/*
21:04:07.203 INFO:   **/prj_comp1/**/*
21:04:07.203 INFO:   **/prj_comp2/**/*
21:04:07.203 INFO:   **/prj_custom/**/*
21:04:07.203 INFO: Excluded sources: 
21:04:07.203 INFO:   **/*.min.css
21:04:07.204 INFO:   **/*.min.js
21:04:07.204 INFO:   **/jquery*.css
21:04:07.204 INFO:   **/jquery*.js
21:04:07.204 INFO:   **/bootstrap*.css
21:04:07.204 INFO:   **/bootstrap*.js
21:04:07.204 INFO:   **/*.pack.js
21:04:07.204 INFO:   **/*.go
21:04:07.204 INFO:   **/*.py
21:04:07.204 INFO:   **/*.ts
21:04:07.204 INFO:   **/*.java
21:04:07.204 INFO:   **/*.js
21:04:07.205 INFO:   **/*.sh
21:04:07.205 INFO:   **/*.xml
21:04:07.205 INFO:   **/*.html
21:04:07.205 INFO:   **/*.pm
21:04:07.205 INFO:   **/*.pl
21:04:07.205 INFO:   **/*.css
21:04:07.205 INFO:   **/*.sql
21:04:07.205 INFO:   **/prj_tools/**/*
21:04:07.205 INFO:   **/moduletest/**/*
21:04:07.205 INFO:   **/thirdparty/**/*
21:04:07.205 INFO:   **/builds/**/*
21:04:07.206 INFO:   **/webcontent/**/*
21:04:07.206 INFO: Excluded tests: 
21:04:07.206 INFO:   **/*.xml
21:04:07.206 INFO:   **/*.xml
21:04:07.751 WARN: Not indexing due to symlink loop: ....
21:05:41.062 INFO: 164910 files indexed
21:05:41.062 INFO: 992474 files ignored because of inclusion/exclusion patterns
21:05:41.063 INFO: Quality profile for c: ABC
21:05:41.063 INFO: Quality profile for cpp: ABC
21:05:41.063 INFO: Quality profile for jsp: FindBugs Security JSP
21:05:41.063 INFO: Quality profile for objc: Sonar way
21:05:41.063 INFO: Quality profile for perl: Sonar way
21:05:41.063 INFO: Quality profile for php: Sonar way
21:05:41.063 INFO: Quality profile for web: Sonar way
21:05:48.611 INFO: Sensor org.sonar.plugins.clover.CloverSensor [clover]
21:05:48.611 WARN: Clover XML report not found
21:05:48.611 INFO: Sensor org.sonar.plugins.clover.CloverSensor [clover] (done) | time=0ms
21:05:48.611 INFO: Sensor JavaXmlSensor [java]
21:05:49.031 INFO: Sensor JavaXmlSensor [java] (done) | time=420ms
21:05:49.031 INFO: Sensor HTML [web]
21:05:49.943 INFO: Sensor HTML [web] (done) | time=911ms
21:05:49.943 INFO: Sensor Perl Squid Sensor [perl]
21:05:50.051 INFO: Sensor Perl Squid Sensor [perl] (done) | time=108ms
21:05:50.051 INFO: Sensor Perl 5 Sensor [perl]
21:05:50.099 INFO: Sensor Perl 5 Sensor [perl] (done) | time=48ms
21:05:50.099 INFO: Sensor PerlCritic Sensor [perl]
21:05:50.099 INFO: Configured report path: Optional[perlcritic_report.txt]
21:05:50.101 INFO: PerlCritic report file 'perlcritic_report.txt' does not exist. Skipping...
21:05:50.101 INFO: Sensor PerlCritic Sensor [perl] (done) | time=2ms
21:05:50.101 INFO: Sensor JaCoCo XML Report Importer [jacoco]
21:05:50.347 INFO: Sensor JaCoCo XML Report Importer [jacoco] (done) | time=246ms
21:05:50.348 INFO: Sensor jsp [findbugs]
21:05:50.617 INFO: Sensor jsp [findbugs] (done) | time=268ms
21:05:50.617 INFO: Sensor FindBugs Sensor [findbugs]
21:05:51.301 INFO: JavaClasspath initialization
21:05:51.381 INFO: JavaClasspath initialization (done) | time=79ms

The analysis does not proceed further and stays stuck here.

Environment

Component Version
SonarQube 6.7
Sonar-FindBugs 3.9.4
KengoTODA commented 4 years ago

Could you take threaddump by jcmd tool? It's better to take threaddump several times like this page, then we can compare them to grasp how threads were working.

pazhani82 commented 4 years ago

jcmd_topcpu.zip

Hello , PFA zip file which contains "jcmd_threaddump.out" and "top_highcpu.out" for analysis.

KengoTODA commented 4 years ago

Thanks. I found that the code is stacked around FindbugsConfiguration.scanForAdditionalClasses():

https://github.com/spotbugs/sonar-findbugs/blob/d5f03306b7543584eb23fbb3c6b41aefa9696bcb/src/main/java/org/sonar/plugins/findbugs/FindbugsConfiguration.java#L213-L229

I guess that we need to use the FileVisitor or streaming API to be more lazy.

"main" #1 prio=5 os_prio=0 tid=0x00007f1690008d70 nid=0x95b7 runnable [0x00007f1699229000]
   java.lang.Thread.State: RUNNABLE
    at org.sonar.plugins.findbugs.FindbugsConfiguration.scanForAdditionalClasses(FindbugsConfiguration.java:191)
    at org.sonar.plugins.findbugs.FindbugsConfiguration.getFindbugsProject(FindbugsConfiguration.java:85)
    at org.sonar.plugins.findbugs.FindbugsExecutor.execute(FindbugsExecutor.java:119)
    at org.sonar.plugins.findbugs.FindbugsSensor.execute(FindbugsSensor.java:119)
    at org.sonar.scanner.sensor.SensorWrapper.analyse(SensorWrapper.java:53)
"main" #1 prio=5 os_prio=0 tid=0x00007f1690008d70 nid=0x95b7 runnable [0x00007f1699229000]
   java.lang.Thread.State: RUNNABLE
    at java.io.UnixFileSystem.getBooleanAttributes0(Native Method)
    at java.io.UnixFileSystem.getBooleanAttributes(UnixFileSystem.java:242)
    at java.io.File.isFile(File.java:882)
    at org.sonar.plugins.findbugs.FindbugsConfiguration.scanForAdditionalClasses(FindbugsConfiguration.java:194)
    at org.sonar.plugins.findbugs.FindbugsConfiguration.getFindbugsProject(FindbugsConfiguration.java:85)
    at org.sonar.plugins.findbugs.FindbugsExecutor.execute(FindbugsExecutor.java:119)
    at org.sonar.plugins.findbugs.FindbugsSensor.execute(FindbugsSensor.java:119)
"main" #1 prio=5 os_prio=0 tid=0x00007f1690008d70 nid=0x95b7 runnable [0x00007f1699229000]
   java.lang.Thread.State: RUNNABLE
    at java.io.UnixFileSystem.list(Native Method)
    at java.io.File.list(File.java:1122)
    at java.io.File.listFiles(File.java:1207)
    at org.sonar.plugins.findbugs.FindbugsConfiguration.scanForAdditionalClasses(FindbugsConfiguration.java:191)
    at org.sonar.plugins.findbugs.FindbugsConfiguration.getFindbugsProject(FindbugsConfiguration.java:85)
    at org.sonar.plugins.findbugs.FindbugsExecutor.execute(FindbugsExecutor.java:119)
    at org.sonar.plugins.findbugs.FindbugsSensor.execute(FindbugsSensor.java:119)
    at org.sonar.scanner.sensor.SensorWrapper.analyse(SensorWrapper.java:53)
rngh101 commented 4 years ago

Thanks @KengoTODA for looking into this.

Couple of queries:

a) Do you mean that the plugin's scanForAdditionalClasses needs certain refactoring? Could you please explain why the thread may be getting stuck?

b) We did a couple of changes in the sonar-scanner-cli commandline: Disabled the Java plugin :: -Dsonar.excludePlugins=java,web,perl,ts,go Updated the java binaries path :: -Dsonar.java.binaries=./ims_do/java/ (Earlier sonar.java.binaries was configured as ".")

With these changes, the FindBugs sensor is not entering the "stuck/hung state". Instead it is logging a couple of WARNINGs and skipping execution: 14:13:20.477 INFO: Sensor jsp [findbugs] 14:13:20.712 INFO: Sensor jsp [findbugs] (done) | time=235ms 14:13:20.712 INFO: Sensor FindBugs Sensor [findbugs] 14:13:21.362 INFO: JavaClasspath initialization 14:13:21.425 INFO: JavaClasspath initialization (done) | time=63ms 14:13:21.445 WARN: Findbugs needs sources to be compiled. Please build project before executing sonar or check the location of compiled classes to make it possible for Findbugs to analyse your (sub)project (PROJECT PATH) 14:13:21.445 WARN: JSP files were found in the current (sub)project (PROJECT_PATH) but FindBugs requires their precompiled form. For more information on how to configure JSP precompilation : https://github.com/find-sec-bugs/find-sec-bugs/wiki/JSP-precompilation 14:13:21.458 INFO: Findbugs analysis skipped for this project. 14:13:21.459 INFO: Sensor FindBugs Sensor [findbugs] (done) | time=747ms

So, was setting the top-level directory "." as the sonar binaries path, the reason for the hung state?

c) In the original issue description, Java files have been marked as excluded? Still why is FindBugs sensor getting triggered for analysis? Is it because .jsp was not added in the exclusion list?

KengoTODA commented 4 years ago

14:13:21.445 WARN: Findbugs needs sources to be compiled. Please build project before executing sonar or check the location of compiled classes to make it possible for Findbugs to analyse your (sub)project (PROJECT PATH) 14:13:21.445 WARN: JSP files were found in the current (sub)project (PROJECT_PATH) but FindBugs requires their precompiled form. For more information on how to configure JSP precompilation : https://github.com/find-sec-bugs/find-sec-bugs/wiki/JSP-precompilation

This means that, your project contains some .jsp files but no .class file. In short your project configuration is incorrect.

c) In the original issue description, Java files have been marked as excluded? Still why is FindBugs sensor getting triggered for analysis?

Not sure. Recheck your config.

KengoTODA commented 4 years ago

a) Do you mean that the plugin's scanForAdditionalClasses needs certain refactoring? Could you please explain why the thread may be getting stuck?

I'm still working in the branch issue-318, but I haven't finished integrated test due to slow network yet.

KengoTODA commented 4 years ago

@rngh101 I confirmed that the plugin itself is working, could you compare its performance with 4.0.0 in your env? You can build and install the plugin file like below:

git clone git@github.com:spotbugs/sonar-findbugs.git
cd sonar-findbugs
git checkout issue-318
mvn package
cp target/sonar-findbugs-plugin.jar $SONARQUBE_HOME/extensions/plugins/

If we can confirm the performance improvement, I'll merge changes and release it as 4.0.1 (or later).