Uploaded image for project: 'SonarQube'
  1. SonarQube
  2. SONAR-11278

Failing step in the compute engine is not logged

    XMLWordPrintable

    Details

    • Type: Bug
    • Status: Closed
    • Priority: Major
    • Resolution: Fixed
    • Affects Version/s: 7.3
    • Fix Version/s: 7.4
    • Component/s: Compute Engine
    • Labels:
    • Edition:
      Community
    • Production Notes:
      None

      Description

      Steps of execution of tasks such as report processing are logged.
      However, when an error occurs, the failing task informations are not logged.
      This implies that the last step visible in logs is the one previous to the failing one, which can be misleading.
      On top of this, the duration of the failing step is lost and so are the step statistics (some may have been computed before the step failed).

      In the following stacktrace, an error was raised in step "Verify Billing" but the last visible step is "Initializing".

      2018.09.18 10:45:04 INFO  ce[AWXr2rcJFozSdSzRWjVE][o.s.c.t.CeWorkerImpl] Execute task | project=pampers-rewards-android | type=REPORT | pullRequest=199 | id=AWXr2rcJFozSdSzRWjVE | submitter=alizahid@github
      2018.09.18 10:45:05 INFO  ce[AWXr2rcJFozSdSzRWjVE][o.s.c.t.s.ComputationStepExecutor] Extract report | time=51ms
      2018.09.18 10:45:05 INFO  ce[AWXr2rcJFozSdSzRWjVE][o.s.c.t.s.ComputationStepExecutor] Persist scanner context | time=40ms
      2018.09.18 10:45:05 INFO  ce[AWXr2rcJFozSdSzRWjVE][o.s.c.t.s.ComputationStepExecutor] Execute DB migrations for current project | time=14ms
      2018.09.18 10:45:05 INFO  ce[AWXr2rcJFozSdSzRWjVE][o.s.c.t.s.ComputationStepExecutor] Generate analysis UUID | time=0ms
      2018.09.18 10:45:05 INFO  ce[AWXr2rcJFozSdSzRWjVE][o.s.c.t.s.ComputationStepExecutor] Load analysis metadata | time=20ms
      2018.09.18 10:45:05 INFO  ce[AWXr2rcJFozSdSzRWjVE][o.s.c.t.s.ComputationStepExecutor] Initialize | time=0ms
      2018.09.18 10:45:05 ERROR ce[AWXr2rcJFozSdSzRWjVE][o.s.c.t.p.a.p.PostProjectAnalysisTasksExecutor] Execution of task class com.sonarsource.branch.pr.PrPostProjectAnalysisTask failed
      java.lang.IllegalStateException: Holder has not been initialized yet
              at com.google.common.base.Preconditions.checkState(Preconditions.java:173)
              at org.sonar.ce.task.projectanalysis.component.TreeRootHolderImpl.checkInitialized(TreeRootHolderImpl.java:104)
              at org.sonar.ce.task.projectanalysis.component.TreeRootHolderImpl.getRoot(TreeRootHolderImpl.java:50)
              at com.sonarsource.branch.pr.PrPostProjectAnalysisTask.createPrData(PrPostProjectAnalysisTask.java:68)
              at com.sonarsource.branch.pr.PrPostProjectAnalysisTask.lambda$finished$1(PrPostProjectAnalysisTask.java:61)
              at java.util.Optional.ifPresent(Optional.java:159)
              at com.sonarsource.branch.pr.PrPostProjectAnalysisTask.finished(PrPostProjectAnalysisTask.java:60)
              at org.sonar.ce.task.projectanalysis.api.posttask.PostProjectAnalysisTasksExecutor.executeTask(PostProjectAnalysisTasksExecutor.java:113)
              at org.sonar.ce.task.projectanalysis.api.posttask.PostProjectAnalysisTasksExecutor.finished(PostProjectAnalysisTasksExecutor.java:107)
              at org.sonar.ce.task.step.ComputationStepExecutor.executeListener(ComputationStepExecutor.java:76)
              at org.sonar.ce.task.step.ComputationStepExecutor.execute(ComputationStepExecutor.java:59)
              at org.sonar.ce.task.projectanalysis.taskprocessor.ReportTaskProcessor.process(ReportTaskProcessor.java:81)
              at org.sonar.ce.taskprocessor.CeWorkerImpl.executeTask(CeWorkerImpl.java:136)
              at org.sonar.ce.taskprocessor.CeWorkerImpl.findAndProcessTask(CeWorkerImpl.java:99)
              at org.sonar.ce.taskprocessor.CeWorkerImpl.withCustomizedThreadName(CeWorkerImpl.java:83)
              at org.sonar.ce.taskprocessor.CeWorkerImpl.call(CeWorkerImpl.java:75)
              at org.sonar.ce.taskprocessor.CeWorkerImpl.call(CeWorkerImpl.java:45)
              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)
      2018.09.18 10:45:05 INFO  ce[AWXr2rcJFozSdSzRWjVE][o.s.c.t.CeWorkerImpl] Executed task | project=pampers-rewards-android | type=REPORT | pullRequest=199 | id=AWXr2rcJFozSdSzRWjVE | submitter=alizahid@github | status=FAILED | time=848ms
      

      fix

      1. Failing step is logged as INFO
        • step should not be logged as ERROR to not create noise. Either an error occurred and another log as ERROR will follow the steps logs, or a functional error occurred and in this case we don't want an ERROR log as only the user can act on it.
      2. if any context information for the step was provided before the failure, it should be logged
      3. To provide the information that the step failed, a status "field" will be added to all the step logs. Possibles values are "SUCCESS" and "FAILED".
        • this decision was driven by the need to be able to parse the steps logs as easily as possible

        Attachments

          Issue Links

            Activity

              People

              Assignee:
              sebastien.lesaint Sebastien Lesaint
              Reporter:
              sebastien.lesaint Sebastien Lesaint
              Votes:
              0 Vote for this issue
              Watchers:
              1 Start watching this issue

                Dates

                Due:
                Created:
                Updated:
                Resolved: