Two jobs run close together cause IllegalArgumentException for SCM plugin


(Josh Cummings) #1
  • versions used - SonarQube 6.7.3, SCM plugin enabled

  • error observed

We are using SonarQube to analyze Spring Security at Pivotal. When we make a check-in to git, our CI launches a SonarQube job against the appropriate branch (e.g. master or one of a couple feature branches).

Sometimes, two check-ins happen close enough to each other that two SonarQube jobs will run less than a couple of minutes apart. And when those two check-ins are from two different branches, SonarQube will complain with the following exception:

Caused by: java.lang.IllegalArgumentException: There's no changeset on line 117
	at com.google.common.base.Preconditions.checkArgument(Preconditions.java:145)
	at org.sonar.server.computation.task.projectanalysis.scm.ScmInfoImpl.getChangesetForLine(ScmInfoImpl.java:66)
	at org.sonar.server.computation.task.projectanalysis.scm.DbScmInfo.getChangesetForLine(DbScmInfo.java:71)
	at org.sonar.server.computation.task.projectanalysis.source.ScmLineReader.read(ScmLineReader.java:39)
	at org.sonar.server.computation.task.projectanalysis.source.ComputeFileSourceData.read(ComputeFileSourceData.java:61)
	at org.sonar.server.computation.task.projectanalysis.source.ComputeFileSourceData.compute(ComputeFileSourceData.java:48)
	at org.sonar.server.computation.task.projectanalysis.step.PersistFileSourcesStep$FileSourceVisitor.visitFile(PersistFileSourcesStep.java:120)

I figure that this is because somehow some kind of artifact from the first analysis is lingering while the second analysis is running, and the second analysis complains that the file being analyzed doesn’t look as it should (or as it did the last time).

When looking at the Background Tasks report, the launch time for the second job is after the completion time of the first job (IOW, no overlap), but if they are less than 2-3 minutes apart, then we always see this error.

Can you shed some light on what is happening here? For example, is there some cleanup step that the last job hasn’t completed yet? Is there a way to make the two jobs queue up and wait so that they aren’t clobbering each other?

  • steps to reproduce

Use the SCM plugin and point it at a git repo, configured for more than one branch. Launch two jobs close together, one against one branch and the other against another. An SCM background task will fail.

  • potential workaround

Perhaps we could solve this by having a project per feature branch; however, we’ve also seen a related bug when the two jobs are for the same branch.


(G Ann Campbell) #2

Hi,

To be clear, there’s no longer a supported SCM plugin; that functionality was incorporated into the core a long time ago. So… you don’t still have an SCM plugin in your instance, do you?

Assuming the answer is no, is there any more to that stacktrace than you’re showing? And if so, could you provide it here, please?

Do your two analyses run on the same CI node? I ask because I’ve never heard of this type of problem before, and I suspect that if there’s a lingering artifact anywhere it’s in your build machine. Are all your branches built/analyzed in the same workspace? And if so,would it be possible to clean the workspace between jobs?

 
Ann


(Josh Cummings) #3

Hi!

Sorry, no, we aren’t using a plugin. Thanks for clarifying.

Here is a full example stack trace:

org.sonar.server.computation.task.projectanalysis.component.VisitException: Visit of Component {key=org.springframework.security:spring-security:spring-security-acl:src/test/java/org/springframework/security/acls/jdbc/BasicLookupStrategyWithAclClassTypeTests.java,uuid=AV9rJyEGsEHb5JvBE97x,type=FILE} failed
	at org.sonar.server.computation.task.projectanalysis.component.VisitException.rethrowOrWrap(VisitException.java:44)
	at org.sonar.server.computation.task.projectanalysis.component.DepthTraversalTypeAwareCrawler.visit(DepthTraversalTypeAwareCrawler.java:41)
	at org.sonar.server.computation.task.projectanalysis.component.DepthTraversalTypeAwareCrawler.visitChildren(DepthTraversalTypeAwareCrawler.java:98)
	at org.sonar.server.computation.task.projectanalysis.component.DepthTraversalTypeAwareCrawler.visitImpl(DepthTraversalTypeAwareCrawler.java:54)
	at org.sonar.server.computation.task.projectanalysis.component.DepthTraversalTypeAwareCrawler.visit(DepthTraversalTypeAwareCrawler.java:39)
	at org.sonar.server.computation.task.projectanalysis.component.DepthTraversalTypeAwareCrawler.visitChildren(DepthTraversalTypeAwareCrawler.java:98)
	at org.sonar.server.computation.task.projectanalysis.component.DepthTraversalTypeAwareCrawler.visitImpl(DepthTraversalTypeAwareCrawler.java:54)
	at org.sonar.server.computation.task.projectanalysis.component.DepthTraversalTypeAwareCrawler.visit(DepthTraversalTypeAwareCrawler.java:39)
	at org.sonar.server.computation.task.projectanalysis.component.DepthTraversalTypeAwareCrawler.visitChildren(DepthTraversalTypeAwareCrawler.java:98)
	at org.sonar.server.computation.task.projectanalysis.component.DepthTraversalTypeAwareCrawler.visitImpl(DepthTraversalTypeAwareCrawler.java:54)
	at org.sonar.server.computation.task.projectanalysis.component.DepthTraversalTypeAwareCrawler.visit(DepthTraversalTypeAwareCrawler.java:39)
	at org.sonar.server.computation.task.projectanalysis.step.PersistFileSourcesStep.execute(PersistFileSourcesStep.java:89)
	at org.sonar.server.computation.task.step.ComputationStepExecutor.executeSteps(ComputationStepExecutor.java:64)
	at org.sonar.server.computation.task.step.ComputationStepExecutor.execute(ComputationStepExecutor.java:52)
	at org.sonar.server.computation.task.projectanalysis.taskprocessor.ReportTaskProcessor.process(ReportTaskProcessor.java:73)
	at org.sonar.ce.taskprocessor.CeWorkerImpl.executeTask(CeWorkerImpl.java:134)
	at org.sonar.ce.taskprocessor.CeWorkerImpl.findAndProcessTask(CeWorkerImpl.java:97)
	at org.sonar.ce.taskprocessor.CeWorkerImpl.withCustomizedThreadName(CeWorkerImpl.java:81)
	at org.sonar.ce.taskprocessor.CeWorkerImpl.call(CeWorkerImpl.java:73)
	at org.sonar.ce.taskprocessor.CeWorkerImpl.call(CeWorkerImpl.java:43)
	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
	at java.lang.Thread.run(Thread.java:748)
Caused by: java.lang.IllegalStateException: Cannot persist sources of org.springframework.security:spring-security:spring-security-acl:src/test/java/org/springframework/security/acls/jdbc/BasicLookupStrategyWithAclClassTypeTests.java
	at org.sonar.server.computation.task.projectanalysis.step.PersistFileSourcesStep$FileSourceVisitor.visitFile(PersistFileSourcesStep.java:123)
	at org.sonar.server.computation.task.projectanalysis.component.DepthTraversalTypeAwareCrawler.visitNode(DepthTraversalTypeAwareCrawler.java:79)
	at org.sonar.server.computation.task.projectanalysis.component.DepthTraversalTypeAwareCrawler.visitImpl(DepthTraversalTypeAwareCrawler.java:51)
	at org.sonar.server.computation.task.projectanalysis.component.DepthTraversalTypeAwareCrawler.visit(DepthTraversalTypeAwareCrawler.java:39)
	... 26 more
Caused by: java.lang.IllegalArgumentException: There's no changeset on line 117
	at com.google.common.base.Preconditions.checkArgument(Preconditions.java:145)
	at org.sonar.server.computation.task.projectanalysis.scm.ScmInfoImpl.getChangesetForLine(ScmInfoImpl.java:66)
	at org.sonar.server.computation.task.projectanalysis.scm.DbScmInfo.getChangesetForLine(DbScmInfo.java:71)
	at org.sonar.server.computation.task.projectanalysis.source.ScmLineReader.read(ScmLineReader.java:39)
	at org.sonar.server.computation.task.projectanalysis.source.ComputeFileSourceData.read(ComputeFileSourceData.java:61)
	at org.sonar.server.computation.task.projectanalysis.source.ComputeFileSourceData.compute(ComputeFileSourceData.java:48)
	at org.sonar.server.computation.task.projectanalysis.step.PersistFileSourcesStep$FileSourceVisitor.visitFile(PersistFileSourcesStep.java:120)
	... 29 more

No, each build step runs on a different CI node, and steps are queued until there is a node available.

In this particular circumstance (the above stacktrace), according to the Background Tasks report, there were two background tasks launched within 27 seconds of each other. Each corresponding job was launched from their own CI node. The command that was run was “gradle clean sonarqube -Dsonar.host.url=…”, which I would imagine takes care of any artifacts on the node before executing.

According to the “Scanner Context” dialog, the jobs were pointed at:

/opt/jenkins/data/workspace/spring-security_5.1.x-KCVITYAWIYE456MKR5HMIGPZMO5SXJ3U422FRL3YS32MFO4X6D3Q/acl/src/main/java

and

/opt/jenkins/data/workspace/spring-security_master-FDWQXDHFCLNXTJ6RG6KRJCVRVU3MQIHVK2YGAKELBS27Z27ANRXQ/acl/src/main/java

respectively. So, even if they were on the same CI node, it makes me wonder how a collision would be occurring from that perspective.


(Josh Cummings) #4

Also, if it’s helpful, the error that we see when it is the same branch (e.g. two master builds right next to each other) is different:

"Validation of project failed:
  o Date of analysis cannot be older than the date of the last known analysis on this project. Value: "2018-09-21T13:18:44+0000". Latest analysis: "2018-09-21T13:19:12+0000". It's only possible to rebuild the past in a chronological order."

(Colin Mueller) #7

Greetings @jzheaux ,

I’m actually looking at a support case with a similar error – looking for a correlation between your issue and this other user’s issue. Could you provide a full list of plugins and their versions installed on your instance?

Thanks,

Colin


(Josh Cummings) #8

I collected these from “Administration -> Marketplace”:

Build Breaker 2.2
Checkstyle 3.7
Clirr 1.3
Clover 3.1
Cobertura 1.9.1
Findbugs 3.6.0
Github 1.4.2.1027
Groovy 1.5
PMD 2.6
SonarJava 4.15.0.12310
SonarQube::Plugins::SCM::Git 1.3.0.869
Sonargraph 3.5
Structure101 5.6.12680
Timeline 1.5


(G Ann Campbell) #9

Hi,

Aside from anything else, your plugin collection is pretty dusty.

Not supported (by us) for a loong time.

Current version 4.11

Abandoned community plugin

Current version 2.0.0, and the description for this release is “Compatibility with SonarQube 6.7”, so…

Current version 3.8.0

Current version 3.0.1

Current version 5.9.1

Current version 1.4.1

This stopped being relevant when dashboards were dropped in IIRC 6.2

I recently saw another case were a problem plugin interfered with native functionality, so I’m wondering if you could clean up your plugins and verify that the problem persists (or not).

 
Ann


(Josh Cummings) #10

Ann, I’ve forwarded that info on, and I’ll get back to you. Thank you for the extra insight about each plugin.


(Josh Cummings) #11

After upgrading plugins, and also disabling the SCM sensor, we have not seen the error for a couple of weeks. We’ll turn on the SCM sensor soon and see what happens with builds at that point.

However, even with the upgraded plugins and disabling the SCM sensor, we saw this today on two builds very close together (15 seconds apart):

Validation of project failed:
  o Date of analysis cannot be older than the date of the last known analysis on this project. Value: "2018-11-30T18:14:19+0000". Latest analysis: "2018-11-30T18:14:21+0000". It's only possible to rebuild the past in a chronological order.

No stack trace in the Background Tasks UI.

It’s as if these share some state in memory somehow? Note that the first Background Tasks always completes successfully. I noted on this one that the second background task fails a few seconds after the first completes.

These are two different branches of the code on two different build machines, two different workspaces, publishing to the same SonarQube instance and the same SonarQube project.


(G Ann Campbell) #12

Hi,

This is as designed. You cannot analyze retroactively. That is, you cannot post an analysis dated before the last analysis (I hear you thinking “duh, that’s what the error already told me”) because it would totally mess up the project “history”.

I believe that the problem here is that the timestamp in analysis2 is before the timestamp on the background task of analysis1. I can’t tell you the exact rules about whether the important times are analysis/background task begin or end, but I’m pretty sure that’s the source of this problem.

What I’d recommend is that you impose a quiet period on the analysis job and/or don’t let multiple iterations run in parallel (I’m assuming analysis takes >15 seconds).

 
HTH,
Ann


(Josh Cummings) #13

Okay, I think I’m understanding.

What appears to happen is, two analyses are started for the same project at roughly the same time, sometimes causing the following:

Run A marks a timestamp for its analysis
Run B marks a timestamp for its analysis
Run B schedules a background task
Run A schedules a background task (which has to wait now since Run B’s background task is now running)

Once Run B’s background task finishes and the analysis completes, Run A’s background task begins, but now its analysis date is older than the most recent => failure. Anything wrong with my thinking there?

AFAIK, Jenkins supports a quiet period per-branch, so that wouldn’t fix this across our feature branches, but I agree that it would help when we happen to launch multiple builds on the same branch. Thanks for the tip.

As for the competing branches, I’m thinking we’ll do a separate sonar project for each branch.


(G Ann Campbell) #14

Hi,

That’s a plausible scenario, altho TBH, race condition didn’t occur to me. I just assumed the job that started first finished first. But yes, in the scenario you describe (B finishes first) that’s exactly the behavior you would get.

Coming back to the initial branch conflict, in very quickly reviewing the thread I notice that you’re on 6.7.3. The current version of the LTS is 6.7.6, altho looking over the release notes (6.7.4, 6.7.5, 6.7.6) I don’t anything that seems immediately relevant to the question.

Before you go to a project-per-branch strategy (because that will explode your instance LOC & therefore increase your bill) let’s take another look at this. You say the error disappeared when you disabled the SCM integration. Can you turn it back on and see if the problem comes back? And if it does, could you bump up your server log level to TRACE just log enough to reproduce this error (Administration > System > Logs level) and post any relevant log excerpts? You’ll want to turn the logging level back down as soon as you’ve reproduced the error, BTW, since TRACE logging impacts performance and produces lots of logs.

 
Ann