Webhook to Jenkins times out from Sonarqube, err : shard is now inactive

SonarQube
1

Stack details

SonarQube version : 8.4.1.35646
Backend DB : AWS postgresql
Sonarqube running on : AWS ECS as a container.
Build server : Jenkins and using pipeline stage as withSonarQubeEnv

Issue : Webhook Times Out

We have the Sonarqube installed and now a days we are seeing issues with the webhook to jenkins being timed out.

# log timings
2020.10.30 15:50:20 DEBUG ce[AXV6M7FEBAFQMUUkmnwr][o.s.s.w.WebHooksImpl] Sent webhook 'Jenkins' | url=https://jenkins.xx.xx.no/jenkins/sonarqube-webhook/ | time=94ms | status=200
2020.10.30 15:56:31 DEBUG ce[AXV6OVG8BAFQMUUkmnwt][o.s.s.w.WebHooksImpl] Failed to send webhook 'Jenkins' | url=https://jenkins.xxxxx.xxxxx.no/jenkins/sonarqube-webhook/ | message=connect timed out

All the scan’s were working till 2020.10.30 15:50:20, once it got failed the scans starting from 2020.10.30 15:56:31 failed to sent the report back to Jenkins (though the sonarqube scan worked perfectly), and the jenkins pipeline eventually timed out and build got failed.

The issue got fixed after we restarted the container and the scan report sent back correctly to jenkins thereafter.

the main log which we think the cause of the issue is given below, (apart from there were some logs in the ldap and user authentications).
If anybody has any idea/solution about this, it would be really helpful, Since restarting the container is not an actual solution…

# Suspicious logs
2020.10.30 15:55:20 DEBUG ce[][o.i.http2.Http2] >> 0x00000000     8 GOAWAY        
2020.10.30 15:55:22 DEBUG es[][o.e.i.s.IndexShard] shard is now inactive
2020.10.30 15:55:22 DEBUG es[][o.e.i.s.IndexShard] shard is now inactive
2020.10.30 15:55:22 DEBUG es[][o.e.i.s.IndexShard] shard is now inactive
2020.10.30 15:55:22 DEBUG es[][o.e.i.e.Engine] Delete index commit [CommitPoint{segment[segments_4z], userData[{local_checkpoint=246500, max_unsafe_auto_id_timestamp=-1, translog_uuid=K9tnYUdiTty13K5vfaRoWQ, history_uuid=Af_RXwrcQIy_b9PpjpgJug, translog_generation=92, sync_id=hnnLVDirTp6xNgNQPsWlgQ, max_seq_no=246500}]}]
2020.10.30 15:55:22 DEBUG es[][o.e.i.e.Engine] Safe commit [CommitPoint{segment[segments_50], userData[{local_checkpoint=250507, max_unsafe_auto_id_timestamp=-1, translog_uuid=K9tnYUdiTty13K5vfaRoWQ, history_uuid=Af_RXwrcQIy_b9PpjpgJug, translog_generation=93, max_seq_no=250507}]}], last commit [CommitPoint{segment[segments_50], userData[{local_checkpoint=250507, max_unsafe_auto_id_timestamp=-1, translog_uuid=K9tnYUdiTty13K5vfaRoWQ, history_uuid=Af_RXwrcQIy_b9PpjpgJug, translog_generation=93, max_seq_no=250507}]}]
2020.10.30 15:55:22 DEBUG es[][o.e.i.f.p.SortedSetDVOrdinalsIndexFieldData] global-ordinals [join_issues#auth][299] took [181.2micros]
2020.10.30 15:55:22 DEBUG es[][o.e.i.e.Engine] Delete index commit [CommitPoint{segment[segments_33], userData[{local_checkpoint=472, max_unsafe_auto_id_timestamp=-1, translog_uuid=rtpF6o-qSkeGIcjO1YdXlg, history_uuid=yL-QFK0ZTnK1LOVNEWzmbw, translog_generation=57, sync_id=ElVQUQfFSEyRLjzGfG2Ilg, max_seq_no=472}]}]
2020.10.30 15:55:22 DEBUG es[][o.e.i.e.Engine] Safe commit [CommitPoint{segment[segments_34], userData[{local_checkpoint=473, max_unsafe_auto_id_timestamp=-1, translog_uuid=rtpF6o-qSkeGIcjO1YdXlg, history_uuid=yL-QFK0ZTnK1LOVNEWzmbw, translog_generation=58, max_seq_no=473}]}], last commit [CommitPoint{segment[segments_34], userData[{local_checkpoint=473, max_unsafe_auto_id_timestamp=-1, translog_uuid=rtpF6o-qSkeGIcjO1YdXlg, history_uuid=yL-QFK0ZTnK1LOVNEWzmbw, translog_generation=58, max_seq_no=473}]}]
2020.10.30 15:55:22 DEBUG es[][o.e.i.f.p.SortedSetDVOrdinalsIndexFieldData] global-ordinals [join_projectmeasures#auth][299] took [186.4micros]
2020.10.30 15:55:22 DEBUG es[][o.e.i.e.Engine] Delete index commit [CommitPoint{segment[segments_33], userData[{local_checkpoint=2472, max_unsafe_auto_id_timestamp=-1, translog_uuid=0WMzbQiBQHCL5UnXM8Bd1w, history_uuid=YOkKKtZzREWft61kBGiCOg, translog_generation=57, sync_id=G4lGY8KlSdaBJjm6V_zMEA, max_seq_no=2472}]}]
2020.10.30 15:55:22 DEBUG es[][o.e.i.e.Engine] Safe commit [CommitPoint{segment[segments_34], userData[{local_checkpoint=2473, max_unsafe_auto_id_timestamp=-1, translog_uuid=0WMzbQiBQHCL5UnXM8Bd1w, history_uuid=YOkKKtZzREWft61kBGiCOg, translog_generation=58, max_seq_no=2473}]}], last commit [CommitPoint{segment[segments_34], userData[{local_checkpoint=2473, max_unsafe_auto_id_timestamp=-1, translog_uuid=0WMzbQiBQHCL5UnXM8Bd1w, history_uuid=YOkKKtZzREWft61kBGiCOg, translog_generation=58, max_seq_no=2473}]}]
2020.10.30 15:55:22 DEBUG es[][o.e.i.f.p.SortedSetDVOrdinalsIndexFieldData] global-ordinals [join_components#auth][299] took [203.9micros]
2020.10.30 15:55:22 DEBUG es[][o.e.i.e.Engine] Delete index commit [CommitPoint{segment[segments_50], userData[{local_checkpoint=250507, max_unsafe_auto_id_timestamp=-1, translog_uuid=K9tnYUdiTty13K5vfaRoWQ, history_uuid=Af_RXwrcQIy_b9PpjpgJug, translog_generation=93, max_seq_no=250507}]}]
2020.10.30 15:55:22 DEBUG es[][o.e.i.e.Engine] Safe commit [CommitPoint{segment[segments_51], userData[{local_checkpoint=250507, max_unsafe_auto_id_timestamp=-1, translog_uuid=K9tnYUdiTty13K5vfaRoWQ, history_uuid=Af_RXwrcQIy_b9PpjpgJug, translog_generation=93, sync_id=NxaOr_psRGiWXAa-MUENLg, max_seq_no=250507}]}], last commit [CommitPoint{segment[segments_51], userData[{local_checkpoint=250507, max_unsafe_auto_id_timestamp=-1, translog_uuid=K9tnYUdiTty13K5vfaRoWQ, history_uuid=Af_RXwrcQIy_b9PpjpgJug, translog_generation=93, sync_id=NxaOr_psRGiWXAa-MUENLg, max_seq_no=250507}]}]
2020.10.30 15:55:22 DEBUG es[][o.e.i.e.Engine] successfully sync committed. sync id [NxaOr_psRGiWXAa-MUENLg].
2020.10.30 15:55:22 DEBUG es[][o.e.i.e.Engine] Delete index commit [CommitPoint{segment[segments_34], userData[{local_checkpoint=473, max_unsafe_auto_id_timestamp=-1, translog_uuid=rtpF6o-qSkeGIcjO1YdXlg, history_uuid=yL-QFK0ZTnK1LOVNEWzmbw, translog_generation=58, max_seq_no=473}]}]
2020.10.30 15:55:22 DEBUG es[][o.e.i.e.Engine] Safe commit [CommitPoint{segment[segments_35], userData[{local_checkpoint=473, max_unsafe_auto_id_timestamp=-1, translog_uuid=rtpF6o-qSkeGIcjO1YdXlg, history_uuid=yL-QFK0ZTnK1LOVNEWzmbw, translog_generation=58, sync_id=micgtjHASwGP-1EctmWZjA, max_seq_no=473}]}], last commit [CommitPoint{segment[segments_35], userData[{local_checkpoint=473, max_unsafe_auto_id_timestamp=-1, translog_uuid=rtpF6o-qSkeGIcjO1YdXlg, history_uuid=yL-QFK0ZTnK1LOVNEWzmbw, translog_generation=58, sync_id=micgtjHASwGP-1EctmWZjA, max_seq_no=473}]}]
2020.10.30 15:55:22 DEBUG es[][o.e.i.e.Engine] successfully sync committed. sync id [micgtjHASwGP-1EctmWZjA].
2020.10.30 15:55:22 DEBUG es[][o.e.i.e.Engine] Delete index commit [CommitPoint{segment[segments_34], userData[{local_checkpoint=2473, max_unsafe_auto_id_timestamp=-1, translog_uuid=0WMzbQiBQHCL5UnXM8Bd1w, history_uuid=YOkKKtZzREWft61kBGiCOg, translog_generation=58, max_seq_no=2473}]}]
2020.10.30 15:55:22 DEBUG es[][o.e.i.e.Engine] Safe commit [CommitPoint{segment[segments_35], userData[{local_checkpoint=2473, max_unsafe_auto_id_timestamp=-1, translog_uuid=0WMzbQiBQHCL5UnXM8Bd1w, history_uuid=YOkKKtZzREWft61kBGiCOg, translog_generation=58, sync_id=AxkHpvc7S82pZxsgLDN4SQ, max_seq_no=2473}]}], last commit [CommitPoint{segment[segments_35], userData[{local_checkpoint=2473, max_unsafe_auto_id_timestamp=-1, translog_uuid=0WMzbQiBQHCL5UnXM8Bd1w, history_uuid=YOkKKtZzREWft61kBGiCOg, translog_generation=58, sync_id=AxkHpvc7S82pZxsgLDN4SQ, max_seq_no=2473}]}]
2020.10.30 15:55:22 DEBUG es[][o.e.i.e.Engine] successfully sync committed. sync id [AxkHpvc7S82pZxsgLDN4SQ].
2

Hello,

The webhook is sent from the Compute Engine process. The suspicious logs you posted are from a different process, elastic search, so it’s unlikely they are related.

Did you check the file ce.log to see if there are any more details? In any case connect time out since to be a networking issue.

3

These addresses resolve correctly and these endpoints are reachable from inside the sonarqube container.

4

Hi Bazzi,
Did you ever solved this issue please? We are facing the same issue for a bitbucket webhook. Same as you, it stopped working one day, only a timeout error in the log and the only way to solve it (for a couple of days) is to restart Sonarqube.
Thanks

5

Our webhook from SonarQube (7.9.2) to Jenkins started failing last June. We’ve never been able to get it working again. However, we made it so that it didn’t matter anymore. We now use the Build Breaker plugin, so if our quality gate rules are violated, the build still fails. That is all we would have needed to get from the webhook result anyway.

6

@larkoie you might be affected by this bug: https://jira.sonarsource.com/browse/SONAR-14870

7

@larkoie We are still having this issue every now and then… Only error we are seeing from the logs is, host unreachable

2021.06.09 12:00:59 DEBUG ce[AXnwpaxxxxxxZGlxs][o.s.s.w.WebHooksImpl] Sent webhook 'Jenkins' | url=https://jenkins.xxx.xxx.xx/jenkins/sonarqube-webhook/ | time=5ms | status=200
2021.06.09 12:01:12 DEBUG ce[AXnwpaxxxxxxZGlxs][o.s.s.w.WebHooksImpl] Failed to send webhook 'ch.mibex.bitbucket.sonar' | url=https://bitbucket.xxxx.xxxx.xxx/rest/sonar4stash/1.0/webhook/secret | message=No route to host (Host unreachable)

Restarting sonar is the only way in this case !!

@dmeneses Do you have some documentation on how to specifically mention the TTL value for CE engine as updated here ?

We should explicitly set the DNS cache TTL to 30s for the Compute Engine process

8

Check the last section here.

You can set a TTL for Java with:

echo "networkaddress.cache.ttl=5" >> "${JAVA_HOME}/conf/security/java.security"
1 Like
9

@dmeneses this change worked well…
We have been running with this change for a month now & not received any issues like that.
Thanks a lot for pointing us to the right direction.

1 Like
10

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