GitLab CI loop of empty posts for PR decoration when quality gate fails

NicolasH · January 23, 2020, 10:34am

Hello

We successfully configured SonarQube PR decoration for a self-hosted GitLab server with self signed certificates and it works just fine when the gitlab-ci pipeline, and the quality gate respectively,
succeeds.

From our .gitlab-ci.yml (SONAR_HOST_URL and SONAR_TOKEN passed as environment variables):

script:
    - 'mvn test sonar:sonar
        -Dsonar.qualitygate.wait=true'
  only:
    - merge_requests

GitLab access log shows following entry:

"x.x.x.x - - [23/Jan/2020:09:47:42 +0100]  "POST /api/v4/projects/20/merge_requests/9/notes?body=%23%23+SonarQube+Code+Analysis++%0A%23%23+Quality+Gate+passed++[...]" HTTP/2.0" 201 4149 "" "okhttp/3.14.2"

However, when the quality gate fails SonarQube keeps sending empty POSTs to our GitLab server infinitly until we restart the SonarQube server. Note: log timestamps copied from several trials and may vary.

x.x.x.x - - [23/Jan/2020:09:09:47 +0100] "POST  HTTP/2.0" 000 0 "" "-"
x.x.x.x- - [23/Jan/2020:09:09:47 +0100] "POST  HTTP/2.0" 000 0 "" "-"
x.x.x.x - - [23/Jan/2020:09:09:47 +0100] "POST  HTTP/2.0" 000 0 "" "-"
x.x.x.x - - [23/Jan/2020:09:09:47 +0100] "POST  HTTP/2.0" 000 0 "" "-"
x.x.x.x - - [23/Jan/2020:09:09:47 +0100] "POST  HTTP/2.0" 000 0 "" "-"

In the SonarQube ce.log file we get following entries

2020.01.23 11:05:52 DEBUG ce[AW_R3XEzmtc3Okx_LPPf][jdk.event.security] ValidationChain: 86393724, 2041265836
2020.01.23 11:05:52 DEBUG ce[AW_R3XEzmtc3Okx_LPPf][jdk.event.security]  TLSHandshake: y.y.y.y:443, TLSv1.3, TLS_AES_256_GCM_SHA384, 2041265836
2020.01.23 11:05:52 DEBUG ce[AW_R3XEzmtc3Okx_LPPf][o.i.http2.Http2] >> CONNECTION 505249202a20485454502f322e300d0a0d0a534d0d0a0d0a
2020.01.23 11:05:52 DEBUG ce[AW_R3XEzmtc3Okx_LPPf][o.i.http2.Http2] >> 0x00000000     6 SETTINGS
2020.01.23 11:05:52 DEBUG ce[AW_R3XEzmtc3Okx_LPPf][o.i.http2.Http2] >> 0x00000000     4 WINDOW_UPDATE
2020.01.23 11:05:52 DEBUG ce[AW_R3XEzmtc3Okx_LPPf][o.i.http2.Http2] >> 0x00000003  4254 HEADERS       END_HEADERS
2020.01.23 11:05:52 DEBUG ce[AW_R3XEzmtc3Okx_LPPf][o.i.http2.Http2] >> 0x00000003     0 DATA          END_STREAM
2020.01.23 11:05:52 DEBUG ce[][o.i.http2.Http2] << 0x00000000    18 SETTINGS
2020.01.23 11:05:52 DEBUG ce[][o.i.http2.Http2] << 0x00000000     4 WINDOW_UPDATE
2020.01.23 11:05:52 DEBUG ce[][o.i.http2.Http2] << 0x00000000     0 SETTINGS      ACK
2020.01.23 11:05:52 DEBUG ce[][o.i.http2.Http2] >> 0x00000000     0 SETTINGS      ACK
2020.01.23 11:05:52 DEBUG ce[][o.i.http2.Http2] << 0x00000000     8 GOAWAY
2020.01.23 11:05:52 DEBUG ce[][o.i.http2.Http2] >> 0x00000003     4 RST_STREAM
2020.01.23 11:05:52 DEBUG ce[AW_R3XEzmtc3Okx_LPPf][jdk.event.security] ValidationChain: 86393724, 2041265836
2020.01.23 11:05:52 DEBUG ce[AW_R3XEzmtc3Okx_LPPf][jdk.event.security]  TLSHandshake: y.y.y.y:443, TLSv1.3, TLS_AES_256_GCM_SHA384, 2041265836
2020.01.23 11:05:52 DEBUG ce[AW_R3XEzmtc3Okx_LPPf][o.i.http2.Http2] >> CONNECTION 505249202a20485454502f322e300d0a0d0a534d0d0a0d0a
2020.01.23 11:05:52 DEBUG ce[AW_R3XEzmtc3Okx_LPPf][o.i.http2.Http2] >> 0x00000000     6 SETTINGS
2020.01.23 11:05:52 DEBUG ce[AW_R3XEzmtc3Okx_LPPf][o.i.http2.Http2] >> 0x00000000     4 WINDOW_UPDATE
2020.01.23 11:05:52 DEBUG ce[AW_R3XEzmtc3Okx_LPPf][o.i.http2.Http2] >> 0x00000003  4254 HEADERS       END_HEADERS
2020.01.23 11:05:52 DEBUG ce[AW_R3XEzmtc3Okx_LPPf][o.i.http2.Http2] >> 0x00000003     0 DATA          END_STREAM
2020.01.23 11:05:52 DEBUG ce[][o.i.http2.Http2] << 0x00000000    18 SETTINGS
2020.01.23 11:05:52 DEBUG ce[][o.i.http2.Http2] << 0x00000000     4 WINDOW_UPDATE
2020.01.23 11:05:52 DEBUG ce[][o.i.http2.Http2] << 0x00000000     0 SETTINGS      ACK
2020.01.23 11:05:52 DEBUG ce[][o.i.http2.Http2] >> 0x00000000     0 SETTINGS      ACK
2020.01.23 11:05:52 DEBUG ce[][o.i.http2.Http2] << 0x00000000     8 GOAWAY
2020.01.23 11:05:52 DEBUG ce[][o.i.http2.Http2] >> 0x00000003     4 RST_STREAM
2020.01.23 11:05:52 DEBUG ce[AW_R3XEzmtc3Okx_LPPf][jdk.event.security]  TLSHandshake: y.y.y.y:443, TLSv1.3, TLS_AES_256_GCM_SHA384, 2041265836
2020.01.23 11:05:52 DEBUG ce[AW_R3XEzmtc3Okx_LPPf][o.i.http2.Http2] >> CONNECTION 505249202a20485454502f322e300d0a0d0a534d0d0a0d0a
2020.01.23 11:05:52 DEBUG ce[AW_R3XEzmtc3Okx_LPPf][o.i.http2.Http2] >> 0x00000000     6 SETTINGS
2020.01.23 11:05:52 DEBUG ce[AW_R3XEzmtc3Okx_LPPf][o.i.http2.Http2] >> 0x00000000     4 WINDOW_UPDATE
2020.01.23 11:05:52 DEBUG ce[AW_R3XEzmtc3Okx_LPPf][o.i.http2.Http2] >> 0x00000003  4254 HEADERS       END_HEADERS
2020.01.23 11:05:52 DEBUG ce[AW_R3XEzmtc3Okx_LPPf][o.i.http2.Http2] >> 0x00000003     0 DATA          END_STREAM
2020.01.23 11:05:52 DEBUG ce[][o.i.http2.Http2] << 0x00000000    18 SETTINGS
2020.01.23 11:05:52 DEBUG ce[][o.i.http2.Http2] << 0x00000000     4 WINDOW_UPDATE
2020.01.23 11:05:52 DEBUG ce[][o.i.http2.Http2] >> 0x00000000     0 SETTINGS      ACK
2020.01.23 11:05:52 DEBUG ce[][o.i.http2.Http2] << 0x00000000     0 SETTINGS      ACK
2020.01.23 11:05:52 DEBUG ce[][o.i.http2.Http2] << 0x00000000     8 GOAWAY
2020.01.23 11:05:52 DEBUG ce[][o.i.http2.Http2] >> 0x00000003     4 RST_STREAM

Also we noticed that when the quality gate fails the following line is missing in the logs

2020.01.23 09:47:42 DEBUG ce[AW_RlenHc81fFix3m0Aw][jdk.event.security] X509Certificate: Alg:SHA256withRSA, Serial:b, Subject:CN=..., OU="...", O=..., L=..., ST=HE, C=DE, Issuer:EMAILADDRESS=postmaster@..., CN=YaST Default CA (...), C=DE, Key type:RSA, Length:2048, Cert Id:..., Valid from:1/6/20, 3:58 PM, Valid until:1/5/21, 3:58 PM

Gitlab Version: 12.6.4-ee & 12.4.0-ee
GitLab Runner Version: 12.4.0
SonarQube Version: Version 8.1 (build 31237) Developer Edition
Maven Version: 3.6.3
Java Version: openJDK11

pierreguillot · January 28, 2020, 10:42am

Welcome to the community forum!

Any warning displayed in SonarQube in the PR view (when the QG fail) ?

NicolasH · January 28, 2020, 12:04pm

Yes, but it’s just saying that the PR decoration failed and that it’s probably a misconfiguration (I don’t have the exact wording available that the moment). But as the decoration works when the quality gate succeeds, it can’t really be a configuration fault.

pierreguillot · January 28, 2020, 12:58pm

So you should have an ERROR log in your ce.log. Anything interesting there ? I see that you looked at debug stuff, but the catched exception should be in ERROR level somewhere in the file.

NicolasH · January 29, 2020, 7:20am

Unfortunally there is no ERROR in the log, application is running with log level INFO and this is all what we get in the logs. The server is then in an endless loop state and does not respond to further requests and we need to restart the service.

2020.01.29 08:15:54 INFO  ce[][o.s.c.t.CeWorkerImpl] Execute task | project=myBuggyProject | type=REPORT | pullRequest=2 | id=AW_wKAwvfH0Cs6gsvtQ_ | submitter=xxx
2020.01.29 08:15:54 INFO  ce[AW_wKAwvfH0Cs6gsvtQ_][o.s.c.t.s.ComputationStepExecutor] Extract report | status=SUCCESS | time=12ms
2020.01.29 08:15:54 INFO  ce[AW_wKAwvfH0Cs6gsvtQ_][o.s.c.t.s.ComputationStepExecutor] Persist scanner context | status=SUCCESS | time=5ms
2020.01.29 08:15:54 INFO  ce[AW_wKAwvfH0Cs6gsvtQ_][o.s.c.t.s.ComputationStepExecutor] Propagate analysis warnings from scanner report | status=SUCCESS | time=0ms
2020.01.29 08:15:54 INFO  ce[AW_wKAwvfH0Cs6gsvtQ_][o.s.c.t.s.ComputationStepExecutor] Execute DB migrations for current project | status=SUCCESS | time=1ms
2020.01.29 08:15:54 INFO  ce[AW_wKAwvfH0Cs6gsvtQ_][o.s.c.t.s.ComputationStepExecutor] Generate analysis UUID | status=SUCCESS | time=0ms
2020.01.29 08:15:54 INFO  ce[AW_wKAwvfH0Cs6gsvtQ_][o.s.c.t.s.ComputationStepExecutor] Load analysis metadata | status=SUCCESS | time=7ms
2020.01.29 08:15:54 INFO  ce[AW_wKAwvfH0Cs6gsvtQ_][o.s.c.t.s.ComputationStepExecutor] Initialize | status=SUCCESS | time=5ms
2020.01.29 08:15:54 INFO  ce[AW_wKAwvfH0Cs6gsvtQ_][o.s.c.t.s.ComputationStepExecutor] Verify billing | status=SUCCESS | time=0ms
2020.01.29 08:15:54 INFO  ce[AW_wKAwvfH0Cs6gsvtQ_][o.s.c.t.s.ComputationStepExecutor] Build tree of components | components=4 | status=SUCCESS | time=9ms
2020.01.29 08:15:54 INFO  ce[AW_wKAwvfH0Cs6gsvtQ_][o.s.c.t.s.ComputationStepExecutor] Validate project | status=SUCCESS | time=2ms
2020.01.29 08:15:55 INFO  ce[AW_wKAwvfH0Cs6gsvtQ_][o.s.c.t.s.ComputationStepExecutor] Load quality profiles | status=SUCCESS | time=170ms
2020.01.29 08:15:55 INFO  ce[AW_wKAwvfH0Cs6gsvtQ_][o.s.c.t.s.ComputationStepExecutor] Load Quality gate | status=SUCCESS | time=5ms
2020.01.29 08:15:55 INFO  ce[AW_wKAwvfH0Cs6gsvtQ_][o.s.c.t.s.ComputationStepExecutor] Load new code period | status=SUCCESS | time=0ms
2020.01.29 08:15:55 INFO  ce[AW_wKAwvfH0Cs6gsvtQ_][o.s.c.t.s.ComputationStepExecutor] Detect file moves | reportFiles=1 | dbFiles=0 | addedFiles=1 | status=SUCCESS | time=2ms
2020.01.29 08:15:55 INFO  ce[AW_wKAwvfH0Cs6gsvtQ_][o.s.c.t.s.ComputationStepExecutor] Load duplications | duplications=2 | status=SUCCESS | time=1ms
2020.01.29 08:15:55 INFO  ce[AW_wKAwvfH0Cs6gsvtQ_][o.s.c.t.s.ComputationStepExecutor] Compute cross project duplications | status=SUCCESS | time=0ms
2020.01.29 08:15:55 INFO  ce[AW_wKAwvfH0Cs6gsvtQ_][o.s.c.t.s.ComputationStepExecutor] Compute size measures | status=SUCCESS | time=0ms
2020.01.29 08:15:55 INFO  ce[AW_wKAwvfH0Cs6gsvtQ_][o.s.c.t.s.ComputationStepExecutor] Compute new coverage | status=SUCCESS | time=0ms
2020.01.29 08:15:55 INFO  ce[AW_wKAwvfH0Cs6gsvtQ_][o.s.c.t.s.ComputationStepExecutor] Compute coverage measures | status=SUCCESS | time=6ms
2020.01.29 08:15:55 INFO  ce[AW_wKAwvfH0Cs6gsvtQ_][o.s.c.t.s.ComputationStepExecutor] Compute comment measures | status=SUCCESS | time=0ms
2020.01.29 08:15:55 INFO  ce[AW_wKAwvfH0Cs6gsvtQ_][o.s.c.t.s.ComputationStepExecutor] Copy custom measures | status=SUCCESS | time=8ms
2020.01.29 08:15:55 INFO  ce[AW_wKAwvfH0Cs6gsvtQ_][o.s.c.t.s.ComputationStepExecutor] Compute duplication measures | status=SUCCESS | time=1ms
2020.01.29 08:15:55 INFO  ce[AW_wKAwvfH0Cs6gsvtQ_][o.s.c.t.s.ComputationStepExecutor] Compute size measures on new code | status=SUCCESS | time=0ms
2020.01.29 08:15:55 INFO  ce[AW_wKAwvfH0Cs6gsvtQ_][o.s.c.t.s.ComputationStepExecutor] Compute language distribution | status=SUCCESS | time=0ms
2020.01.29 08:15:55 INFO  ce[AW_wKAwvfH0Cs6gsvtQ_][o.s.c.t.s.ComputationStepExecutor] Compute test measures | status=SUCCESS | time=0ms
2020.01.29 08:15:55 INFO  ce[AW_wKAwvfH0Cs6gsvtQ_][o.s.c.t.s.ComputationStepExecutor] Compute complexity measures | status=SUCCESS | time=0ms
2020.01.29 08:15:55 INFO  ce[AW_wKAwvfH0Cs6gsvtQ_][o.s.c.t.s.ComputationStepExecutor] Load measure computers | status=SUCCESS | time=0ms
2020.01.29 08:15:55 INFO  ce[AW_wKAwvfH0Cs6gsvtQ_][o.s.c.t.s.ComputationStepExecutor] Compute Quality Profile status | status=SUCCESS | time=2ms
2020.01.29 08:15:55 INFO  ce[AW_wKAwvfH0Cs6gsvtQ_][o.s.c.t.s.ComputationStepExecutor] Execute component visitors | status=SUCCESS | time=76ms
2020.01.29 08:15:55 INFO  ce[AW_wKAwvfH0Cs6gsvtQ_][o.s.c.t.s.ComputationStepExecutor] Checks executed after computation of measures | status=SUCCESS | time=5ms
2020.01.29 08:15:55 INFO  ce[AW_wKAwvfH0Cs6gsvtQ_][o.s.c.t.s.ComputationStepExecutor] Compute Quality Gate measures | status=SUCCESS | time=13ms
2020.01.29 08:15:55 INFO  ce[AW_wKAwvfH0Cs6gsvtQ_][o.s.c.t.s.ComputationStepExecutor] Compute Quality profile measures | status=SUCCESS | time=0ms
2020.01.29 08:15:55 INFO  ce[AW_wKAwvfH0Cs6gsvtQ_][o.s.c.t.s.ComputationStepExecutor] Generate Quality profile events | status=SUCCESS | time=2ms
2020.01.29 08:15:55 INFO  ce[AW_wKAwvfH0Cs6gsvtQ_][o.s.c.t.s.ComputationStepExecutor] Generate Quality gate events | status=SUCCESS | time=0ms
2020.01.29 08:15:55 INFO  ce[AW_wKAwvfH0Cs6gsvtQ_][o.s.c.t.s.ComputationStepExecutor] Persist components | status=SUCCESS | time=14ms
2020.01.29 08:15:55 INFO  ce[AW_wKAwvfH0Cs6gsvtQ_][o.s.c.t.s.ComputationStepExecutor] Persist analysis | status=SUCCESS | time=3ms
2020.01.29 08:15:55 INFO  ce[AW_wKAwvfH0Cs6gsvtQ_][o.s.c.t.s.ComputationStepExecutor] Persist analysis properties | status=SUCCESS | time=5ms
2020.01.29 08:15:55 INFO  ce[AW_wKAwvfH0Cs6gsvtQ_][o.s.c.t.s.ComputationStepExecutor] Persist measures | inserts=75 | status=SUCCESS | time=9ms
2020.01.29 08:15:55 INFO  ce[AW_wKAwvfH0Cs6gsvtQ_][o.s.c.t.s.ComputationStepExecutor] Persist live measures | insertsOrUpdates=268 | status=SUCCESS | time=41ms
2020.01.29 08:15:55 INFO  ce[AW_wKAwvfH0Cs6gsvtQ_][o.s.c.t.s.ComputationStepExecutor] Persist duplication data | insertsOrUpdates=0 | status=SUCCESS | time=0ms
2020.01.29 08:15:55 INFO  ce[AW_wKAwvfH0Cs6gsvtQ_][o.s.c.t.s.ComputationStepExecutor] Persist new ad hoc Rules | status=SUCCESS | time=0ms
2020.01.29 08:15:55 INFO  ce[AW_wKAwvfH0Cs6gsvtQ_][o.s.c.t.s.ComputationStepExecutor] Persist issues | inserts=2 | updates=0 | merged=0 | untouched=0 | status=SUCCESS | time=13ms
2020.01.29 08:15:55 INFO  ce[AW_wKAwvfH0Cs6gsvtQ_][o.s.c.t.s.ComputationStepExecutor] Persist project links | status=SUCCESS | time=0ms
2020.01.29 08:15:55 INFO  ce[AW_wKAwvfH0Cs6gsvtQ_][o.s.c.t.s.ComputationStepExecutor] Persist events | status=SUCCESS | time=3ms
2020.01.29 08:15:55 INFO  ce[AW_wKAwvfH0Cs6gsvtQ_][o.s.c.t.s.ComputationStepExecutor] Persist sources | status=SUCCESS | time=12ms
2020.01.29 08:15:55 INFO  ce[AW_wKAwvfH0Cs6gsvtQ_][o.s.c.t.s.ComputationStepExecutor] Persist cross project duplications | status=SUCCESS | time=0ms
2020.01.29 08:15:55 INFO  ce[AW_wKAwvfH0Cs6gsvtQ_][o.s.c.t.s.ComputationStepExecutor] Enable analysis | status=SUCCESS | time=3ms
2020.01.29 08:15:55 INFO  ce[AW_wKAwvfH0Cs6gsvtQ_][o.s.c.t.s.ComputationStepExecutor] Update last usage date of quality profiles | status=SUCCESS | time=23ms
2020.01.29 08:15:55 INFO  ce[AW_wKAwvfH0Cs6gsvtQ_][o.s.c.t.s.ComputationStepExecutor] Purge db | status=SUCCESS | time=37ms
2020.01.29 08:15:55 INFO  ce[AW_wKAwvfH0Cs6gsvtQ_][o.s.c.t.s.ComputationStepExecutor] Index analysis | status=SUCCESS | time=63ms
2020.01.29 08:15:55 INFO  ce[AW_wKAwvfH0Cs6gsvtQ_][o.s.c.t.s.ComputationStepExecutor] Send issue notifications | status=SUCCESS | time=0ms
2020.01.29 08:15:55 INFO  ce[AW_wKAwvfH0Cs6gsvtQ_][o.s.c.t.s.ComputationStepExecutor] Publish task results | status=SUCCESS | time=0ms
2020.01.29 08:15:55 INFO  ce[AW_wKAwvfH0Cs6gsvtQ_][o.s.c.t.s.ComputationStepExecutor] Trigger refresh of Portfolios and Applications | status=SUCCESS | time=0ms
2020.01.29 08:15:55 INFO  ce[AW_wKAwvfH0Cs6gsvtQ_][o.s.c.t.p.a.p.PostProjectAnalysisTasksExecutor] Webhooks | globalWebhooks=0 | projectWebhooks=0 | status=SUCCESS | time=2ms

After five minutes we received following message in the ce.log

2020.01.29 08:20:55 WARN  ce[][okhttp3.OkHttpClient] A connection to https://x.x.x.x/ was leaked. Did you forget to close a response body? To see where this was allocated, set the OkHttpClient logger level to FINE: Logger.getLogger(OkHttpClient.class.getName()).setLevel(Level.FINE);

Update: Apparently the message on the GUI was from another try where the analysis completed and the PR decoration failed for another reason (setting parameters manually in .gitlab-ci.yml), trying now does not give us any message on GUI only says:

The analysis is in progress.

rlee · January 30, 2020, 8:19pm

I’m running into a similar issue when QG fails which causes the GET function to continuously loop in the PR Decoration. I found this in the access.log as the log continues to fill.

I’m evaluating the SonarQube Enterprise Edition while running Gitlab On-Prem.

To give a bit more context:

Gitlab calls Sonarqube to run the analysis. As it’s waiting for Quality Gate Status, after 5 minutes, the runner times out stating Quality Gate check timeout exceeded and gives the link to the merge_request. The link states that Quality Gate has failed with the bug. When I go to Sonarqube and look at the background processes, it’s still running an analysis, however, it’s not.

When I check the es.log there’s nothing showing, not until I check access.log which shows a stream of GET requests.

This only happens when Quality Gate fails.

pierreguillot · February 6, 2020, 4:07pm

Looks like we indeed have an issue with self-signed certificate. @NicolasH and @rlee, how your SSL certificates are generated ?

tsmigaj · February 11, 2020, 7:28am

I am also affected by this issue.
However, I noticed that after more than 1 hour in loop, the analysis task times out.

I use CA signed certificate for on-prem gitlab.
SonarQube is not running SSL.

@pierreguillot Do you know if any workaround for the problem (other than stop using PR decoration) exists yet?

pierreguillot · February 11, 2020, 9:42am

I tracked this matter here, the SonarQube team need to investigate and reproduce. We internally tested this feature on gitlab.com, which does not show this behaviour. I hope we will be able to investigate this before 8.2, no promise though

No workaround yet

srsukhov · February 25, 2020, 5:45am

Hello,
I faced with same issue, but for some reason it doesn’t happen with all my sonarqube projects, with some of them, if you need any logs or info feel free to request them.

pierreguillot · February 25, 2020, 8:43am

Hello, we fixed few issues in the GitLab Merge Request decoration mechanism in the 8.2 version that will be published this week. When available, please give it a try, and if the issue is still present, turn ce logs to DEBUG and post your logs here. I added a few useful logs.

Clement_Stoquart · February 28, 2020, 9:05am

Hello,

We’re currently testing the merge request decoration feature with Gitlab 12.7 CE and SonarQube 8.2 developer edition and we’re hitting an infinity loop issue.

So when the quality gate is passed everything is fine. The merge request is properly commented by SonarQube as expected.

But when the quality gate isn’t passed the merge request isn’t commented and the analysis never ends.

ce.log becomes a bit crazy printing these lines block many times per second:

2020.02.27 16:06:04 DEBUG ce[][o.i.http2.Http2] << 0x00000000     8 GOAWAY
2020.02.27 16:06:04 DEBUG ce[][o.i.http2.Http2] >> 0x00000009     4 RST_STREAM
2020.02.27 16:06:04 DEBUG ce[AXCHLtqIO2hDuTzVGory][o.i.http2.Http2] >> CONNECTION 505249202a20485454502f322e300d0a0d0a534d0d0a0d0a
2020.02.27 16:06:04 DEBUG ce[AXCHLtqIO2hDuTzVGory][o.i.http2.Http2] >> 0x00000000     6 SETTINGS
2020.02.27 16:06:04 DEBUG ce[AXCHLtqIO2hDuTzVGory][o.i.http2.Http2] >> 0x00000000     4 WINDOW_UPDATE
2020.02.27 16:06:04 DEBUG ce[AXCHLtqIO2hDuTzVGory][o.i.http2.Http2] >> 0x00000003  4637 HEADERS       END_HEADERS
2020.02.27 16:06:04 DEBUG ce[AXCHLtqIO2hDuTzVGory][o.i.http2.Http2] >> 0x00000003     0 DATA          END_STREAM
2020.02.27 16:06:04 DEBUG ce[][o.i.http2.Http2] << 0x00000000    18 SETTINGS
2020.02.27 16:06:04 DEBUG ce[][o.i.http2.Http2] << 0x00000000     4 WINDOW_UPDATE
2020.02.27 16:06:04 DEBUG ce[][o.i.http2.Http2] << 0x00000000     0 SETTINGS      ACK

We need to reboot the SonarQube server to get rid of the associated background task.

I’ve tested running the api call https://gitlab.mycompany.com/api/v4/projects/6044/merge_requests/2/notes by myself using a rest client and it worked.

Any help would be appreciated

pierreguillot · February 28, 2020, 9:29am

Welcome to the community forum! Could you please put sonar.log.level.ce in DEBUG and provide us a full trace of an analysis from the start, to theses http2 logs ? I’m interested in what is between. If the logs contains sensitive information, feel free to send me the file by private message.

Clement_Stoquart · February 28, 2020, 12:48pm

Thanks for your quick answer

Here are the requested logs:

2020.02.27 16:06:03 INFO  ce[AXCHLtqIO2hDuTzVGory][o.s.c.t.p.a.p.PostProjectAnalysisTasksExecutor] Webhooks | globalWebhooks=0 | projectWebhooks=0 | status=SUCCESS | time=15ms
2020.02.27 16:06:03 DEBUG ce[AXCHLtqIO2hDuTzVGory][GitlabPrHttpClient] loading notes from [https://gitlab.mycompany.com/api/v4/projects/6044/merge_requests/2/notes]
2020.02.27 16:06:03 DEBUG ce[AXCHLtqIO2hDuTzVGory][o.i.http2.Http2] >> CONNECTION 505249202a20485454502f322e300d0a0d0a534d0d0a0d0a
2020.02.27 16:06:03 DEBUG ce[AXCHLtqIO2hDuTzVGory][o.i.http2.Http2] >> 0x00000000     6 SETTINGS
2020.02.27 16:06:03 DEBUG ce[AXCHLtqIO2hDuTzVGory][o.i.http2.Http2] >> 0x00000000     4 WINDOW_UPDATE
2020.02.27 16:06:03 DEBUG ce[AXCHLtqIO2hDuTzVGory][o.i.http2.Http2] >> 0x00000003    95 HEADERS       END_STREAM|END_HEADERS
2020.02.27 16:06:03 DEBUG ce[][o.i.http2.Http2] << 0x00000000    18 SETTINGS
2020.02.27 16:06:03 DEBUG ce[][o.i.http2.Http2] << 0x00000000     4 WINDOW_UPDATE
2020.02.27 16:06:03 DEBUG ce[][o.i.http2.Http2] >> 0x00000000     0 SETTINGS      ACK
2020.02.27 16:06:03 DEBUG ce[][o.i.http2.Http2] << 0x00000000     0 SETTINGS      ACK
2020.02.27 16:06:04 DEBUG ce[][o.i.http2.Http2] << 0x00000003   623 HEADERS       END_HEADERS
2020.02.27 16:06:04 DEBUG ce[][o.i.http2.Http2] << 0x00000003  3291 DATA
2020.02.27 16:06:04 DEBUG ce[][o.i.http2.Http2] << 0x00000003  3412 DATA
2020.02.27 16:06:04 DEBUG ce[][o.i.http2.Http2] << 0x00000003     0 DATA          END_STREAM
2020.02.27 16:06:04 DEBUG ce[AXCHLtqIO2hDuTzVGory][GitlabPrHttpClient] get current user : [https://gitlab.mycompany.com/api/v4/user]
2020.02.27 16:06:04 DEBUG ce[AXCHLtqIO2hDuTzVGory][o.i.http2.Http2] >> 0x00000005    17 HEADERS       END_STREAM|END_HEADERS
2020.02.27 16:06:04 DEBUG ce[][o.i.http2.Http2] << 0x00000005   284 HEADERS       END_HEADERS
2020.02.27 16:06:04 DEBUG ce[][o.i.http2.Http2] << 0x00000005   765 DATA          END_STREAM
2020.02.27 16:06:04 DEBUG ce[AXCHLtqIO2hDuTzVGory][GitlabPrHttpClient] delete note [https://gitlab.mycompany.com/api/v4/projects/6044/merge_requests/2/notes/800646]
2020.02.27 16:06:04 DEBUG ce[AXCHLtqIO2hDuTzVGory][o.i.http2.Http2] >> 0x00000007    54 HEADERS       END_HEADERS
2020.02.27 16:06:04 DEBUG ce[AXCHLtqIO2hDuTzVGory][o.i.http2.Http2] >> 0x00000007     0 DATA          END_STREAM
2020.02.27 16:06:04 DEBUG ce[][o.i.http2.Http2] << 0x00000007     4 WINDOW_UPDATE
2020.02.27 16:06:04 DEBUG ce[][o.i.http2.Http2] << 0x00000007   213 HEADERS       END_STREAM|END_HEADERS
2020.02.27 16:06:04 DEBUG ce[AXCHLtqIO2hDuTzVGory][GitlabPrHttpClient] post note : [https://gitlab.mycompany.com/api/v4/projects/6044/merge_requests/2/notes?body=%23%23+SonarQube+Code+Analysis++%0A%23%23+Quality+Gate+failed++%0A%5B%21%5BQuality+Gate+failed%5D%28https%3A%2F%2Felb-sonar-ee-mycompany-tooling-dev-1.aws.mycompany.com%2Fstatic%2Fdeveloper-server%2Fchecks%2FQualityGateBadge%2Ffailed.svg+%27Quality+Gate+failed%27%29%5D%28https%3A%2F%2Felb-sonar-ee-mycompany-tooling-dev-1.aws.mycompany.com%2Fdashboard%3Fid%3Dcom.mycompany%253Ademo%26pullRequest%3D2%29%0A%0A%5B%21%5BFailed+condition%5D%28https%3A%2F%2Felb-sonar-ee-mycompany-tooling-dev-1.aws.mycompany.com%2Fstatic%2Fdeveloper-server%2Fchecks%2FFailedConditionIcon.svg+%27Failed+condition%27%29%5D%28https%3A%2F%2Felb-sonar-ee-mycompany-tooling-dev-1.aws.mycompany.com%2Fdashboard%3Fid%3Dcom.mycompany%253Ademo%26pullRequest%3D2%29+%5B%21%5BB%5D%28https%3A%2F%2Felb-sonar-ee-mycompany-tooling-dev-1.aws.mycompany.com%2Fstatic%2Fdeveloper-server%2Fchecks%2FRatingBadge%2FB.svg+%27B%27%29%5D%28https%3A%2F%2Felb-sonar-ee-mycompany-tooling-dev-1.aws.mycompany.com%2Fdashboard%3Fid%3Dcom.mycompany%253Ademo%26pullRequest%3D2%29+Maintainability+Rating+on+New+Code+%28is+worse+than+A%29++%0A%5B%21%5BFailed+condition%5D%28https%3A%2F%2Felb-sonar-ee-mycompany-tooling-dev-1.aws.mycompany.com%2Fstatic%2Fdeveloper-server%2Fchecks%2FFailedConditionIcon.svg+%27Failed+condition%27%29%5D%28https%3A%2F%2Felb-sonar-ee-mycompany-tooling-dev-1.aws.mycompany.com%2Fdashboard%3Fid%3Dcom.mycompany%253Ademo%26pullRequest%3D2%29+%5B%21%5B0.0%25%5D%28https%3A%2F%2Felb-sonar-ee-mycompany-tooling-dev-1.aws.mycompany.com%2Fstatic%2Fdeveloper-server%2Fchecks%2FCoverageChart%2F0.svg+%270.0%25%27%29%5D%28https%3A%2F%2Felb-sonar-ee-mycompany-tooling-dev-1.aws.mycompany.com%2Fdashboard%3Fid%3Dcom.mycompany%253Ademo%26pullRequest%3D2%29+0.0%25+Coverage+on+New+Code+%28is+less+than+80%25%29++%0A%0A%5BSee+analysis+details+on+SonarQube%5D%28https%3A%2F%2Felb-sonar-ee-mycompany-tooling-dev-1.aws.mycompany.com%2Fdashboard%3Fid%3Dcom.mycompany%253Ademo%26pullRequest%3D2%29%0A%0A%23%23+Additional+information%0A%0A*The+following+metrics+might+not+affect+the+Quality+Gate+status+but+improving*++%0A*them+will+improve+your+project+code+quality.*%0A%0A%23%23%23+3+Issues%0A%0A%5B%21%5BBug%5D%28https%3A%2F%2Felb-sonar-ee-mycompany-tooling-dev-1.aws.mycompany.com%2Fstatic%2Fdeveloper-server%2Fcommon%2Fbug.svg+%27Bug%27%29%5D%28https%3A%2F%2Felb-sonar-ee-mycompany-tooling-dev-1.aws.mycompany.com%2Fproject%2Fissues%3Fid%3Dcom.mycompany%253Ademo%26pullRequest%3D2%26resolved%3Dfalse%26types%3DBUG%29+%5B%21%5BA%5D%28https%3A%2F%2Felb-sonar-ee-mycompany-tooling-dev-1.aws.mycompany.com%2Fstatic%2Fdeveloper-server%2Fchecks%2FRatingBadge%2FA.svg+%27A%27%29%5D%28https%3A%2F%2Felb-sonar-ee-mycompany-tooling-dev-1.aws.mycompany.com%2Fproject%2Fissues%3Fid%3Dcom.mycompany%253Ademo%26pullRequest%3D2%26resolved%3Dfalse%26types%3DBUG%29+%5B0+Bugs%5D%28https%3A%2F%2Felb-sonar-ee-mycompany-tooling-dev-1.aws.mycompany.com%2Fproject%2Fissues%3Fid%3Dcom.mycompany%253Ademo%26pullRequest%3D2%26resolved%3Dfalse%26types%3DBUG%29++%0A%5B%21%5BVulnerability%5D%28https%3A%2F%2Felb-sonar-ee-mycompany-tooling-dev-1.aws.mycompany.com%2Fstatic%2Fdeveloper-server%2Fcommon%2Fvulnerability.svg+%27Vulnerability%27%29%5D%28https%3A%2F%2Felb-sonar-ee-mycompany-tooling-dev-1.aws.mycompany.com%2Fproject%2Fissues%3Fid%3Dcom.mycompany%253Ademo%26pullRequest%3D2%26resolved%3Dfalse%26types%3DVULNERABILITY%29+%5B%21%5BA%5D%28https%3A%2F%2Felb-sonar-ee-mycompany-tooling-dev-1.aws.mycompany.com%2Fstatic%2Fdeveloper-server%2Fchecks%2FRatingBadge%2FA.svg+%27A%27%29%5D%28https%3A%2F%2Felb-sonar-ee-mycompany-tooling-dev-1.aws.mycompany.com%2Fproject%2Fissues%3Fid%3Dcom.mycompany%253Ademo%26pullRequest%3D2%26resolved%3Dfalse%26types%3DVULNERABILITY%29+%5B0+Vulnerabilities%5D%28https%3A%2F%2Felb-sonar-ee-mycompany-tooling-dev-1.aws.mycompany.com%2Fproject%2Fissues%3Fid%3Dcom.mycompany%253Ademo%26pullRequest%3D2%26resolved%3Dfalse%26types%3DVULNERABILITY%29+%28and+%5B%21%5BSecurity+Hotspot%5D%28https%3A%2F%2Felb-sonar-ee-mycompany-tooling-dev-1.aws.mycompany.com%2Fstatic%2Fdeveloper-server%2Fcommon%2Fsecurity_hotspot.svg+%27Security+Hotspot%27%29%5D%28https%3A%2F%2Felb-sonar-ee-mycompany-tooling-dev-1.aws.mycompany.com%2Fsecurity_hotspots%3Fid%3Dcom.mycompany%253Ademo%26pullRequest%3D2%29+%5B1+Security+Hotspot%5D%28https%3A%2F%2Felb-sonar-ee-mycompany-tooling-dev-1.aws.mycompany.com%2Fsecurity_hotspots%3Fid%3Dcom.mycompany%253Ademo%26pullRequest%3D2%29+to+review%29++%0A%5B%21%5BCode+Smell%5D%28https%3A%2F%2Felb-sonar-ee-mycompany-tooling-dev-1.aws.mycompany.com%2Fstatic%2Fdeveloper-server%2Fcommon%2Fcode_smell.svg+%27Code+Smell%27%29%5D%28https%3A%2F%2Felb-sonar-ee-mycompany-tooling-dev-1.aws.mycompany.com%2Fproject%2Fissues%3Fid%3Dcom.mycompany%253Ademo%26pullRequest%3D2%26resolved%3Dfalse%26types%3DCODE_SMELL%29+%5B%21%5BB%5D%28https%3A%2F%2Felb-sonar-ee-mycompany-tooling-dev-1.aws.mycompany.com%2Fstatic%2Fdeveloper-server%2Fchecks%2FRatingBadge%2FB.svg+%27B%27%29%5D%28https%3A%2F%2Felb-sonar-ee-mycompany-tooling-dev-1.aws.mycompany.com%2Fproject%2Fissues%3Fid%3Dcom.mycompany%253Ademo%26pullRequest%3D2%26resolved%3Dfalse%26types%3DCODE_SMELL%29+%5B3+Code+Smells%5D%28https%3A%2F%2Felb-sonar-ee-mycompany-tooling-dev-1.aws.mycompany.com%2Fproject%2Fissues%3Fid%3Dcom.mycompany%253Ademo%26pullRequest%3D2%26resolved%3Dfalse%26types%3DCODE_SMELL%29%0A%0A%23%23%23+Coverage+and+Duplications%0A%0A%5B%21%5B0.0%25%5D%28https%3A%2F%2Felb-sonar-ee-mycompany-tooling-dev-1.aws.mycompany.com%2Fstatic%2Fdeveloper-server%2Fchecks%2FCoverageChart%2F0.svg+%270.0%25%27%29%5D%28https%3A%2F%2Felb-sonar-ee-mycompany-tooling-dev-1.aws.mycompany.com%2Fcomponent_measures%3Fid%3Dcom.mycompany%253Ademo%26pullRequest%3D2%26metric%3Dnew_coverage%26view%3Dlist%29+%5B0.0%25+Coverage%5D%28https%3A%2F%2Felb-sonar-ee-mycompany-tooling-dev-1.aws.mycompany.com%2Fcomponent_measures%3Fid%3Dcom.mycompany%253Ademo%26pullRequest%3D2%26metric%3Dnew_coverage%26view%3Dlist%29+%280.0%25+Estimated+after+merge%29++%0A%5B%21%5B0.0%25%5D%28https%3A%2F%2Felb-sonar-ee-mycompany-tooling-dev-1.aws.mycompany.com%2Fstatic%2Fdeveloper-server%2Fchecks%2FDuplications%2F3.svg+%270.0%25%27%29%5D%28https%3A%2F%2Felb-sonar-ee-mycompany-tooling-dev-1.aws.mycompany.com%2Fcomponent_measures%3Fid%3Dcom.mycompany%253Ademo%26pullRequest%3D2%26metric%3Dnew_duplicated_lines_density%26view%3Dlist%29+%5B0.0%25+Duplication%5D%28https%3A%2F%2Felb-sonar-ee-mycompany-tooling-dev-1.aws.mycompany.com%2Fcomponent_measures%3Fid%3Dcom.mycompany%253Ademo%26pullRequest%3D2%26metric%3Dnew_duplicated_lines_density%26view%3Dlist%29+%280.0%25+Estimated+after+merge%29%0A%0A]
2020.02.27 16:06:04 DEBUG ce[AXCHLtqIO2hDuTzVGory][o.i.http2.Http2] >> 0x00000009  4579 HEADERS       END_HEADERS
2020.02.27 16:06:04 DEBUG ce[AXCHLtqIO2hDuTzVGory][o.i.http2.Http2] >> 0x00000009     0 DATA          END_STREAM
2020.02.27 16:06:04 DEBUG ce[][o.i.http2.Http2] << 0x00000000     8 GOAWAY
2020.02.27 16:06:04 DEBUG ce[][o.i.http2.Http2] >> 0x00000009     4 RST_STREAM
2020.02.27 16:06:04 DEBUG ce[AXCHLtqIO2hDuTzVGory][o.i.http2.Http2] >> CONNECTION 505249202a20485454502f322e300d0a0d0a534d0d0a0d0a
2020.02.27 16:06:04 DEBUG ce[AXCHLtqIO2hDuTzVGory][o.i.http2.Http2] >> 0x00000000     6 SETTINGS
2020.02.27 16:06:04 DEBUG ce[AXCHLtqIO2hDuTzVGory][o.i.http2.Http2] >> 0x00000000     4 WINDOW_UPDATE
2020.02.27 16:06:04 DEBUG ce[AXCHLtqIO2hDuTzVGory][o.i.http2.Http2] >> 0x00000003  4637 HEADERS       END_HEADERS
2020.02.27 16:06:04 DEBUG ce[AXCHLtqIO2hDuTzVGory][o.i.http2.Http2] >> 0x00000003     0 DATA          END_STREAM
2020.02.27 16:06:04 DEBUG ce[][o.i.http2.Http2] << 0x00000000    18 SETTINGS
2020.02.27 16:06:04 DEBUG ce[][o.i.http2.Http2] << 0x00000000     4 WINDOW_UPDATE
2020.02.27 16:06:04 DEBUG ce[][o.i.http2.Http2] << 0x00000000     0 SETTINGS      ACK
2020.02.27 16:06:04 DEBUG ce[][o.i.http2.Http2] << 0x00000000     8 GOAWAY
2020.02.27 16:06:04 DEBUG ce[][o.i.http2.Http2] >> 0x00000003     4 RST_STREAM
2020.02.27 16:06:04 DEBUG ce[AXCHLtqIO2hDuTzVGory][o.i.http2.Http2] >> CONNECTION 505249202a20485454502f322e300d0a0d0a534d0d0a0d0a
2020.02.27 16:06:04 DEBUG ce[AXCHLtqIO2hDuTzVGory][o.i.http2.Http2] >> 0x00000000     6 SETTINGS
2020.02.27 16:06:04 DEBUG ce[AXCHLtqIO2hDuTzVGory][o.i.http2.Http2] >> 0x00000000     4 WINDOW_UPDATE
2020.02.27 16:06:04 DEBUG ce[AXCHLtqIO2hDuTzVGory][o.i.http2.Http2] >> 0x00000003  4637 HEADERS       END_HEADERS
2020.02.27 16:06:04 DEBUG ce[AXCHLtqIO2hDuTzVGory][o.i.http2.Http2] >> 0x00000003     0 DATA          END_STREAM
2020.02.27 16:06:04 DEBUG ce[][o.i.http2.Http2] << 0x00000000    18 SETTINGS
2020.02.27 16:06:04 DEBUG ce[][o.i.http2.Http2] << 0x00000000     4 WINDOW_UPDATE
2020.02.27 16:06:04 DEBUG ce[][o.i.http2.Http2] << 0x00000000     0 SETTINGS      ACK
2020.02.27 16:06:04 DEBUG ce[][o.i.http2.Http2] << 0x00000000     8 GOAWAY
2020.02.27 16:06:04 DEBUG ce[][o.i.http2.Http2] >> 0x00000003     4 RST_STREAM

pierreguillot · February 28, 2020, 1:06pm

Thanks for the log. i’ll try to reproduce with that payload.

NicolasH · March 12, 2020, 1:25pm

Seems to be working for us thus far. Thanks a lot

Clement_Stoquart · March 16, 2020, 10:32am

Hello,
Have you been able to reproduce this issue ?

pierreguillot · March 19, 2020, 9:57am

we where not able to reproduce this issue. It seems dependant of the SSL certificat used, along other factor. We recently had issues with SSL certificates generated few years ago in JKS format, not working well with jdk 11.0.6. We had to regenerate them in pkcs12. What is the exact version of java you are using to run SonarQube ?

Clement_Stoquart · March 19, 2020, 1:03pm

Hi,
We are using jdk 11.0.6. This is the full java -version output:
openjdk version “11.0.6” 2020-01-14
OpenJDK Runtime Environment AdoptOpenJDK (build 11.0.6+10)
OpenJDK 64-Bit Server VM AdoptOpenJDK (build 11.0.6+10, mixed mode)

pierreguillot · March 19, 2020, 1:20pm

Ok so you could give a try to a jdk 11.0.3, before the last security baseline was adopted. And try with a new certificate (in pkcs12 format), or with another certificate provider. There is no issue reported with letsencrypt certificate, for example, as far as i know.