6

I know this is similar to sonarqube 5.2 background tasks sometimes fail with no log - however I cannot comment (due to lack of reputation points) to add some more information, so tried adding this post as an answer, but had it deleted by the moderators...

I was having a problem with SonarQube 5.2, and now 5.3 following an upgrade yesterday. I have tried upping the logging to TRACE on the server, and enabling sonar.verbose=true on the project itself.

However, there is no extra information in the output from the maven build - just the normal:

ANALYSIS SUCCESSFUL, you can browse xxx in the build logs.

I do see a POST /api/ce/submit?projectKey=xxxx&projectName=yyyy | time=757ms in the server log files - but nothing further.

I also see a zip file in data\ce\reports with a name matches the id in build log (eg: AVI19fDPpe3MLWoccJn9.zip)

However - I get intermittent failures on the background tasks screen - with no log link in the background tasks screen, and no logs in data\ce\logs\reports directory created.

I resorted to re-building the sonarqube database from scratch for 5.3 (as we had no history anyway) - and the error was still happening.

I am using:

  • Oracle DB on a fresh sonarqube 5.3 install
  • Plugins:
    • sonar-java-plugin-3.9
    • sonar-ldap-plugin-1.5.1
    • sonar-scm-perforce-plugin-1.3 (although currently have sonar.scm.disabled=true as we had problems in the previous version)
    • sonar-csharp-plugin-4.3 (not relevant for this java analysis)
    • sonar-scm-git-plugin-1.1 (not relevant for this analysis)
    • sonar-scm-svn-plugin-1.2 (not relevant for this analysis)
  • I'm building a Maven project using sonar-jacoco-listeners v 3.2 (have also tried 2.9.1)
Community
  • 1
  • 1
Rohan Pynor
  • 61
  • 1
  • 4
  • When you activate the "DEBUG" level for the logs, can you copy-paste somewhere (pastebin.org for instance) what it written in the "logs/sonar.log" file after you have run an analysis? – Fabrice - SonarSource Team Jan 13 '16 at 09:57
  • Log files are here : https://gist.github.com/rpynor/d35ed08ecab0a40a4d0a – Rohan Pynor Jan 13 '16 at 11:14
  • For this particular analysis - there was a zip file created in data/ce/reports called AVI6rosFQGlYbPrUc57o.zip, and there were no log files generated in data/ce/logs/report. Additionally, the dashboard shows the background as failed with a duration of 31 ms with no log file link – Rohan Pynor Jan 13 '16 at 11:18
  • I should also add, for completeness that we are hosting this on a Windows 2008 R2 Server. – Rohan Pynor Jan 13 '16 at 11:22
  • This is weird, you should have at least one line "web[o.s.s.c.t.CeWorkerCallableImpl] Execute task" in the "sonar.log" file if you say that you see a failed background task... Can you activate the "TRACE" level for the logs and copy-paste it again? – Fabrice - SonarSource Team Jan 13 '16 at 13:42
  • I do see that for a run that worked earlier, ovenight last night - 2016.01.13 02:38:35 INFO web[o.s.s.c.t.CeWorkerCallableImpl] Execute task | project=com.xxx.xxx.xxx.asf-parent | id=AVI42Vv2MSzbk9eumfw8 2016.01.13 02:50:45 INFO web[o.s.s.c.t.CeWorkerCallableImpl] Executed task | project=com.xxx.xxx.xxx:asf-parent | id=AVI42Vv2MSzbk9eumfw8 | time=729848ms – Rohan Pynor Jan 13 '16 at 15:26
  • and the analysis I just ran appears to have queued up successfully. – Rohan Pynor Jan 13 '16 at 15:27
  • Had another failure - trace log is here: https://gist.github.com/rpynor/e21efd54635006416b51 – Rohan Pynor Jan 13 '16 at 16:21
  • I upgraded to jre1.8.0_51 from 1.7.0_15-b03 (in the wrapper.conf) and have had several successful background runs. I will let the overnight builds run to see if this makes a difference. – Rohan Pynor Jan 13 '16 at 20:35
  • No luck - still getting intermittent failures - the same project will sometimes work, sometimes not. – Rohan Pynor Jan 14 '16 at 08:37
  • Can you make sure that you don't have 2 SonarQube instances that point to the same DB? – Fabrice - SonarSource Team Jan 14 '16 at 16:13
  • No - I have double checked - we only have one Sonar Instance – Rohan Pynor Jan 14 '16 at 16:27

1 Answers1

11

You are facing a very odd issue.

To sum it up:

  • from time to times
  • a background task is processed without any log in sonar.log nor a task log in the data/ce/logs directory
  • the task failed (as visible in the UI of SQ)
  • it ran for a very short time
  • the report zip file is still present in the data directory

The only time we faced such a scenario, it turned out two SonarQube instances were running on the same database and here is what was going on:

  • SQ A (the one you are aware of and monitoring) receives the report, save the zip file to its data directory and adds an entry (a background task) in the DB
  • SQ A and SQ B both poll the DB regularly for PENDING items to process. Sometimes, SQ B will be the first one to pick the entry from the DB and starts processing it. Since the report is not in its data directory, the processing very quickly fails and the entry is flagged as failed in the DB
  • SQ A never tries to process the entry, because from its point of view, it is either PROCESSING (when SQ B is working on it) or FAILED (when SQ B is done with it). Only items PENDING can be processed. So, no log ever shows up in SQ A's sonar.log and no task log is created either. Still, in the UI the background task is displayed as failed because the UI shows information from the DB.

A good hint that the processing (ie. change of state of the entry in DB) wasn't done by the SQ A is that the report zip file is still present in the data directory. The change of state of the entry to FAIL or SUCCESS is tightly coupled with the deletion of the zip file.

It's only a hint since the deletion could also have failed, but in such case, you would have a ERROR in the logs.

Seb - SonarSource Team
  • 942
  • 4
  • 9
  • 1
    Embarrassingly, it looks like you are correct. Someone else in the organisation had 'borrowed' our oracle schema to run their own instance of SonarQube against - I will evict them and hopefully the issue will be resolved. – Rohan Pynor Jan 15 '16 at 15:33
  • Thank you so much for this answer! I've experienced the same issue and couldn't imagine it was a second SQ instance. But after enabling some database connection logging I found a second one - somebody had cloned my VM running SQ and forgotten to change the database connection. You saved me at least a few days tearing one's hair :D – Alex Jan 22 '16 at 13:03