Why was a background task cancelled

SonarQube 7.9.1

When running a sonar project ‘Run Code Analysis’ background task - it succeeds, the background task status is ‘canceled’ (as viewed in administration -> background task)

Similar background tasks for other projects work as expected (succeed).

Any help to investigate the issue would be appreciated

sonar.log.level.ce=DEBUG

sonar.log:

Launching a JVM...
Wrapper (Version 3.2.3) http://wrapper.tanukisoftware.org
  Copyright 1999-2006 Tanuki Software, Inc.  All Rights Reserved.
2019.11.03 11:59:46 INFO  app[][o.s.a.AppFileSystem] Cleaning or creating temp directory D:\sonarqube-7.9.1\temp
2019.11.03 11:59:47 INFO  app[][o.s.a.es.EsSettings] Elasticsearch listening on /127.0.0.1:9001
2019.11.03 11:59:47 INFO  app[][o.s.a.ProcessLauncherImpl] Launch process[[key='es', ipcIndex=1, logFilenamePrefix=es]] from [D:\sonarqube-7.9.1\elasticsearch]: C:\Program Files\Java\jdk-11.0.2\bin\java -XX:+UseConcMarkSweepGC -XX:CMSInitiatingOccupancyFraction=75 -XX:+UseCMSInitiatingOccupancyOnly -Des.networkaddress.cache.ttl=60 -Des.networkaddress.cache.negative.ttl=10 -XX:+AlwaysPreTouch -Xss1m -Djava.awt.headless=true -Dfile.encoding=UTF-8 -Djna.nosys=true -XX:-OmitStackTraceInFastThrow -Dio.netty.noUnsafe=true -Dio.netty.noKeySetOptimization=true -Dio.netty.recycler.maxCapacityPerThread=0 -Dlog4j.shutdownHookEnabled=false -Dlog4j2.disable.jmx=true -Djava.io.tmpdir=D:\sonarqube-7.9.1\temp -XX:ErrorFile=../logs/es_hs_err_pid%p.log -Des.enforce.bootstrap.checks=true -Xms512m -Xmx512m -XX:+HeapDumpOnOutOfMemoryError -Delasticsearch -Des.path.home=D:\sonarqube-7.9.1\elasticsearch -Des.path.conf=D:\sonarqube-7.9.1\temp\conf\es -cp lib/* org.elasticsearch.bootstrap.Elasticsearch
2019.11.03 11:59:48 INFO  app[][o.s.a.SchedulerImpl] Waiting for Elasticsearch to be up and running
Java HotSpot(TM) 64-Bit Server VM warning: Option UseConcMarkSweepGC was deprecated in version 9.0 and will likely be removed in a future release.
2019.11.03 11:59:50 INFO  app[][o.e.p.PluginsService] no modules loaded
2019.11.03 11:59:50 INFO  app[][o.e.p.PluginsService] loaded plugin [org.elasticsearch.transport.Netty4Plugin]
2019.11.03 12:00:27 INFO  app[][o.s.a.SchedulerImpl] Process[es] is up
2019.11.03 12:00:27 INFO  app[][o.s.a.ProcessLauncherImpl] Launch process[[key='web', ipcIndex=2, logFilenamePrefix=web]] from [D:\sonarqube-7.9.1]: C:\Program Files\Java\jdk-11.0.2\bin\java -Djava.awt.headless=true -Dfile.encoding=UTF-8 -Djava.io.tmpdir=D:\sonarqube-7.9.1\temp --add-opens=java.base/java.util=ALL-UNNAMED --add-opens=java.base/java.lang=ALL-UNNAMED --add-opens=java.base/java.io=ALL-UNNAMED --add-opens=java.rmi/sun.rmi.transport=ALL-UNNAMED -Xmx512m -Xms128m -XX:+HeapDumpOnOutOfMemoryError -Dhttp.nonProxyHosts=localhost|127.*|[::1] -cp ./lib/common/*;D:\sonarqube-7.9.1\lib\jdbc\mssql\mssql-jdbc-7.2.2.jre11.jar org.sonar.server.app.WebServer D:\sonarqube-7.9.1\temp\sq-process2301479775350868285properties
2019.11.03 12:01:33 INFO  app[][o.s.a.SchedulerImpl] Process[web] is up
2019.11.03 12:01:33 INFO  app[][o.s.a.ProcessLauncherImpl] Launch process[[key='ce', ipcIndex=3, logFilenamePrefix=ce]] from [D:\sonarqube-7.9.1]: C:\Program Files\Java\jdk-11.0.2\bin\java -Djava.awt.headless=true -Dfile.encoding=UTF-8 -Djava.io.tmpdir=D:\sonarqube-7.9.1\temp --add-opens=java.base/java.util=ALL-UNNAMED -Xmx512m -Xms128m -XX:+HeapDumpOnOutOfMemoryError -Dhttp.nonProxyHosts=localhost|127.*|[::1] -cp ./lib/common/*;D:\sonarqube-7.9.1\lib\jdbc\mssql\mssql-jdbc-7.2.2.jre11.jar org.sonar.ce.app.CeServer D:\sonarqube-7.9.1\temp\sq-process2729176916739112220properties
2019.11.03 12:01:49 INFO  app[][o.s.a.SchedulerImpl] Process[ce] is up
2019.11.03 12:01:49 INFO  app[][o.s.a.SchedulerImpl] SonarQube is up

ce log:

2019.11.03 12:42:40 DEBUG ce[AW4w2nVNX0PsCJf3nNiZ][o.s.c.t.p.s.ExtractReportStep] Analysis report is 35 MB uncompressed
2019.11.03 12:42:40 INFO  ce[AW4w2nVNX0PsCJf3nNiZ][o.s.c.t.s.ComputationStepExecutor] Extract report | status=SUCCESS | time=104206ms
2019.11.03 12:42:40 INFO  ce[AW4w2nVNX0PsCJf3nNiZ][o.s.c.t.s.ComputationStepExecutor] Persist scanner context | status=SUCCESS | time=16ms
2019.11.03 12:42:40 INFO  ce[AW4w2nVNX0PsCJf3nNiZ][o.s.c.t.s.ComputationStepExecutor] Propagate analysis warnings from scanner report | status=SUCCESS | time=62ms
2019.11.03 12:42:40 INFO  ce[AW4w2nVNX0PsCJf3nNiZ][o.s.c.t.s.ComputationStepExecutor] Execute DB migrations for current project | status=SUCCESS | time=219ms
2019.11.03 12:42:40 INFO  ce[AW4w2nVNX0PsCJf3nNiZ][o.s.c.t.s.ComputationStepExecutor] Generate analysis UUID | status=SUCCESS | time=0ms
2019.11.03 12:42:40 INFO  ce[AW4w2nVNX0PsCJf3nNiZ][o.s.c.t.s.ComputationStepExecutor] Load analysis metadata | status=SUCCESS | time=188ms
2019.11.03 12:42:40 INFO  ce[AW4w2nVNX0PsCJf3nNiZ][o.s.c.t.s.ComputationStepExecutor] Initialize | status=SUCCESS | time=0ms
2019.11.03 12:42:40 INFO  ce[AW4w2nVNX0PsCJf3nNiZ][o.s.c.t.s.ComputationStepExecutor] Verify billing | status=SUCCESS | time=0ms
2019.11.03 12:42:42 INFO  ce[AW4w2nVNX0PsCJf3nNiZ][o.s.c.t.s.ComputationStepExecutor] Build tree of components | components=1147 | status=SUCCESS | time=1515ms
2019.11.03 12:42:42 INFO  ce[AW4w2nVNX0PsCJf3nNiZ][o.s.c.t.s.ComputationStepExecutor] Validate project | status=SUCCESS | time=0ms
2019.11.03 12:42:42 INFO  ce[AW4w2nVNX0PsCJf3nNiZ][o.s.c.t.s.ComputationStepExecutor] Load quality profiles | status=SUCCESS | time=500ms
2019.11.03 12:42:42 INFO  ce[AW4w2nVNX0PsCJf3nNiZ][o.s.c.t.s.ComputationStepExecutor] Load Quality gate | status=SUCCESS | time=79ms
2019.11.03 12:42:42 INFO  ce[AW4w2nVNX0PsCJf3nNiZ][o.s.c.t.s.ComputationStepExecutor] Load new code period | status=SUCCESS | time=0ms
2019.11.03 12:42:42 DEBUG ce[AW4w2nVNX0PsCJf3nNiZ][o.s.c.t.p.f.FileMoveDetectionStep] First analysis. Do nothing.
2019.11.03 12:42:42 INFO  ce[AW4w2nVNX0PsCJf3nNiZ][o.s.c.t.s.ComputationStepExecutor] Detect file moves | status=SUCCESS | time=0ms
2019.11.03 12:42:43 INFO  ce[AW4w2nVNX0PsCJf3nNiZ][o.s.c.t.s.ComputationStepExecutor] Load duplications | duplications=742 | status=SUCCESS | time=656ms
2019.11.03 12:42:43 DEBUG ce[AW4w2nVNX0PsCJf3nNiZ][o.s.c.t.p.d.CrossProjectDuplicationStatusHolderImpl] Cross project duplication is disabled because it's disabled in the analysis report
2019.11.03 12:42:43 INFO  ce[AW4w2nVNX0PsCJf3nNiZ][o.s.c.t.s.ComputationStepExecutor] Compute cross project duplications | status=SUCCESS | time=0ms
2019.11.03 12:42:44 INFO  ce[AW4w2nVNX0PsCJf3nNiZ][o.s.c.t.s.ComputationStepExecutor] Compute size measures | status=SUCCESS | time=1328ms
2019.11.03 12:42:45 INFO  ce[AW4w2nVNX0PsCJf3nNiZ][o.s.c.t.s.ComputationStepExecutor] Compute new coverage | status=SUCCESS | time=31ms
2019.11.03 12:42:45 INFO  ce[AW4w2nVNX0PsCJf3nNiZ][o.s.c.t.s.ComputationStepExecutor] Compute coverage measures | status=SUCCESS | time=625ms
2019.11.03 12:42:45 INFO  ce[AW4w2nVNX0PsCJf3nNiZ][o.s.c.t.s.ComputationStepExecutor] Compute comment measures | status=SUCCESS | time=31ms
2019.11.03 12:42:45 INFO  ce[AW4w2nVNX0PsCJf3nNiZ][o.s.c.t.s.ComputationStepExecutor] Copy custom measures | status=SUCCESS | time=0ms
2019.11.03 12:42:45 INFO  ce[AW4w2nVNX0PsCJf3nNiZ][o.s.c.t.s.ComputationStepExecutor] Compute duplication measures | status=SUCCESS | time=47ms
2019.11.03 12:42:45 INFO  ce[AW4w2nVNX0PsCJf3nNiZ][o.s.c.t.s.ComputationStepExecutor] Compute size measures on new code | status=SUCCESS | time=15ms
2019.11.03 12:42:45 INFO  ce[AW4w2nVNX0PsCJf3nNiZ][o.s.c.t.s.ComputationStepExecutor] Compute language distribution | status=SUCCESS | time=125ms
2019.11.03 12:42:45 INFO  ce[AW4w2nVNX0PsCJf3nNiZ][o.s.c.t.s.ComputationStepExecutor] Compute test measures | status=SUCCESS | time=16ms
2019.11.03 12:42:46 INFO  ce[AW4w2nVNX0PsCJf3nNiZ][o.s.c.t.s.ComputationStepExecutor] Compute complexity measures | status=SUCCESS | time=140ms
2019.11.03 12:42:46 INFO  ce[AW4w2nVNX0PsCJf3nNiZ][o.s.c.t.s.ComputationStepExecutor] Load measure computers | status=SUCCESS | time=0ms
2019.11.03 12:42:46 INFO  ce[AW4w2nVNX0PsCJf3nNiZ][o.s.c.t.s.ComputationStepExecutor] Compute Quality Profile status | status=SUCCESS | time=79ms
2019.11.03 12:43:05 DEBUG ce[AW4w2nVNX0PsCJf3nNiZ][o.s.c.t.p.s.ExecuteVisitorsStep]   Execution time for each component visitor:
2019.11.03 12:43:05 DEBUG ce[AW4w2nVNX0PsCJf3nNiZ][o.s.c.t.p.s.ExecuteVisitorsStep]   - LoadComponentUuidsHavingOpenIssuesVisitor | time=188ms
2019.11.03 12:43:05 DEBUG ce[AW4w2nVNX0PsCJf3nNiZ][o.s.c.t.p.s.ExecuteVisitorsStep]   - IntegrateIssuesVisitor | time=18501ms
2019.11.03 12:43:05 DEBUG ce[AW4w2nVNX0PsCJf3nNiZ][o.s.c.t.p.s.ExecuteVisitorsStep]   - CloseIssuesOnRemovedComponentsVisitor | time=0ms
2019.11.03 12:43:05 DEBUG ce[AW4w2nVNX0PsCJf3nNiZ][o.s.c.t.p.s.ExecuteVisitorsStep]   - MaintainabilityMeasuresVisitor | time=109ms
2019.11.03 12:43:05 DEBUG ce[AW4w2nVNX0PsCJf3nNiZ][o.s.c.t.p.s.ExecuteVisitorsStep]   - NewMaintainabilityMeasuresVisitor | time=0ms
2019.11.03 12:43:05 DEBUG ce[AW4w2nVNX0PsCJf3nNiZ][o.s.c.t.p.s.ExecuteVisitorsStep]   - ReliabilityAndSecurityRatingMeasuresVisitor | time=16ms
2019.11.03 12:43:05 DEBUG ce[AW4w2nVNX0PsCJf3nNiZ][o.s.c.t.p.s.ExecuteVisitorsStep]   - NewReliabilityAndSecurityRatingMeasuresVisitor | time=0ms
2019.11.03 12:43:05 DEBUG ce[AW4w2nVNX0PsCJf3nNiZ][o.s.c.t.p.s.ExecuteVisitorsStep]   - SecurityReviewRatingVisitor | time=0ms
2019.11.03 12:43:05 DEBUG ce[AW4w2nVNX0PsCJf3nNiZ][o.s.c.t.p.s.ExecuteVisitorsStep]   - LastCommitVisitor | time=125ms
2019.11.03 12:43:05 DEBUG ce[AW4w2nVNX0PsCJf3nNiZ][o.s.c.t.p.s.ExecuteVisitorsStep]   - MeasureComputersVisitor | time=30ms
2019.11.03 12:43:05 INFO  ce[AW4w2nVNX0PsCJf3nNiZ][o.s.c.t.s.ComputationStepExecutor] Execute component visitors | status=SUCCESS | time=19016ms
2019.11.03 12:43:05 INFO  ce[AW4w2nVNX0PsCJf3nNiZ][o.s.c.t.s.ComputationStepExecutor] Checks executed after computation of measures | status=SUCCESS | time=0ms
2019.11.03 12:43:05 INFO  ce[AW4w2nVNX0PsCJf3nNiZ][o.s.c.t.s.ComputationStepExecutor] Compute Quality Gate measures | status=SUCCESS | time=47ms
2019.11.03 12:43:05 INFO  ce[AW4w2nVNX0PsCJf3nNiZ][o.s.c.t.s.ComputationStepExecutor] Compute Quality profile measures | status=SUCCESS | time=15ms
2019.11.03 12:43:05 INFO  ce[AW4w2nVNX0PsCJf3nNiZ][o.s.c.t.s.ComputationStepExecutor] Generate Quality profile events | status=SUCCESS | time=16ms
2019.11.03 12:43:05 INFO  ce[AW4w2nVNX0PsCJf3nNiZ][o.s.c.t.s.ComputationStepExecutor] Generate Quality gate events | status=SUCCESS | time=0ms
2019.11.03 12:43:10 INFO  ce[AW4w2nVNX0PsCJf3nNiZ][o.s.c.t.s.ComputationStepExecutor] Persist components | status=SUCCESS | time=4719ms
2019.11.03 12:43:10 INFO  ce[AW4w2nVNX0PsCJf3nNiZ][o.s.c.t.s.ComputationStepExecutor] Persist analysis | status=SUCCESS | time=15ms
2019.11.03 12:43:10 INFO  ce[AW4w2nVNX0PsCJf3nNiZ][o.s.c.t.s.ComputationStepExecutor] Persist analysis properties | status=SUCCESS | time=0ms
2019.11.03 12:43:10 INFO  ce[AW4w2nVNX0PsCJf3nNiZ][o.s.c.t.s.ComputationStepExecutor] Persist measures | inserts=58 | status=SUCCESS | time=16ms
2019.11.03 12:43:47 INFO  ce[AW4w2nVNX0PsCJf3nNiZ][o.s.c.t.s.ComputationStepExecutor] Persist live measures | insertsOrUpdates=30393 | status=SUCCESS | time=36969ms
2019.11.03 12:43:47 INFO  ce[AW4w2nVNX0PsCJf3nNiZ][o.s.c.t.s.ComputationStepExecutor] Persist duplication data | insertsOrUpdates=101 | status=SUCCESS | time=141ms
2019.11.03 12:43:49 INFO  ce[AW4w2nVNX0PsCJf3nNiZ][o.s.c.t.s.ComputationStepExecutor] Persist new ad hoc Rules | status=SUCCESS | time=1781ms
2019.11.03 12:44:10 INFO  ce[AW4w2nVNX0PsCJf3nNiZ][o.s.c.t.s.ComputationStepExecutor] Persist issues | inserts=8333 | updates=0 | merged=0 | untouched=0 | status=SUCCESS | time=21829ms
2019.11.03 12:44:10 INFO  ce[AW4w2nVNX0PsCJf3nNiZ][o.s.c.t.s.ComputationStepExecutor] Persist project links | status=SUCCESS | time=0ms
2019.11.03 12:44:10 INFO  ce[AW4w2nVNX0PsCJf3nNiZ][o.s.c.t.s.ComputationStepExecutor] Persist events | status=SUCCESS | time=15ms
2019.11.03 12:44:26 INFO  ce[AW4w2nVNX0PsCJf3nNiZ][o.s.c.t.s.ComputationStepExecutor] Persist sources | status=SUCCESS | time=16126ms
2019.11.03 12:44:26 INFO  ce[AW4w2nVNX0PsCJf3nNiZ][o.s.c.t.s.ComputationStepExecutor] Persist cross project duplications | status=SUCCESS | time=0ms
2019.11.03 12:44:27 INFO  ce[AW4w2nVNX0PsCJf3nNiZ][o.s.c.t.s.ComputationStepExecutor] Enable analysis | status=SUCCESS | time=265ms
2019.11.03 12:44:27 INFO  ce[AW4w2nVNX0PsCJf3nNiZ][o.s.c.t.s.ComputationStepExecutor] Update last usage date of quality profiles | status=SUCCESS | time=16ms
2019.11.03 12:44:27 DEBUG ce[AW4w2nVNX0PsCJf3nNiZ][o.s.d.p.p.KeepOneFilter] -> Keep one snapshot per day between 2019-10-06 and 2019-11-02
2019.11.03 12:44:27 DEBUG ce[AW4w2nVNX0PsCJf3nNiZ][o.s.d.p.p.DefaultPeriodCleaner] <- Delete analyses of component AW4w2mVvX0PsCJf3nNiT: 
2019.11.03 12:44:27 DEBUG ce[AW4w2nVNX0PsCJf3nNiZ][o.s.d.p.p.KeepOneFilter] -> Keep one snapshot per week between 2018-11-04 and 2019-10-06
2019.11.03 12:44:27 DEBUG ce[AW4w2nVNX0PsCJf3nNiZ][o.s.d.p.p.DefaultPeriodCleaner] <- Delete analyses of component AW4w2mVvX0PsCJf3nNiT: 
2019.11.03 12:44:27 DEBUG ce[AW4w2nVNX0PsCJf3nNiZ][o.s.d.p.p.KeepOneFilter] -> Keep one snapshot per month between 2014-11-09 and 2018-11-04
2019.11.03 12:44:27 DEBUG ce[AW4w2nVNX0PsCJf3nNiZ][o.s.d.p.p.DefaultPeriodCleaner] <- Delete analyses of component AW4w2mVvX0PsCJf3nNiT: 
2019.11.03 12:44:27 DEBUG ce[AW4w2nVNX0PsCJf3nNiZ][o.s.d.p.p.KeepWithVersionFilter] -> Keep analyses with a version prior to 2017-11-05
2019.11.03 12:44:27 DEBUG ce[AW4w2nVNX0PsCJf3nNiZ][o.s.d.p.p.DefaultPeriodCleaner] <- Delete analyses of component AW4w2mVvX0PsCJf3nNiT: 
2019.11.03 12:44:27 DEBUG ce[AW4w2nVNX0PsCJf3nNiZ][o.s.d.p.p.DeleteAllFilter] -> Delete data prior to: 2014-11-09
2019.11.03 12:44:27 DEBUG ce[AW4w2nVNX0PsCJf3nNiZ][o.s.d.p.p.DefaultPeriodCleaner] <- Delete analyses of component AW4w2mVvX0PsCJf3nNiT: 
2019.11.03 12:44:27 DEBUG ce[AW4w2nVNX0PsCJf3nNiZ][o.s.d.purge.PurgeDao] <- Delete aborted builds
2019.11.03 12:44:28 INFO  ce[AW4w2nVNX0PsCJf3nNiZ][o.s.c.t.s.ComputationStepExecutor] Purge db | status=SUCCESS | time=813ms
2019.11.03 12:44:28 DEBUG ce[AW4w2nVNX0PsCJf3nNiZ][o.s.c.t.p.s.IndexAnalysisStep] Call org.sonar.server.measure.index.ProjectMeasuresIndexer@3b30f5e8
2019.11.03 12:44:29 DEBUG ce[AW4w2nVNX0PsCJf3nNiZ][o.s.c.t.p.s.IndexAnalysisStep] Call org.sonar.server.component.index.ComponentIndexer@20c682d
2019.11.03 12:44:30 DEBUG ce[AW4w2nVNX0PsCJf3nNiZ][o.s.c.t.p.s.IndexAnalysisStep] Call org.sonar.server.issue.index.IssueIndexer@3bb5bf30
2019.11.03 12:44:34 INFO  ce[AW4w2nVNX0PsCJf3nNiZ][o.s.c.t.s.ComputationStepExecutor] Index analysis | status=SUCCESS | time=6172ms
2019.11.03 12:44:34 INFO  ce[AW4w2nVNX0PsCJf3nNiZ][o.s.c.t.s.ComputationStepExecutor] Send issue notifications | newIssuesNotifs=0 | newIssuesDeliveries=0 | myNewIssuesNotifs=0 | myNewIssuesDeliveries=0 | changesNotifs=0 | changesDeliveries=0 | status=SUCCESS | time=0ms
2019.11.03 12:44:34 INFO  ce[AW4w2nVNX0PsCJf3nNiZ][o.s.c.t.s.ComputationStepExecutor] Publish task results | status=SUCCESS | time=0ms
2019.11.03 12:44:34 INFO  ce[AW4w2nVNX0PsCJf3nNiZ][o.s.c.t.s.ComputationStepExecutor] Trigger refresh of Portfolios and Applications | status=SUCCESS | time=0ms
2019.11.03 12:45:02 ERROR ce[AW4w2nVNX0PsCJf3nNiZ][o.s.c.t.CeWorkerImpl] Failed to finalize task with uuid 'AW4w2nVNX0PsCJf3nNiZ' and persist its state to db
java.lang.IllegalStateException: Task does not exist anymore: CeTask{organizationUuid=AWyAsaqAF5-lNFJeDOGK, type=REPORT, uuid=AW4w2nVNX0PsCJf3nNiZ, component=Component{uuid='AW4w2mVvX0PsCJf3nNiT', key='AICT', name='AIC-T'}, mainComponent=Component{uuid='AW4w2mVvX0PsCJf3nNiT', key='AICT', name='AIC-T'}, submitter=User{uuid='XXXXXXXX', login='XXXXXXXX'}}
	at org.sonar.ce.queue.InternalCeQueueImpl.lambda$remove$0(InternalCeQueueImpl.java:118)
	at java.base/java.util.Optional.orElseThrow(Optional.java:408)
	at org.sonar.ce.queue.InternalCeQueueImpl.remove(InternalCeQueueImpl.java:118)
	at org.sonar.ce.taskprocessor.CeWorkerImpl$ExecuteTask.finalizeTask(CeWorkerImpl.java:242)
	at org.sonar.ce.taskprocessor.CeWorkerImpl$ExecuteTask.afterExecute(CeWorkerImpl.java:236)
	at org.sonar.ce.taskprocessor.CeWorkerImpl$ExecuteTask.close(CeWorkerImpl.java:196)
	at org.sonar.ce.taskprocessor.CeWorkerImpl.findAndProcessTask(CeWorkerImpl.java:159)
	at org.sonar.ce.taskprocessor.CeWorkerImpl$TrackRunningState.get(CeWorkerImpl.java:133)
	at org.sonar.ce.taskprocessor.CeWorkerImpl.call(CeWorkerImpl.java:85)
	at org.sonar.ce.taskprocessor.CeWorkerImpl.call(CeWorkerImpl.java:53)
	at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
	at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515)
	at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
	at java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304)
	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
	at java.base/java.lang.Thread.run(Thread.java:834)

Hi,

Welcome to the community!

What do you see in the logs for that particular task?

 
Ann

We’re running the analysis using Azure DevOps pipeline tasks
Thereof, there are 2 task logs:

Run Code Analysis Log (looks like the task succeeded)

2019-11-03T10:40:17.5373901Z 12:40:17.533 INFO: CPD calculation finished
2019-11-03T10:40:36.1479640Z 12:40:36.143 INFO: Analysis report generated in 18001ms, dir size=35 MB
2019-11-03T10:40:49.1686192Z 12:40:49.159 INFO: Analysis report compressed in 13016ms, zip size=9 MB
2019-11-03T10:40:49.1686977Z 12:40:49.159 INFO: Analysis report generated in D:\Azure-DevOps-Agents\A01_work\3.sonarqube\out.sonar\scanner-report
2019-11-03T10:40:49.1687232Z 12:40:49.159 DEBUG: Upload report
2019-11-03T10:40:53.8439815Z 12:40:53.831 DEBUG: POST 200 http://ourServer:ourPort/api/ce/submit?projectKey=AncillariesInCheckinTest&projectName=Ancillaries%20in%20Check%20in-test | time=4672ms
2019-11-03T10:40:53.8566003Z 12:40:53.847 INFO: Analysis report uploaded in 4688ms
2019-11-03T10:40:53.8566789Z 12:40:53.847 INFO: ANALYSIS SUCCESSFUL, you can browse http://ourServer:ourPort/dashboard?id=AncillariesInCheckinTest
2019-11-03T10:40:53.8567240Z 12:40:53.847 INFO: Note that you will be able to access the updated dashboard once the server has processed the submitted analysis report
2019-11-03T10:40:53.8567677Z 12:40:53.847 INFO: More about the report processing at http://ourServer:ourPort/api/ce/task?id=AW4w2nVNX0PsCJf3nNiZ
2019-11-03T10:40:53.8742294Z 12:40:53.862 DEBUG: Report metadata written to D:\Azure-DevOps-Agents\A01_work_temp\sonar\20191103.6\5a042a9b-bbf6-b8aa-ca73-03868ca54897\report-task.txt
2019-11-03T10:40:53.8798509Z 12:40:53.862 DEBUG: Post-jobs :
2019-11-03T10:42:20.4889147Z 12:42:20.474 INFO: Analysis total time: 9:42.219 s
2019-11-03T10:42:20.5399980Z 12:42:20.505 INFO: ------------------------------------------------------------------------
2019-11-03T10:42:20.5526897Z 12:42:20.505 INFO: EXECUTION SUCCESS
2019-11-03T10:42:20.5599642Z 12:42:20.505 INFO: ------------------------------------------------------------------------
2019-11-03T10:42:20.5600169Z 12:42:20.505 INFO: Total time: 9:43.782s
2019-11-03T10:42:20.8009308Z 12:42:20.787 INFO: Final Memory: 14M/54M
2019-11-03T10:42:20.8328054Z 12:42:20.787 INFO: ------------------------------------------------------------------------
2019-11-03T10:42:21.2356881Z Process returned exit code 0
2019-11-03T10:42:21.2393858Z The SonarQube Scanner has finished
2019-11-03T10:42:21.2461899Z 12:42:21.24 Post-processing succeeded.
2019-11-03T10:42:21.3288519Z ##[debug]Exit code 0 received from tool ‘D:\Azure-DevOps-Agents\A01_work_tasks\SonarQubePrepare_15b84ca1-b62f-4a2a-a403-89b77a063157\4.8.0\classic-sonar-scanner-msbuild\SonarScanner.MSBuild.exe’
2019-11-03T10:42:21.3290496Z ##[debug]STDIO streams have closed for tool ‘D:\Azure-DevOps-Agents\A01_work_tasks\SonarQubePrepare_15b84ca1-b62f-4a2a-a403-89b77a063157\4.8.0\classic-sonar-scanner-msbuild\SonarScanner.MSBuild.exe’
2019-11-03T10:42:21.3775496Z ##[section]Finishing: Run Code Analysis

Publish Quality Gate results (seems that the task is already canceled)

2019-11-03T10:42:30.2862488Z ##[debug][SQ] Parse Task report file: projectKey=AncillariesInCheckinTest
serverUrl=http://ourServer:ourPort
serverVersion=7.9.1.27448
dashboardUrl=http://ourServer:ourPort/dashboard?id=AncillariesInCheckinTest
ceTaskId=AW4w2nVNX0PsCJf3nNiZ
ceTaskUrl=http://ourServer:ourPort/api/ce/task?id=AW4w2nVNX0PsCJf3nNiZ
2019-11-03T10:42:30.2875028Z ##[debug][SQ] Waiting for task ‘AW4w2nVNX0PsCJf3nNiZ’ to complete.
2019-11-03T10:42:30.2875742Z ##[debug][SQ] API GET: ‘/api/ce/task’ with query “{“id”:“AW4w2nVNX0PsCJf3nNiZ”}”
2019-11-03T10:42:30.3319566Z ##[debug]Response: 200 Body: “{“task”:{“id”:“AW4w2nVNX0PsCJf3nNiZ”,“type”:“REPORT”,“componentId”:“AW4w2mVvX0PsCJf3nNiT”,“componentKey”:“AncillariesInCheckinTest”,“componentName”:“Ancillaries in Check in-test”,“componentQualifier”:“TRK”,“status”:“CANCELED”,“submittedAt”:“2019-11-03T12:40:53+0200”,“submitterLogin”:“admin”,“startedAt”:“2019-11-03T12:40:54+0200”,“executedAt”:“2019-11-03T12:41:06+0200”,“executionTimeMs”:11678,“logs”:false,“hasScannerContext”:false,“organization”:“default-organization”,“warningCount”:0,“warnings”:}}”
2019-11-03T10:42:30.3323261Z ##[debug][SQ] Task status:CANCELED
2019-11-03T10:42:31.3357408Z ##[debug][SQ] Waiting for task ‘AW4w2nVNX0PsCJf3nNiZ’ to complete.
2019-11-03T10:42:31.3405435Z ##[debug][SQ] API GET: ‘/api/ce/task’ with query “{“id”:“AW4w2nVNX0PsCJf3nNiZ”}”
2019-11-03T10:42:31.3514497Z ##[debug]Response: 200 Body: “{“task”:{“id”:“AW4w2nVNX0PsCJf3nNiZ”,“type”:“REPORT”,“componentId”:“AW4w2mVvX0PsCJf3nNiT”,“componentKey”:“AncillariesInCheckinTest”,“componentName”:“Ancillaries in Check in-test”,“componentQualifier”:“TRK”,“status”:“CANCELED”,“submittedAt”:“2019-11-03T12:40:53+0200”,“submitterLogin”:“admin”,“startedAt”:“2019-11-03T12:40:54+0200”,“executedAt”:“2019-11-03T12:41:06+0200”,“executionTimeMs”:11678,“logs”:false,“hasScannerContext”:false,“organization”:“default-organization”,“warningCount”:0,“warnings”:}}”
2019-11-03T10:42:31.3515546Z ##[debug][SQ] Task status:CANCELED

Hi,

Those look like logs from the build agent. I was asking about server-side Background Task logs, which you’ll find at the project level under Administration > Background Tasks, and then look under the cog menu.

 
Ann

I have looked at the place you mentioned, and there’s only ‘Show Scanner Context’ option under the cog. It didn’t find anything about the task cancellation in the scanner context.
Am I missing the task log option there? if so, what could cause it?

Hi,

I didn’t have an example Cancelled task to look at when I gave you those directions. I was hoping that there would be some info there. Without it… I’m afraid you’d have to parse your access logs to see who sent the Cancel command and just ask them. Because it should be that it was manually cancelled by a person. I can’t think of any situation in which SonarQube will cancel your tasks on its own.

 
Sorry I wasn’t more help,
Ann

Hello,

I also have a “task is cancelled with no human interaction” behaviour.

I’ve had failures on Nov 14 (because of system issues), and since that day, on some projects (not all), all project analysis are canceled.

At first I thought there may be a protection mechanism somewhere, that prevents it from insisting when analysis is known to fail. But I couldn’t find any info on that.

My Maven sonar task reports this when trying to start analysis:

[ERROR] Failed to execute goal org.sonarsource.scanner.maven:sonar-maven-plugin:3.6.0.1398:sonar (default-cli) on project silex-root: Unable to load component class org.sonar.scanner.bootstrap.ScannerPluginInstaller: Unable to load component class org.sonar.scanner.bootstrap.PluginFiles: Unable to load component class org.sonar.scanner.bootstrap.GlobalConfiguration: Unable to load component class org.sonar.scanner.bootstrap.GlobalServerSettings: Error 500 on http://sonar.silex.io/api/settings/values.protobuf : <!doctype html><html lang="en"><head><title>HTTP Status 500 – Internal Server Error</title><style type="text/css">h1 {font-family:Tahoma,Arial,sans-serif;color:white;background-color:#525D76;font-size:22px;} h2 {font-family:Tahoma,Arial,sans-serif;color:white;background-color:#525D76;font-size:16px;} h3 {font-family:Tahoma,Arial,sans-serif;color:white;background-color:#525D76;font-size:14px;} body {font-family:Tahoma,Arial,sans-serif;color:black;background-color:white;} b {font-family:Tahoma,Arial,sans-serif;color:white;background-color:#525D76;} p {font-family:Tahoma,Arial,sans-serif;background:white;color:black;font-size:12px;} a {color:black;} a.name {color:black;} .line {height:1px;background-color:#525D76;border:none;}</style></head><body><h1>HTTP Status 500 – Internal Server Error</h1><hr class="line" /><p><b>Type</b> Status Report</p><p><b>Description</b> The server encountered an unexpected condition that prevented it from fulfilling the request.</p><hr class="line" /><h3>Apache Tomcat/8.5.38</h3></body></html> -> [Help 1]

I’m currently running Sonar Community Edition Version 7.9.1 (build 27448).

Hi @hervenicol,

You’re getting a 500 error from the server. You should check your server logs to get to the root of the problem.

 
Ann

Oops, sorry, I forgot to post a follow-up. :confounded:

In my case, the server logs did not tell me much.
However, the problem was with the PG server.
It was short of memory, and was crashing when scanning some big projects.
I allocated it more memory, and now all is fine.

Thanks for your support @ganncamp ! :+1:

2 Likes

Thanks for the follow up @hervenicol! That is indeed helpful.

1 Like

A post was split to a new topic: Failed to finalize task

Hi Herve, what is PG server you have mentioned, your company server or something specific on sonarqube terminology?

Im having a similar situation from VSTS, my sonar server has 8GB Ram and our version is 7.9.2, no errors in the sonar logs and it seems when builds are triggered from VSTS they are taking longer than expected and sometimes after 45 mins running they got cancelled(not human interaction).

SonarQube relies on a database (see the installation requirements page here: https://docs.sonarqube.org/latest/requirements/requirements/#header-3).

My installation uses postgresql (PG).