SQ 9.6/9.7: Compute Engine is not operational

Hi,

starting with SQ 9.6 GET api/ce/task from Web API returns endless PENDING. Is this an known issue or is there an API change?

In a script I read the LOG file from the scanner and call the link from the script in a loop to find out when analysis on server side is done:

09:20:41.659 INFO: More about the report processing at http://localhost:9000/api/ce/task?id=AYQYvmSrMMwumWW_cPG3

Calling http://localhost:9000/api/ce/task?id=AYQYvmSrMMwumWW_cPG3 I get endless PENDING.
In older versions it was something like this:

CURRENT STATUS : PENDING
CURRENT STATUS : IN_PROGRESS
CURRENT STATUS : IN_PROGRESS
CURRENT STATUS : IN_PROGRESS
CURRENT STATUS : SUCCESS

LOG file:

...
09:20:41.659 INFO: Analysis report uploaded in 172ms
09:20:41.659 DEBUG: Report metadata written to D:\a\integration-tests\testdata\project\.scannerwork\report-task.txt
09:20:41.659 INFO: ANALYSIS SUCCESSFUL, you can find the results at: http://localhost:9000/dashboard?id=project
09:20:41.659 INFO: Note that you will be able to access the updated dashboard once the server has processed the submitted analysis report
09:20:41.659 INFO: More about the report processing at http://localhost:9000/api/ce/task?id=AYQYvmSrMMwumWW_cPG3
09:20:41.659 DEBUG: Post-jobs : Final report
09:20:41.659 INFO: Executing post-job 'Final report'
09:20:41.674 INFO: Analysis total time: 9.311 s
09:20:41.674 INFO: ------------------------------------------------------------------------
09:20:41.674 INFO: EXECUTION SUCCESS
09:20:41.674 INFO: ------------------------------------------------------------------------
09:20:41.674 INFO: Total time: 11.343s
09:20:41.737 INFO: Final Memory: 17M/57M
09:20:41.737 INFO: ------------------------------------------------------------------------

Regards,
Günter

Hey there.

For this same task, what do you see in the UI regarding it’s status?

Hi Colin,

the integration tests are running on GitHub Actions, it’s not possible to access the UI.

The strange thing is

  • the setup is the same except the SQ version: 8.9.10.61524, 9.5.0.56709, 9.6.1.59531, 9.7.0.61563
  • on scanner side it’s always successful (see LOG file)
  • we are running same tests on different OS: Linux & Windows
  • SQ 8.9.10.61524, 9.5.0.56709 is working in all combinations
  • SQ 9.6.1.59531, 9.7.0.61563 are working on Linux but not on Windows?

Any ideas?

Regards,

Hey there.

If you don’t have access to the logs or the UI, I don’t think we’ll be able to provide much help. I would try and reproduce this in a local environment.

Hi,

I have access to all LOG files but not to the UI.
Which LOG file could contain hints?

Regards,

The ce.log file should give some indication if that task in question every actually processes successfully.

I did some more tests:

  • it’s working on the CI/CD machine with Linux
  • with Windows it is working on a local machine
  • there is no ce.log on the CI/CD machine under Windows
  • seems everything is stopping because of an ElasticSearch error (all logs attached)?

Do you have an idea why?

2022.11.06 10:33:46 INFO  app[][o.s.a.AppFileSystem] Cleaning or creating temp directory D:\a\test\sonarqube-9.7.1.62043\temp
2022.11.06 10:33:46 INFO  app[][o.s.a.es.EsSettings] Elasticsearch listening on [HTTP: 127.0.0.1:9001, TCP: 127.0.0.1:62508]
2022.11.06 10:33:46 INFO  app[][o.s.a.ProcessLauncherImpl] Launch process[ELASTICSEARCH] from [D:\a\test\sonarqube-9.7.1.62043\elasticsearch]: C:\hostedtoolcache\windows\Java_Temurin-Hotspot_jdk\11.0.17-8\x64\bin\java -XX:+UseG1GC -Djava.io.tmpdir=D:\a\test\sonarqube-9.7.1.62043\temp -XX:ErrorFile=../logs/es_hs_err_pid%p.log -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 -Djna.tmpdir=D:\a\test\sonarqube-9.7.1.62043\temp -XX:-OmitStackTraceInFastThrow -Dio.netty.noUnsafe=true -Dio.netty.noKeySetOptimization=true -Dio.netty.recycler.maxCapacityPerThread=0 -Dio.netty.allocator.numDirectArenas=0 -Dlog4j.shutdownHookEnabled=false -Dlog4j2.disable.jmx=true -Dlog4j2.formatMsgNoLookups=true -Djava.locale.providers=COMPAT -Dcom.redhat.fips=false -Xmx512m -Xms512m -XX:MaxDirectMemorySize=256m -XX:+HeapDumpOnOutOfMemoryError -Delasticsearch -Des.path.home=D:\a\test\sonarqube-9.7.1.62043\elasticsearch -Des.path.conf=D:\a\test\sonarqube-9.7.1.62043\temp\conf\es -cp lib/* org.elasticsearch.bootstrap.Elasticsearch
2022.11.06 10:33:46 INFO  app[][o.s.a.SchedulerImpl] Waiting for Elasticsearch to be up and running
2022.11.06 10:33:57 INFO  app[][o.s.a.SchedulerImpl] Process[es] is up
2022.11.06 10:33:57 INFO  app[][o.s.a.ProcessLauncherImpl] Launch process[WEB_SERVER] from [D:\a\test\sonarqube-9.7.1.62043]: C:\hostedtoolcache\windows\Java_Temurin-Hotspot_jdk\11.0.17-8\x64\bin\java -Djava.awt.headless=true -Dfile.encoding=UTF-8 -Djava.io.tmpdir=D:\a\test\sonarqube-9.7.1.62043\temp -XX:-OmitStackTraceInFastThrow --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 --add-exports=java.base/jdk.internal.ref=ALL-UNNAMED --add-opens=java.base/java.nio=ALL-UNNAMED --add-opens=java.base/sun.nio.ch=ALL-UNNAMED --add-opens=java.management/sun.management=ALL-UNNAMED --add-opens=jdk.management/com.sun.management.internal=ALL-UNNAMED -Dcom.redhat.fips=false -Xmx512m -Xms128m -XX:+HeapDumpOnOutOfMemoryError -Dhttp.nonProxyHosts=localhost|127.*|[::1] -cp ./lib/sonar-application-9.7.1.62043.jar;D:\a\test\sonarqube-9.7.1.62043\lib\jdbc\h2\h2-2.1.214.jar org.sonar.server.app.WebServer D:\a\test\sonarqube-9.7.1.62043\temp\sq-process16670576256285931471properties
2022.11.06 10:35:00 WARN  app[][startup] ####################################################################################################################
2022.11.06 10:35:00 WARN  app[][startup] Plugin(s) detected. Plugins are not provided by SonarSource and are therefore installed at your own risk. A SonarQube administrator needs to acknowledge this risk once logged in.
2022.11.06 10:35:00 WARN  app[][startup] ####################################################################################################################
2022.11.06 10:35:02 INFO  app[][o.s.a.SchedulerImpl] Process[web] is up
2022.11.06 10:35:02 INFO  app[][o.s.a.ProcessLauncherImpl] Launch process[COMPUTE_ENGINE] from [D:\a\test\sonarqube-9.7.1.62043]: C:\hostedtoolcache\windows\Java_Temurin-Hotspot_jdk\11.0.17-8\x64\bin\java -Djava.awt.headless=true -Dfile.encoding=UTF-8 -Djava.io.tmpdir=D:\a\test\sonarqube-9.7.1.62043\temp -XX:-OmitStackTraceInFastThrow --add-opens=java.base/java.util=ALL-UNNAMED --add-exports=java.base/jdk.internal.ref=ALL-UNNAMED --add-opens=java.base/java.lang=ALL-UNNAMED --add-opens=java.base/java.nio=ALL-UNNAMED --add-opens=java.base/sun.nio.ch=ALL-UNNAMED --add-opens=java.management/sun.management=ALL-UNNAMED --add-opens=jdk.management/com.sun.management.internal=ALL-UNNAMED -Dcom.redhat.fips=false -Xmx512m -Xms128m -XX:+HeapDumpOnOutOfMemoryError -Dhttp.nonProxyHosts=localhost|127.*|[::1] -cp ./lib/sonar-application-9.7.1.62043.jar;D:\a\test\sonarqube-9.7.1.62043\lib\jdbc\h2\h2-2.1.214.jar org.sonar.ce.app.CeServer D:\a\test\sonarqube-9.7.1.62043\temp\sq-process829163348814204568properties
2022.11.06 10:35:02 WARN  app[][startup] ####################################################################################################################
2022.11.06 10:50:00 WARN  app[][startup] Default Administrator credentials are still being used. Make sure to change the password or deactivate the account.
2022.11.06 10:50:00 WARN  app[][startup] ####################################################################################################################
2022.11.06 10:50:00 WARN  app[][o.s.a.p.AbstractManagedProcess] Process exited with exit value [ElasticSearch]: 1
2022.11.06 10:50:00 INFO  app[][o.s.a.SchedulerImpl] Process[ElasticSearch] is stopped
2022.11.06 10:50:00 INFO  app[][o.s.a.SchedulerImpl] Process[Compute Engine] is stopped

logs.zip (24.8 KB)

…with sonar.log.level=DEBUG I get attached logs. I still see no reason why it’s not working?

logs.zip (25.5 KB)

I don’t see one either, except that Elasticsearch exits with code 1… but it ends almost exactly 15 minutes after the process is started up, which doesn’t feel like it could be a coincidence (maybe there’s a timeout in the context of your integration tests?)

In the access.log of the file you shared, it looks like at some point GET api/ce/task stops being queried and it switches to api/ce/logs and then other API calls. If you’re receiving endless PENDING – what’s triggering the change to a new API call?

127.0.0.1 - - [06/Nov/2022:10:36:51 +0000] "POST /api/ce/submit?projectKey=clangsa_project HTTP/1.1" 200 44 "-" "ScannerCLI/4.7.0.2747" "AYRMgixA/CtIArLuAADR"
0:0:0:0:0:0:0:1 - - [06/Nov/2022:10:36:52 +0000] "GET /api/ce/task?id=AYRMg7agvpzmNCEdpTA4 HTTP/1.1" 200 284 "-" "python-requests/2.28.1" "AYRMgixA/CtIArLuAADS"
0:0:0:0:0:0:0:1 - - [06/Nov/2022:10:36:54 +0000] "GET /api/ce/task?id=AYRMg7agvpzmNCEdpTA4 HTTP/1.1" 200 284 "-" "python-requests/2.28.1" "AYRMgixA/CtIArLuAADT"
0:0:0:0:0:0:0:1 - - [06/Nov/2022:10:36:55 +0000] "GET /api/ce/task?id=AYRMg7agvpzmNCEdpTA4 HTTP/1.1" 200 284 "-" "python-requests/2.28.1" "AYRMgixA/CtIArLuAADU"
0:0:0:0:0:0:0:1 - - [06/Nov/2022:10:36:56 +0000] "GET /api/ce/task?id=AYRMg7agvpzmNCEdpTA4 HTTP/1.1" 200 284 "-" "python-requests/2.28.1" "AYRMgixA/CtIArLuAADV"
0:0:0:0:0:0:0:1 - - [06/Nov/2022:10:36:57 +0000] "GET /api/ce/task?id=AYRMg7agvpzmNCEdpTA4 HTTP/1.1" 200 284 "-" "python-requests/2.28.1" "AYRMgixA/CtIArLuAADW"
0:0:0:0:0:0:0:1 - - [06/Nov/2022:10:36:58 +0000] "GET /api/ce/task?id=AYRMg7agvpzmNCEdpTA4 HTTP/1.1" 200 284 "-" "python-requests/2.28.1" "AYRMgixA/CtIArLuAADX"
0:0:0:0:0:0:0:1 - - [06/Nov/2022:10:36:59 +0000] "GET /api/ce/task?id=AYRMg7agvpzmNCEdpTA4 HTTP/1.1" 200 284 "-" "python-requests/2.28.1" "AYRMgixA/CtIArLuAADY"
0:0:0:0:0:0:0:1 - - [06/Nov/2022:10:37:01 +0000] "GET /api/ce/task?id=AYRMg7agvpzmNCEdpTA4 HTTP/1.1" 200 284 "-" "python-requests/2.28.1" "AYRMgixA/CtIArLuAADZ"
0:0:0:0:0:0:0:1 - - [06/Nov/2022:10:37:02 +0000] "GET /api/ce/task?id=AYRMg7agvpzmNCEdpTA4 HTTP/1.1" 200 284 "-" "python-requests/2.28.1" "AYRMgixA/CtIArLuAADa"
0:0:0:0:0:0:0:1 - - [06/Nov/2022:10:37:02 +0000] "GET /api/ce/logs?taskId=AYRMg7agvpzmNCEdpTA4 HTTP/1.1" 404 49 "-" "python-requests/2.28.1" "AYRMgixA/CtIArLuAADb"

I don’t know why you don’t have a ce.log file, but you might still be able to access it via an API call to GET api/system/logs (?process=ce)

Hi, I tried to get the report with GET api/system/logs (?process=ce)
Also this is not working (returns wrong log file: access.log), see below.

In the access.log of the file you shared, it looks like at some point GET api/ce/task stops being queried and it switches to api/ce/logs and then other API calls. If you’re receiving endless PENDING – what’s triggering the change to a new API call?

There is a loop in a Python program calling GET /api/ce/task. After every try I’m waiting and asking again. After some tries I brake with timeout (in a first version I was waiting endless). After timeout I’m trying with the next test. At the end of all tests I stop SonarQube.

Looks like this on Windows:

Get Analysis In Background : http://localhost:9000/api/ce/task?id=AYRiEwoBzXO7cN8QBU6f
/api/ce/task response:
{"task":{"id":"AYRiEwoBzXO7cN8QBU6f","type":"REPORT","componentId":"AYRiEwkHzXO7cN8QBU6W","componentKey":"boosttest_project","componentName":"boosttest_project","componentQualifier":"TRK","status":"PENDING","submittedAt":"2022-11-10T15:05:25+0000","submitterLogin":"admin","warnings":[]}}
     CURRENT STATUS : PENDING
/api/ce/task response:
{"task":{"id":"AYRiEwoBzXO7cN8QBU6f","type":"REPORT","componentId":"AYRiEwkHzXO7cN8QBU6W","componentKey":"boosttest_project","componentName":"boosttest_project","componentQualifier":"TRK","status":"PENDING","submittedAt":"2022-11-10T15:05:25+0000","submitterLogin":"admin","warnings":[]}}
     CURRENT STATUS : PENDING
/api/ce/task response:
{"task":{"id":"AYRiEwoBzXO7cN8QBU6f","type":"REPORT","componentId":"AYRiEwkHzXO7cN8QBU6W","componentKey":"boosttest_project","componentName":"boosttest_project","componentQualifier":"TRK","status":"PENDING","submittedAt":"2022-11-10T15:05:25+0000","submitterLogin":"admin","warnings":[]}}
     CURRENT STATUS : PENDING
/api/ce/task response:
{"task":{"id":"AYRiEwoBzXO7cN8QBU6f","type":"REPORT","componentId":"AYRiEwkHzXO7cN8QBU6W","componentKey":"boosttest_project","componentName":"boosttest_project","componentQualifier":"TRK","status":"PENDING","submittedAt":"2022-11-10T15:05:25+0000","submitterLogin":"admin","warnings":[]}}
     CURRENT STATUS : PENDING
/api/ce/task response:
{"task":{"id":"AYRiEwoBzXO7cN8QBU6f","type":"REPORT","componentId":"AYRiEwkHzXO7cN8QBU6W","componentKey":"boosttest_project","componentName":"boosttest_project","componentQualifier":"TRK","status":"PENDING","submittedAt":"2022-11-10T15:05:25+0000","submitterLogin":"admin","warnings":[]}}
     CURRENT STATUS : PENDING
/api/ce/task response:
{"task":{"id":"AYRiEwoBzXO7cN8QBU6f","type":"REPORT","componentId":"AYRiEwkHzXO7cN8QBU6W","componentKey":"boosttest_project","componentName":"boosttest_project","componentQualifier":"TRK","status":"PENDING","submittedAt":"2022-11-10T15:05:25+0000","submitterLogin":"admin","warnings":[]}}
     CURRENT STATUS : PENDING
/api/ce/task response:
{"task":{"id":"AYRiEwoBzXO7cN8QBU6f","type":"REPORT","componentId":"AYRiEwkHzXO7cN8QBU6W","componentKey":"boosttest_project","componentName":"boosttest_project","componentQualifier":"TRK","status":"PENDING","submittedAt":"2022-11-10T15:05:25+0000","submitterLogin":"admin","warnings":[]}}
     CURRENT STATUS : PENDING
/api/ce/task response:
{"task":{"id":"AYRiEwoBzXO7cN8QBU6f","type":"REPORT","componentId":"AYRiEwkHzXO7cN8QBU6W","componentKey":"boosttest_project","componentName":"boosttest_project","componentQualifier":"TRK","status":"PENDING","submittedAt":"2022-11-10T15:05:25+0000","submitterLogin":"admin","warnings":[]}}
     CURRENT STATUS : PENDING
/api/ce/task response:
{"task":{"id":"AYRiEwoBzXO7cN8QBU6f","type":"REPORT","componentId":"AYRiEwkHzXO7cN8QBU6W","componentKey":"boosttest_project","componentName":"boosttest_project","componentQualifier":"TRK","status":"PENDING","submittedAt":"2022-11-10T15:05:25+0000","submitterLogin":"admin","warnings":[]}}
     CURRENT STATUS : PENDING
     CURRENT STATUS : timeout, abort
/api/system/logs?process=ce response:
0:0:0:0:0:0:0:1 - - [10/Nov/2022:15:04:32 +0000] "GET /api/system/status HTTP/1.1" 200 82 "-" "python-requests/2.28.1" "-"
0:0:0:0:0:0:0:1 - - [10/Nov/2022:15:04:42 +0000] "GET /api/system/status HTTP/1.1" 200 82 "-" "python-requests/2.28.1" "-"
0:0:0:0:0:0:0:1 - - [10/Nov/2022:15:04:52 +0000] "GET /api/system/status HTTP/1.1" 200 82 "-" "python-requests/2.28.1" "-"
0:0:0:0:0:0:0:1 - - [10/Nov/2022:15:05:02 +0000] "GET /api/system/status HTTP/1.1" 200 76 "-" "python-requests/2.28.1" "AYRiErCd5NoUQ9oZAAAA"
0:0:0:0:0:0:0:1 - - [10/Nov/2022:15:05:03 +0000] "GET /api/qualityprofiles/search HTTP/1.1" 200 - "-" "python-requests/2.28.1" "AYRiErCd5NoUQ9oZAAAB"
0:0:0:0:0:0:0:1 - - [10/Nov/2022:15:05:03 +0000] "POST /api/qualityprofiles/set_default HTTP/1.1" 204 - "-" "python-requests/2.28.1" "AYRiErCd5NoUQ9oZAAAC"
0:0:0:0:0:0:0:1 - - [10/Nov/2022:15:05:03 +0000] "POST /api/qualityprofiles/copy HTTP/1.1" 200 130 "-" "python-requests/2.28.1" "AYRiErCd5NoUQ9oZAAAD"
0:0:0:0:0:0:0:1 - - [10/Nov/2022:15:05:03 +0000] "GET /api/qualityprofiles/search HTTP/1.1" 200 - "-" "python-requests/2.28.1" "AYRiErCd5NoUQ9oZAAAE"
0:0:0:0:0:0:0:1 - - [10/Nov/2022:15:05:03 +0000] "POST /api/qualityprofiles/set_default HTTP/1.1" 204 - "-" "python-requests/2.28.1" "AYRiErCd5NoUQ9oZAAAF"
127.0.0.1 - - [10/Nov/2022:15:05:04 +0000] "GET /batch/index HTTP/1.1" 200 - "-" "ScannerCLI/4.7.0.2747" "AYRiErCd5NoUQ9oZAAAG"
127.0.0.1 - - [10/Nov/2022:15:05:05 +0000] "GET /batch/file?name=sonar-scanner-engine-shaded-9.7.1.62043-all.jar HTTP/1.1" 200 - "-" "ScannerCLI/4.7.0.2747" "AYRiErCd5NoUQ9oZAAAH"
...

Like this on Linux:

Get Analysis In Background : http://localhost:9000/api/ce/task?id=AYRiEV-DY_ydPeBY9p1i
/api/ce/task response:
{"task":{"id":"AYRiEV-DY_ydPeBY9p1i","type":"REPORT","componentId":"AYRiEV6CY_ydPeBY9p1Z","componentKey":"boosttest_project","componentName":"boosttest_project","componentQualifier":"TRK","status":"IN_PROGRESS","submittedAt":"2022-11-10T15:03:36+0000","submitterLogin":"admin","startedAt":"2022-11-10T15:03:37+0000","executionTimeMs":853,"warnings":[]}}
     CURRENT STATUS : IN_PROGRESS
/api/ce/task response:
{"task":{"id":"AYRiEV-DY_ydPeBY9p1i","type":"REPORT","componentId":"AYRiEV6CY_ydPeBY9p1Z","componentKey":"boosttest_project","componentName":"boosttest_project","componentQualifier":"TRK","status":"IN_PROGRESS","submittedAt":"2022-11-10T15:03:36+0000","submitterLogin":"admin","startedAt":"2022-11-10T15:03:37+0000","executionTimeMs":2211,"warnings":[]}}
     CURRENT STATUS : IN_PROGRESS
/api/ce/task response:
{"task":{"id":"AYRiEV-DY_ydPeBY9p1i","type":"REPORT","componentId":"AYRiEV6CY_ydPeBY9p1Z","componentKey":"boosttest_project","componentName":"boosttest_project","componentQualifier":"TRK","status":"IN_PROGRESS","submittedAt":"2022-11-10T15:03:36+0000","submitterLogin":"admin","startedAt":"2022-11-10T15:03:37+0000","executionTimeMs":3561,"warnings":[]}}
     CURRENT STATUS : IN_PROGRESS
/api/ce/task response:
{"task":{"id":"AYRiEV-DY_ydPeBY9p1i","type":"REPORT","componentId":"AYRiEV6CY_ydPeBY9p1Z","componentKey":"boosttest_project","componentName":"boosttest_project","componentQualifier":"TRK","status":"IN_PROGRESS","submittedAt":"2022-11-10T15:03:36+0000","submitterLogin":"admin","startedAt":"2022-11-10T15:03:37+0000","executionTimeMs":4850,"warnings":[]}}
     CURRENT STATUS : IN_PROGRESS
/api/ce/task response:
{"task":{"id":"AYRiEV-DY_ydPeBY9p1i","type":"REPORT","componentId":"AYRiEV6CY_ydPeBY9p1Z","componentKey":"boosttest_project","componentName":"boosttest_project","componentQualifier":"TRK","status":"IN_PROGRESS","submittedAt":"2022-11-10T15:03:36+0000","submitterLogin":"admin","startedAt":"2022-11-10T15:03:37+0000","executionTimeMs":6290,"warnings":[]}}
     CURRENT STATUS : IN_PROGRESS
/api/ce/task response:
{"task":{"id":"AYRiEV-DY_ydPeBY9p1i","type":"REPORT","componentId":"AYRiEV6CY_ydPeBY9p1Z","componentKey":"boosttest_project","componentName":"boosttest_project","componentQualifier":"TRK","analysisId":"AYRiEWXW6DieK6jSQNoM","status":"SUCCESS","submittedAt":"2022-11-10T15:03:36+0000","submitterLogin":"admin","startedAt":"2022-11-10T15:03:37+0000","executedAt":"2022-11-10T15:03:44+0000","executionTimeMs":7081,"hasScannerContext":true,"warningCount":1,"warnings":[]}}
     CURRENT STATUS : SUCCESS
/api/system/logs?process=ce response:
2022.11.10 15:03:08 INFO  ce[][o.s.p.ProcessEntryPoint] Starting Compute Engine
2022.11.10 15:03:08 INFO  ce[][o.s.ce.app.CeServer] Compute Engine starting up...
2022.11.10 15:03:09 INFO  ce[][o.sonar.db.Database] Create JDBC data source for jdbc:h2:tcp://127.0.0.1:9092/sonar;NON_KEYWORDS=VALUE
2022.11.10 15:03:09 INFO  ce[][c.z.h.HikariDataSource] HikariPool-1 - Starting...
2022.11.10 15:03:09 INFO  ce[][c.z.h.p.HikariPool] HikariPool-1 - Added connection conn0: url=jdbc:h2:tcp://127.0.0.1:9092/sonar user=
2022.11.10 15:03:09 INFO  ce[][c.z.h.HikariDataSource] HikariPool-1 - Start completed.
2022.11.10 15:03:09 WARN  ce[][o.s.db.dialect.H2] H2 database should be used for evaluation purpose only.
2022.11.10 15:03:11 INFO  ce[][o.s.s.p.ServerFileSystemImpl] SonarQube home: /home/runner/work/test/sonarqube-9.7.1.62043
2022.11.10 15:03:11 INFO  ce[][o.s.c.c.CePluginRepository] Load plugins
2022.11.10 15:03:13 INFO  ce[][o.s.c.c.ComputeEngineContainerImpl] Running Community edition
2022.11.10 15:03:13 INFO  ce[][o.s.ce.app.CeServer] Compute Engine is started
...

Still pretty clueless?
Call SonarStart.bat, wait with GET api/system/status until UP comes. GET api/system/health returns “Compute Engine is not operational” and when I try to query the ce.log it returns access.log ( GET api/system/logs?process=ce)?

How can I get more information for “Compute Engine is not operational”?

StartSonar.bat

/api/system/status response:

{"id":"147B411E-AYRmRYupMVloGNTjuDf0","version":"9.7.1.62043","status":"STARTING"}
{"id":"147B411E-AYRmRYupMVloGNTjuDf0","version":"9.7.1.62043","status":"STARTING"}
{"id":"147B411E-AYRmRYupMVloGNTjuDf0","version":"9.7.1.62043","status":"STARTING"}
{"id":"147B411E-AYRmRYupMVloGNTjuDf0","version":"9.7.1.62043","status":"UP"}

OK, duration: 90.6 s

/api/system/health response:

{"health":"RED","causes":[{"message":"Compute Engine is not operational"}]}

/api/system/info response:

{
   "Health":"RED",
   "Health Causes":[
      "Compute Engine is not operational"
   ],
   "System":{
      "Server ID":"147B411E-AYRmRYupMVloGNTjuDf0",
      "Version":"9.7.1.62043",
      "Docker":false,
      "High Availability":false,
      "Official Distribution":true,
      "Force authentication":true,
      "Home Dir":"D:\\a\\test\\sonarqube-9.7.1.62043",
      "Data Dir":"D:\\a\\test\\sonarqube-9.7.1.62043\\data",
      "Temp Dir":"D:\\a\\test\\sonarqube-9.7.1.62043\\temp",
      "Processors":2
   },
   "Database":{
      "Database":"H2",
      "Database Version":"2.1.214 (2022-06-13)",
      "Username":"",
      "URL":"jdbc:h2:tcp://127.0.0.1:9092/sonar",
      "Driver":"H2 JDBC Driver",
      "Driver Version":"2.1.214 (2022-06-13)",
      "Default transaction isolation":"TRANSACTION_READ_COMMITTED"
   },
   "Bundled":{
      "python":"3.19.0.10254 [Python Code Quality and Security]",
      "go":"1.11.0.3905 [Go Code Quality and Security]",
      "jacoco":"1.1.1.1157 [JaCoCo]",
      "kotlin":"2.10.0.1456 [Kotlin Code Quality and Security]",
      "iac":"1.9.2.2279 [IaC Code Quality and Security]",
      "javascript":"9.9.0.19492 [JavaScript/TypeScript/CSS Code Quality and Security]",
      "ruby":"1.11.0.3905 [Ruby Code Quality and Security]",
      "sonarscala":"1.11.0.3905 [Scala Code Quality and Security]",
      "csharp":"8.46.0.54807 [C# Code Quality and Security]",
      "java":"7.14.0.30229 [Java Code Quality and Security]",
      "web":"3.6.0.3106 [HTML Code Quality and Security]",
      "flex":"2.7.0.2865 [Flex Code Quality and Security]",
      "xml":"2.6.1.3686 [XML Code Quality and Security]",
      "php":"3.25.0.9077 [PHP Code Quality and Security]",
      "text":"1.1.0.282 [Text file Code Quality and Security]",
      "vbnet":"8.46.0.54807 [VB.NET Code Quality and Security]",
      "config":"1.2.0.267 [Configuration detection fot Code Quality and Security]"
   },
   "Plugins":{
      "cxx":"2.1.0.332 [C++ (Community)]"
   },
   "Web JVM State":{
      "Max Memory (MB)":512,
      "Free Memory (MB)":41,
      "Heap Committed (MB)":289,
      "Heap Init (MB)":128,
      "Heap Max (MB)":512,
      "Heap Used (MB)":247,
      "Non Heap Committed (MB)":168,
      "Non Heap Init (MB)":7,
      "Non Heap Used (MB)":161,
      "System Load Average":"-100.0% (last minute)",
      "Threads":45
   },
   "Web Database Connection":{
      "Pool Total Connections":11,
      "Pool Active Connections":1,
      "Pool Idle Connections":10,
      "Pool Max Connections":60,
      "Pool Min Idle Connections":10,
      "Pool Max Wait (ms)":8000,
      "Pool Max Lifetime (ms)":1800000
   },
   "Web Logging":{
      "Logs Level":"INFO",
      "Logs Dir":"D:\\a\\test\\sonarqube-9.7.1.62043\\logs"
   },
   "Web JVM Properties":{
      "awt.toolkit":"sun.awt.windows.WToolkit",
      "catalina.base":"D:\\a\\test\\sonarqube-9.7.1.62043\\temp\\tc",
      "catalina.home":"D:\\a\\test\\sonarqube-9.7.1.62043\\temp\\tc",
      "catalina.useNaming":"false",
      "com.redhat.fips":"false",
      "com.zaxxer.hikari.pool_number":"1",
      "file.encoding":"UTF-8",
      "file.separator":"\\",
      "h2.bindAddress":"127.0.0.1",
      "http.agent":"SonarQube 9.7.1.62043 # 147B411E-AYRmRYupMVloGNTjuDf0",
      "http.nonProxyHosts":"localhost|127.*|[::1]",
      "java.awt.graphicsenv":"sun.awt.Win32GraphicsEnvironment",
      "java.awt.headless":"true",
      "java.awt.printerjob":"sun.awt.windows.WPrinterJob",
      "java.class.path":"./lib/sonar-application-9.7.1.62043.jar;D:\\a\\test\\sonarqube-9.7.1.62043\\lib\\jdbc\\h2\\h2-2.1.214.jar",
      "java.class.version":"55.0",
      "java.home":"C:\\hostedtoolcache\\windows\\Java_Temurin-Hotspot_jdk\\11.0.17-8\\x64",
      "java.io.tmpdir":"D:\\a\\test\\sonarqube-9.7.1.62043\\temp",
      "java.library.path":"C:\\hostedtoolcache\\windows\\Java_Temurin-Hotspot_jdk\\11.0.17-8\\x64\\bin;C:\\Windows\\Sun\\Java\\bin;C:\\Windows\\system32;C:\\Windows;D:\\a\\test\\sonar-scanner-4.7.0.2747\\bin;C:\\Users\\runneradmin\\AppData\\Roaming\\Python\\Python37\\Scripts;C:\\hostedtoolcache\\windows\\Python\\3.7.9\\x64\\Scripts;C:\\hostedtoolcache\\windows\\Python\\3.7.9\\x64;C:\\hostedtoolcache\\windows\\Java_Temurin-Hotspot_jdk\\11.0.17-8\\x64\\bin;C:\\Program Files\\MongoDB\\Server\\5.0\\bin;C:\\aliyun-cli;C:\\vcpkg;C:\\Program Files (x86)\\NSIS\\;C:\\tools\\zstd;C:\\Program Files\\Mercurial\\;C:\\hostedtoolcache\\windows\\stack\\2.9.1\\x64;C:\\cabal\\bin;C:\\\\ghcup\\bin;C:\\tools\\ghc-9.4.2\\bin;C:\\Program Files\\dotnet;C:\\mysql\\bin;C:\\Program Files\\R\\R-4.2.1\\bin\\x64;C:\\SeleniumWebDrivers\\GeckoDriver;C:\\Program Files (x86)\\sbt\\bin;C:\\Program Files (x86)\\GitHub CLI;C:\\Program Files\\Git\\bin;C:\\Program Files (x86)\\pipx_bin;C:\\npm\\prefix;C:\\hostedtoolcache\\windows\\go\\1.17.13\\x64\\bin;C:\\hostedtoolcache\\windows\\Python\\3.9.13\\x64\\Scripts;C:\\hostedtoolcache\\windows\\Python\\3.9.13\\x64;C:\\hostedtoolcache\\windows\\Ruby\\3.0.4\\x64\\bin;C:\\tools\\kotlinc\\bin;C:\\hostedtoolcache\\windows\\Java_Temurin-Hotspot_jdk\\8.0.345-1\\x64\\bin;C:\\Program Files\\ImageMagick-7.1.0-Q16-HDRI;C:\\Program Files (x86)\\Microsoft SDKs\\Azure\\CLI2\\wbin;C:\\ProgramData\\kind;C:\\Program Files\\Microsoft\\jdk-11.0.12.7-hotspot\\bin;C:\\Windows\\system32;C:\\Windows;C:\\Windows\\System32\\Wbem;C:\\Windows\\System32\\WindowsPowerShell\\v1.0\\;C:\\Windows\\System32\\OpenSSH\\;C:\\Program Files\\dotnet\\;C:\\ProgramData\\Chocolatey\\bin;C:\\Program Files\\PowerShell\\7\\;C:\\Program Files\\Microsoft\\Web Platform Installer\\;C:\\Program Files\\Microsoft SQL Server\\Client SDK\\ODBC\\170\\Tools\\Binn\\;C:\\Program Files\\Microsoft SQL Server\\150\\Tools\\Binn\\;C:\\Program Files\\OpenSSL\\bin;C:\\Strawberry\\c\\bin;C:\\Strawberry\\perl\\site\\bin;C:\\Strawberry\\perl\\bin;C:\\ProgramData\\chocolatey\\lib\\pulumi\\tools\\Pulumi\\bin;C:\\Program Files\\TortoiseSVN\\bin;C:\\Program Files\\CMake\\bin;C:\\ProgramData\\chocolatey\\lib\\maven\\apache-maven-3.8.6\\bin;C:\\Program Files\\Microsoft Service Fabric\\bin\\Fabric\\Fabric.Code;C:\\Program Files\\Microsoft SDKs\\Service Fabric\\Tools\\ServiceFabricLocalClusterManager;C:\\Program Files\\nodejs\\;C:\\Program Files\\Git\\cmd;C:\\Program Files\\Git\\mingw64\\bin;C:\\Program Files\\Git\\usr\\bin;C:\\Program Files\\GitHub CLI\\;c:\\tools\\php;C:\\Program Files (x86)\\sbt\\bin;C:\\SeleniumWebDrivers\\ChromeDriver\\;C:\\SeleniumWebDrivers\\EdgeDriver\\;C:\\Program Files\\Amazon\\AWSCLIV2\\;C:\\Program Files\\Amazon\\SessionManagerPlugin\\bin\\;C:\\Program Files\\Amazon\\AWSSAMCLI\\bin\\;C:\\Program Files\\Microsoft SQL Server\\130\\Tools\\Binn\\;C:\\Program Files\\LLVM\\bin;C:\\Users\\runneradmin\\.dotnet\\tools;C:\\Users\\runneradmin\\.cargo\\bin;C:\\Users\\runneradmin\\AppData\\Local\\Microsoft\\WindowsApps;.",
      "java.runtime.name":"OpenJDK Runtime Environment",
      "java.runtime.version":"11.0.17+8",
      "java.specification.name":"Java Platform API Specification",
      "java.specification.vendor":"Oracle Corporation",
      "java.specification.version":"11",
      "java.vendor":"Eclipse Adoptium",
      "java.vendor.url":"https://adoptium.net/",
      "java.vendor.url.bug":"https://github.com/adoptium/adoptium-support/issues",
      "java.vendor.version":"Temurin-11.0.17+8",
      "java.version":"11.0.17",
      "java.version.date":"2022-10-18",
      "java.vm.compressedOopsMode":"32-bit",
      "java.vm.info":"mixed mode",
      "java.vm.name":"OpenJDK 64-Bit Server VM",
      "java.vm.specification.name":"Java Virtual Machine Specification",
      "java.vm.specification.vendor":"Oracle Corporation",
      "java.vm.specification.version":"11",
      "java.vm.vendor":"Eclipse Adoptium",
      "java.vm.version":"11.0.17+8",
      "jdk.debug":"release",
      "line.separator":"\r\n",
      "logbackDisableServletContainerInitializer":"true",
      "org.apache.catalina.startup.EXIT_ON_INIT_FAILURE":"true",
      "org.apache.tomcat.util.buf.UDecoder.ALLOW_ENCODED_SLASH":"true",
      "os.arch":"amd64",
      "os.name":"Windows Server 2022",
      "os.version":"10.0",
      "path.separator":";",
      "sun.arch.data.model":"64",
      "sun.boot.library.path":"C:\\hostedtoolcache\\windows\\Java_Temurin-Hotspot_jdk\\11.0.17-8\\x64\\bin",
      "sun.cpu.endian":"little",
      "sun.cpu.isalist":"amd64",
      "sun.desktop":"windows",
      "sun.io.unicode.encoding":"UnicodeLittle",
      "sun.java.command":"org.sonar.server.app.WebServer D:\\a\\test\\sonarqube-9.7.1.62043\\temp\\sq-process15632845847819876078properties",
      "sun.java.launcher":"SUN_STANDARD",
      "sun.jnu.encoding":"Cp1252",
      "sun.management.compiler":"HotSpot 64-Bit Tiered Compilers",
      "sun.os.patch.level":"",
      "user.country":"US",
      "user.dir":"D:\\a\\test\\sonarqube-9.7.1.62043",
      "user.home":"C:\\Users\\runneradmin",
      "user.language":"en",
      "user.name":"runneradmin",
      "user.script":"",
      "user.timezone":"UTC",
      "user.variant":""
   },
   "Search State":{
      "State":"GREEN",
      "CPU Usage (%)":6,
      "Disk Available":"12.1 GB",
      "Store Size":"20.4 MB",
      "Translog Size":"18.5 MB",
      "Open File Descriptors":-1,
      "Max File Descriptors":-1,
      "JVM Heap Usage":"34.0%",
      "JVM Heap Used":"185.4 MB",
      "JVM Heap Max":"536.9 MB",
      "JVM Non Heap Used":"129.3 MB",
      "JVM Threads":52,
      "Field Data Memory":"5.6 kB",
      "Field Data Circuit Breaker Limit":"214.7 MB",
      "Field Data Circuit Breaker Estimation":"5.6 kB",
      "Request Circuit Breaker Limit":"322.1 MB",
      "Request Circuit Breaker Estimation":"0 bytes",
      "Query Cache Memory":"0 bytes",
      "Request Cache Memory":"0 bytes"
   },
   "Search Indexes":{
      "Index components - Docs":0,
      "Index components - Shards":5,
      "Index components - Store Size":"1.1 kB",
      "Index metadatas - Docs":17,
      "Index metadatas - Shards":1,
      "Index metadatas - Store Size":"33.5 kB",
      "Index projectmeasures - Docs":0,
      "Index projectmeasures - Shards":5,
      "Index projectmeasures - Store Size":"1.1 kB",
      "Index rules - Docs":15275,
      "Index rules - Shards":2,
      "Index rules - Store Size":"20.3 MB",
      "Index issues - Docs":0,
      "Index issues - Shards":5,
      "Index issues - Store Size":"1.1 kB",
      "Index views - Docs":0,
      "Index views - Shards":5,
      "Index views - Store Size":"1.1 kB",
      "Index users - Docs":1,
      "Index users - Shards":1,
      "Index users - Store Size":"6.3 kB"
   },
   "ALMs":{
      
   },
   "Server Push Connections":{
      "SonarLint Connected Clients":0
   },
   "Settings":{
      "http.nonProxyHosts":"localhost|127.*|[::1]",
      "process.gracefulStopTimeout":"270000",
      "process.index":"2",
      "process.key":"web",
      "process.sharedDir":"D:\\a\\test\\sonarqube-9.7.1.62043\\temp",
      "projects.default.visibility":"public",
      "qualitygate.default":"AYRmRYdhMVloGNTjuDfj",
      "sonar.authenticator.ignoreStartupFailure":"false",
      "sonar.blueGreenEnabled":"false",
      "sonar.ce.gracefulStopTimeOutInMs":"21600000",
      "sonar.ce.javaAdditionalOpts":"",
      "sonar.ce.javaOpts":"-Xmx512m -Xms128m -XX:+HeapDumpOnOutOfMemoryError",
      "sonar.cluster.enabled":"false",
      "sonar.cluster.kubernetes":"false",
      "sonar.cluster.name":"sonarqube",
      "sonar.cluster.node.name":"sonarqube-ee34a62d-0c9f-4f7b-99c4-fa13334ea553",
      "sonar.cluster.node.port":"9003",
      "sonar.cluster.web.startupLeader":"true",
      "sonar.core.id":"147B411E-AYRmRYupMVloGNTjuDf0",
      "sonar.core.startTime":"2022-11-11T10:39:02+0000",
      "sonar.embeddedDatabase.port":"9092",
      "sonar.es.port":"57701",
      "sonar.forceAuthentication":"true",
      "sonar.jdbc.driverPath":"D:\\a\\test\\sonarqube-9.7.1.62043\\lib\\jdbc\\h2\\h2-2.1.214.jar",
      "sonar.jdbc.maxActive":"60",
      "sonar.jdbc.maxWait":"8000",
      "sonar.jdbc.minIdle":"10",
      "sonar.jdbc.password":"xxxxxxxx",
      "sonar.jdbc.url":"jdbc:h2:tcp://127.0.0.1:9092/sonar;NON_KEYWORDS\u003dVALUE",
      "sonar.jdbc.username":"",
      "sonar.log.jsonOutput":"false",
      "sonar.path.data":"D:\\a\\test\\sonarqube-9.7.1.62043\\data",
      "sonar.path.home":"D:\\a\\test\\sonarqube-9.7.1.62043",
      "sonar.path.logs":"D:\\a\\test\\sonarqube-9.7.1.62043\\logs",
      "sonar.path.temp":"D:\\a\\test\\sonarqube-9.7.1.62043\\temp",
      "sonar.path.web":"D:\\a\\test\\sonarqube-9.7.1.62043\\web",
      "sonar.plugins.risk.consent":"REQUIRED",
      "sonar.search.host":"127.0.0.1",
      "sonar.search.javaAdditionalOpts":"",
      "sonar.search.javaOpts":"-Xmx512m -Xms512m -XX:MaxDirectMemorySize\u003d256m -XX:+HeapDumpOnOutOfMemoryError",
      "sonar.search.port":"9001",
      "sonar.telemetry.compression":"true",
      "sonar.telemetry.enable":"true",
      "sonar.telemetry.frequencyInSeconds":"10800",
      "sonar.telemetry.url":"https://telemetry.sonarsource.com/sonarqube",
      "sonar.updatecenter.activate":"true",
      "sonar.web.gracefulStopTimeOutInMs":"240000",
      "sonar.web.javaAdditionalOpts":"",
      "sonar.web.javaOpts":"-Xmx512m -Xms128m -XX:+HeapDumpOnOutOfMemoryError",
      "sonar.web.sso.emailHeader":"X-Forwarded-Email",
      "sonar.web.sso.enable":"false",
      "sonar.web.sso.groupsHeader":"X-Forwarded-Groups",
      "sonar.web.sso.loginHeader":"X-Forwarded-Login",
      "sonar.web.sso.nameHeader":"X-Forwarded-Name",
      "sonar.web.sso.refreshIntervalInMinutes":"5",
      "Default New Code Definition":"PREVIOUS_VERSION"
   }
}

I’ve flagged this for some expert attention.

For me it looks like the Compute Engine is crashing during startup before it’s able to create a LOG file? Maybe a missing dependency? As already written this happens only running it with Github Actions with windows-latest (Windows Server 2022 and SQ > 9.5).

Is it possible to start only the CE to see if there are error messages during startup?

Very strange: I’m starting the StartSonar.bat file in a Python script. In case of using stdout=subprocess.PIPE starting CE is failing (like described above)?

No idea why this affects the launch of CE?

Failing:

command = ['cmd.exe', '/c', os.path.join(sonarhome, 'bin/windows-x86-64/StartSonar.bat')]
subprocess.Popen(command, stdout=subprocess.PIPE)

Working:

command = ['cmd.exe', '/c', os.path.join(sonarhome, 'bin/windows-x86-64/StartSonar.bat')]
subprocess.Popen(command)

This topic was automatically closed 7 days after the last reply. New replies are no longer allowed.