Overview
We are running SonarQube version 5.0 and have encountered a problem with some of our builds failing. The build log states:
[10:12:42][Exec] 10:12:42.873 DEBUG - Loaded 2058 properties from l10n bundles
[10:12:43][Exec] 10:12:43.642 INFO - Load project referentials...
[10:13:03][Exec] 10:13:03.637 INFO - Load project referentials done: 19995 ms
[10:13:03][Exec] INFO: ------------------------------------------------------------------------
[10:13:03][Exec] INFO: EXECUTION FAILURE
[10:13:03][Exec] INFO: ------------------------------------------------------------------------
[10:13:03][Exec] Total time: 27.272s
[10:13:03][Exec] Final Memory: 20M/316M
[10:13:03][Exec] INFO: ------------------------------------------------------------------------
[10:13:03][Exec] EXEC Error during Sonar runner execution
[10:13:03][Exec] org.sonar.runner.impl.RunnerException: Unable to execute Sonar
[10:13:03][Exec] at org.sonar.runner.impl.BatchLauncher$1.delegateExecution(BatchLauncher.java:91)
[10:13:03][Exec] at org.sonar.runner.impl.BatchLauncher$1.run(BatchLauncher.java:75)
[10:13:03][Exec] at java.security.AccessController.doPrivileged(Native Method)
[10:13:03][Exec] at org.sonar.runner.impl.BatchLauncher.doExecute(BatchLauncher.java:69)
[10:13:03][Exec] at org.sonar.runner.impl.BatchLauncher.execute(BatchLauncher.java:50)
[10:13:03][Exec] at org.sonar.runner.api.EmbeddedRunner.doExecute(EmbeddedRunner.java:102)
[10:13:03][Exec] at org.sonar.runner.api.Runner.execute(Runner.java:100)
[10:13:03][Exec] at org.sonar.runner.Main.executeTask(Main.java:70)
[10:13:03][Exec] at org.sonar.runner.Main.execute(Main.java:59)
[10:13:03][Exec] at org.sonar.runner.Main.main(Main.java:53)
[10:13:03][Exec] Caused by: java.lang.IllegalStateException: Unable to request: /batch/project?key=xxxx.xxx&preview=false
Eventually we came across two Sonar defects both which state they are fixed in version 5.1:
So we needed to upgrade Sonar from version 5.0 to (at least) 5.1
Given the latest version of Sonar is 5.3 it made sense to upgrade to the latest version, it couldn't be that hard could it?
Given that Sonar is a Java application (and therefore all of the files needed are in a directory rather than a Windows install) the upgrade is fairly straight forward:
- Backup the SonarQube database
- Snapshot the VM
- Extract SonarQube-5.3.zip
- Run D:\Sonar\sonarqube-5.0\bin\windows-x86-64\UninstallNTService.bat to uninstall the existing Sonar Service.
- Copy the plugins from D:\Sonar\SonarQube-5.0\Extensions\Plugins to D:\Sonar\SonarQube-5.3\Extensions\Plugins
- Update the D:\Sonar\SonarQube-5.3\conf\sonar.properties file with the changes for SQL connectivity, http proxy and LDAP configuration from the SonarQube-5.0 sonar.properties file.
- Run D:\Sonar\sonarqube-5.3\bin\windows-x86-64\InstallNTService.bat to uninstall the existing Sonar Service.
- Start the SonarQube service
Let's do it
After getting the VM and database backed up I was ready to begin, so I extracted the SonarQube-5.3 zip file on the server and run the batch file to unregister the service that we use to start SonarQube (taking note of the user that it runs under).
The next step was to update the sonar.properties file (found in the conf folder) with the information from the existing version (as the Sonar 5.0 install was in a different folder this was fairly straight forward).
- Entered the SQL connection string
- In the Update Center part I had to enter our proxy server details
- As we use the LDAP plugin (so we can login using our network IDs) I needed to copy of this configuration.
Next I copied the plugins from the Sonar 5.0 folder over.
Starting Sonar
Now that the config was correct I registered the service and set it to run as the same user. Then I started the service and then I looked at the logs/sonar.log file to see what was happening:
2016.03.02 17:56:28 INFO web[o.s.s.p.ServerImpl] SonarQube Server / 5.3 / 8db783e62b266eeb0d0b10dc050a7ca50e96c5d1
2016.03.02 17:56:28 INFO web[o.sonar.db.Database] Create JDBC data source for jdbc:sqlserver://xxxxxxx;databaseName=SonarQube;integratedSecurity=true
2016.03.02 17:56:30 WARN web[o.s.s.p.DatabaseServerCompatibility] Database must be upgraded. Please backup database and browse /setup
2016.03.02 17:56:30 INFO web[o.s.s.p.DefaultServerFileSystem] SonarQube home: D:\Sonar\sonarqube-5.3
2016.03.02 17:56:30 INFO es[o.e.cluster.metadata] [sonar-1456941379001] [rules] creating index, cause [api], templates [], shards [1]/[0], mappings []
2016.03.02 17:56:31 INFO es[o.e.cluster.metadata] [sonar-1456941379001] [rules] create_mapping [rule]
2016.03.02 17:56:31 INFO es[o.e.cluster.metadata] [sonar-1456941379001] [rules] create_mapping [activeRule]
2016.03.02 17:56:31 ERROR web[o.a.c.c.C.[.[.[/]] Exception sending context initialized event to listener instance of class org.sonar.server.platform.PlatformServletContextListener
org.sonar.api.utils.MessageException: File is not a plugin. Please delete it and restart: D:\Sonar\sonarqube-5.3\extensions\plugins\sonar-ant-task-2.3.jar
2016.03.02 17:56:31 INFO web[jruby.rack] jruby 1.7.9 (ruby-1.8.7p370) 2013-12-06 87b108a on Java HotSpot(TM) 64-Bit Server VM 1.7.0_45-b18 [Windows Server 2008 R2-amd64]
2016.03.02 17:56:31 INFO web[jruby.rack] using a shared (threadsafe!) runtime
2016.03.02 17:56:35 ERROR web[jruby.rack] initialization failed
org.jruby.rack.RackInitializationException: java.lang.NullPointerException
at org.jruby.rack.RackInitializationException.wrap(RackInitializationException.java:31) ~[jruby-rack-1.1.13.2.jar:na]
at org.jruby.rack.RackApplicationFactoryDecorator.init(RackApplicationFactoryDecorator.java:98) ~[jruby-rack-1.1.13.2.jar:na]
at org.jruby.rack.RackServletContextListener.contextInitialized(RackServletContextListener.java:50) ~[jruby-rack-1.1.13.2.jar:na]
Ok, so it doesn't like the ant plugin that we use, upon looking this doesn't look to be an actual Sonar plugin but something that is required on the local machines so I move it out of the directory and started the service again.
Thankfully it looked to be ok but needed the database to be upgraded. The logs state to browse to the URL followed by /setup to do this.
This was a new page that you had to click on the upgrade button and state that you have a backup of the database, upon clicking the link it quickly stated that the database upgrade failed. Oh joy.
Looking at the sonar.properties file once again to be sure that the connection settings were ok I spotted a problem:
#----- Microsoft SQLServer 2008/2012/2014 and SQL Azure
# A database named sonar must exist and its collation must be case-sensitive (CS) and accent-sensitive (AS)
# Use the following connection string if you want to use integrated security with Microsoft Sql Server
# Do not set sonar.jdbc.username or sonar.jdbc.password property if you are using Integrated Security
# For Integrated Security to work, you have to download the Microsoft SQL JDBC driver package from
# http://www.microsoft.com/en-us/download/details.aspx?displaylang=en&id=11774
# and copy sqljdbc_auth.dll to your path. You have to copy the 32 bit or 64 bit version of the dll
# depending upon the architecture of your server machine.
# This version of SonarQube has been tested with Microsoft SQL JDBC version 4.1
We already use the JDBC driver so that wasn't an issue, the problem is that our database is called SonarQube and not Sonar.
Thankfully the DBAs could resolve this pretty quickly for me.
I amended the config (and also turned on extra logging), started the service and tried to upgrade the database again, still no joy.
The log file stated:
2016.03.02 18:46:53 INFO web[o.s.d.v.v.FixMsSqlCollation] Updating columns from table schema_migrations
2016.03.02 18:46:53 ERROR web[o.s.s.d.m.DatabaseMigrator] Fail to execute database migration: org.sonar.db.version.v53.FixMsSqlCollation
java.lang.IllegalStateException: Fail to execute DROP INDEX unique_schema_migrations ON schema_migrations
at org.sonar.db.version.DdlChange$Context.execute(DdlChange.java:70) ~[sonar-db-5.3.jar:na]
at org.sonar.db.version.v53.FixMsSqlCollation$UpdateTableCollation.removeIndexes(FixMsSqlCollation.java:504) ~[sonar-db-5.3.jar:na]
at org.sonar.db.version.v53.FixMsSqlCollation$UpdateTableCollation.execute(FixMsSqlCollation.java:492) ~[sonar-db-5.3.jar:na]
After trying the upgrade again the page stated that a problem had occurred but looking at the log file it stated that the upgrade of the database was successful.
I was able to login to Sonar and appeared to look good so I ran a build through TeamCity to confirm that it was ok, I initially tried the Finance build but this failed (due to some NuGet packages being out of date - not related) so I tried a Product build. The build was previously green so it should go through with no errors.
Unfortunately this wasn't the case and looking at the build log file I was presented with this error:
[19:12:31] : [Exec] INFO: ------------------------------------------------------------------------
[19:12:31] : [Exec] INFO: EXECUTION FAILURE
[19:12:31] : [Exec] INFO: ------------------------------------------------------------------------
[19:12:31] : [Exec] Total time: 6.395s
[19:12:31]E: [Exec] EXEC Error during Sonar runner execution
[19:12:31] : [Exec] Final Memory: 9M/156M
[19:12:31] : [Exec] INFO: ------------------------------------------------------------------------
[19:12:31] : [Exec] org.sonar.runner.impl.RunnerException: Unable to execute Sonar
[19:12:31] : [Exec] at org.sonar.runner.impl.BatchLauncher$1.delegateExecution(BatchLauncher.java:91)
[19:12:31] : [Exec] at org.sonar.runner.impl.BatchLauncher$1.run(BatchLauncher.java:75)
[19:12:31] : [Exec] at java.security.AccessController.doPrivileged(Native Method)
[19:12:31] : [Exec] at org.sonar.runner.impl.BatchLauncher.doExecute(BatchLauncher.java:69)
[19:12:31] : [Exec] at org.sonar.runner.impl.BatchLauncher.execute(BatchLauncher.java:50)
[19:12:31] : [Exec] at org.sonar.runner.api.EmbeddedRunner.doExecute(EmbeddedRunner.java:102)
[19:12:31] : [Exec] at org.sonar.runner.api.Runner.execute(Runner.java:100)
[19:12:31] : [Exec] at org.sonar.runner.Main.executeTask(Main.java:70)
[19:12:31] : [Exec] at org.sonar.runner.Main.execute(Main.java:59)
[19:12:31] : [Exec] at org.sonar.runner.Main.main(Main.java:53)
[19:12:31] : [Exec] Caused by: java.lang.IllegalStateException: Unable to register extension org.sonar.plugins.javascript.JavaScriptSquidSensor
Upon checking our Javascript plugin we were using version 2.5 and the latest version was version 2.10, so I downloaded the new version and put it into the 'extensions\plugins' folder and tried again.
This time I had the same problem with Sonar Build Breaker problem which needed to be upgraded version 1.1 to 2.0 and I tried again...
Next it was the C# plugin that needed to be upgraded from version 3.3 to 4.5. However upgrading this version gave another side effect, it required .Net 4.5.2 to be installed on the build agents.
I then tried the build on a build agent with .Net 4.6 installed and crossed my fingers....
[19:53:58] : [Exec] 19:53:58.454 INFO - Analysis report generated in F:\TeamCity\buildAgent\work\a2e9533bd348fbbc\source\.\.sonar\batch-report
[19:53:58] : [Exec] INFO: ------------------------------------------------------------------------
[19:53:58] : [Exec] INFO: EXECUTION FAILURE
[19:53:58] : [Exec] INFO: ------------------------------------------------------------------------
[19:53:58] : [Exec] Total time: 12:28.997s
[19:53:59] : [Exec] Final Memory: 7M/122M
[19:53:59] : [Exec] INFO: ------------------------------------------------------------------------
[19:53:59]E: [Exec] EXEC Error during Sonar runner execution
[19:53:59] : [Exec] org.sonar.runner.impl.RunnerException: Unable to execute Sonar
[19:53:59] : [Exec] at org.sonar.runner.impl.BatchLauncher$1.delegateExecution(BatchLauncher.java:91)
[19:53:59] : [Exec] at org.sonar.runner.impl.BatchLauncher$1.run(BatchLauncher.java:75)
[19:53:59] : [Exec] at java.security.AccessController.doPrivileged(Native Method)
[19:53:59] : [Exec] at org.sonar.runner.impl.BatchLauncher.doExecute(BatchLauncher.java:69)
[19:53:59] : [Exec] at org.sonar.runner.impl.BatchLauncher.execute(BatchLauncher.java:50)
[19:53:59] : [Exec] at org.sonar.runner.api.EmbeddedRunner.doExecute(EmbeddedRunner.java:102)
[19:53:59] : [Exec] at org.sonar.runner.api.Runner.execute(Runner.java:100)
[19:53:59] : [Exec] at org.sonar.runner.Main.executeTask(Main.java:70)
[19:53:59] : [Exec] at org.sonar.runner.Main.execute(Main.java:59)
[19:53:59] : [Exec] at org.sonar.runner.Main.main(Main.java:53)
[19:53:59] : [Exec] Caused by: java.lang.IllegalStateException: Report processing did not complete successfully: FAILED
[19:53:59] : [Exec] at org.sonar.plugins.buildbreaker.QualityGateBreaker.getAnalysisId(QualityGateBreaker.java:138)
[19:53:59] : [Exec] at org.sonar.plugins.buildbreaker.QualityGateBreaker.execute(QualityGateBreaker.java:94)
[19:53:59] : [Exec] at org.sonar.plugins.buildbreaker.QualityGateBreaker.executeOn(QualityGateBreaker.java:81)
This was more of a problem. The error was clearly with the Build Breaker problem (which was already upgraded) and we need so that Team City can be aware of broken builds.
It was at this point (after over 3 hours of trying and the security guard trying to kick me out of the building) that I decided to abort the upgrade and try again another day.
Update
I eventually found that the cause of my problem was due to a defect with the Sonar Build Breaker plug-in.
We had Sonar configured with two checks on Technical Debt.
We had a rule stating that Technical Debt could not be greater than 5 days, we also had a rule stating that technical debt could not have increased by 0.5 day from the previous build.
This is due to be resolved in Sonar 5.6, in the meantime we just removed the second check.
For more details on the defect check out the issue (
Sonar-7276)