SQ randomly started failing. Error message isn't helpful

Douglas_Jones · June 24, 2024, 7:01pm

Must-share information (formatted with Markdown):

which versions are you using (SonarQube, Scanner, Plugin, and any relevant extension)
how is SonarQube deployed: zip, Docker, Helm
what are you trying to achieve
what have you tried so far to achieve this

Do not share screenshots of logs – share the text itself (bonus points for being well-formatted)!

Version sonarqube-enterprise-10.3.0.82913
Deployment: Zip
What I need: SQ randomly started failing on startup
I’ve tried the following

1. turning it off and on again
1. turning the server off and on again
1. changing the ElastiSearch port
1. setting the ES port to 0 (which finds any available port)
1. the following error just repeats over and over

2024.06.24 07:12:47 DEBUG app[][o.a.h.i.n.c.MainClientExec] [exchange: 225] start execution
2024.06.24 07:12:47 DEBUG app[][o.a.h.c.p.RequestAddCookies] CookieSpec selected: default
2024.06.24 07:12:47 DEBUG app[][o.a.h.c.p.RequestAuthCache] Re-using cached 'basic' auth scheme for http://127.0.0.1:9001
2024.06.24 07:12:47 DEBUG app[][o.a.h.c.p.RequestAuthCache] No credentials for preemptive authentication
2024.06.24 07:12:47 DEBUG app[][o.a.h.i.n.c.InternalHttpAsyncClient] [exchange: 225] Request connection for {}->http://127.0.0.1:9001
2024.06.24 07:12:47 DEBUG app[][o.a.h.i.n.c.PoolingNHttpClientConnectionManager] Connection request: [route: {}->http://127.0.0.1:9001][total kept alive: 0; route allocated: 0 of 10; total allocated: 0 of 30]
2024.06.24 07:12:47 DEBUG app[][o.a.h.i.n.c.PoolingNHttpClientConnectionManager] Connection request failed
java.net.ConnectException: Connection refused: no further information
        at java.base/sun.nio.ch.Net.pollConnect(Native Method)
        at java.base/sun.nio.ch.Net.pollConnectNow(Net.java:672)
        at java.base/sun.nio.ch.SocketChannelImpl.finishConnect(SocketChannelImpl.java:946)
        at org.apache.http.impl.nio.reactor.DefaultConnectingIOReactor.processEvent(DefaultConnectingIOReactor.java:174)
        at org.apache.http.impl.nio.reactor.DefaultConnectingIOReactor.processEvents(DefaultConnectingIOReactor.java:148)
        at org.apache.http.impl.nio.reactor.AbstractMultiworkerIOReactor.execute(AbstractMultiworkerIOReactor.java:351)
        at org.apache.http.impl.nio.conn.PoolingNHttpClientConnectionManager.execute(PoolingNHttpClientConnectionManager.java:221)
        at org.apache.http.impl.nio.client.CloseableHttpAsyncClientBase$1.run(CloseableHttpAsyncClientBase.java:64)
        at java.base/java.lang.Thread.run(Thread.java:842)
2024.06.24 07:12:47 DEBUG app[][o.a.h.i.n.c.InternalHttpAsyncClient] [exchange: 225] connection request failed
2024.06.24 07:12:47 DEBUG app[][o.e.c.RestClient] request [GET http://127.0.0.1:9001/] failed
java.net.ConnectException: Connection refused: no further information
        at java.base/sun.nio.ch.Net.pollConnect(Native Method)
        at java.base/sun.nio.ch.Net.pollConnectNow(Net.java:672)
        at java.base/sun.nio.ch.SocketChannelImpl.finishConnect(SocketChannelImpl.java:946)
        at org.apache.http.impl.nio.reactor.DefaultConnectingIOReactor.processEvent(DefaultConnectingIOReactor.java:174)
        at org.apache.http.impl.nio.reactor.DefaultConnectingIOReactor.processEvents(DefaultConnectingIOReactor.java:148)
        at org.apache.http.impl.nio.reactor.AbstractMultiworkerIOReactor.execute(AbstractMultiworkerIOReactor.java:351)
        at org.apache.http.impl.nio.conn.PoolingNHttpClientConnectionManager.execute(PoolingNHttpClientConnectionManager.java:221)
        at org.apache.http.impl.nio.client.CloseableHttpAsyncClientBase$1.run(CloseableHttpAsyncClientBase.java:64)
        at java.base/java.lang.Thread.run(Thread.java:842)
2024.06.24 07:12:47 DEBUG app[][o.e.c.RestClient] updated [[host=http://127.0.0.1:9001]] already in blacklist
2024.06.24 07:12:47 DEBUG app[][o.a.h.i.n.c.MainClientExec] [exchange: 226] start execution
2024.06.24 07:12:47 DEBUG app[][o.a.h.c.p.RequestAddCookies] CookieSpec selected: default
2024.06.24 07:12:47 DEBUG app[][o.a.h.c.p.RequestAuthCache] Re-using cached 'basic' auth scheme for http://127.0.0.1:9001
2024.06.24 07:12:47 DEBUG app[][o.a.h.c.p.RequestAuthCache] No credentials for preemptive authentication
2024.06.24 07:12:47 DEBUG app[][o.a.h.i.n.c.InternalHttpAsyncClient] [exchange: 226] Request connection for {}->http://127.0.0.1:9001
2024.06.24 07:12:47 DEBUG app[][o.a.h.i.n.c.PoolingNHttpClientConnectionManager] Connection request: [route: {}->http://127.0.0.1:9001][total kept alive: 0; route allocated: 0 of 10; total allocated: 0 of 30]
2024.06.24 07:12:47 DEBUG app[][o.a.h.i.n.c.PoolingNHttpClientConnectionManager] Connection request failed
java.net.ConnectException: Connection refused: no further information
        at java.base/sun.nio.ch.Net.pollConnect(Native Method)
        at java.base/sun.nio.ch.Net.pollConnectNow(Net.java:672)
        at java.base/sun.nio.ch.SocketChannelImpl.finishConnect(SocketChannelImpl.java:946)
        at org.apache.http.impl.nio.reactor.DefaultConnectingIOReactor.processEvent(DefaultConnectingIOReactor.java:174)
        at org.apache.http.impl.nio.reactor.DefaultConnectingIOReactor.processEvents(DefaultConnectingIOReactor.java:148)
        at org.apache.http.impl.nio.reactor.AbstractMultiworkerIOReactor.execute(AbstractMultiworkerIOReactor.java:351)
        at org.apache.http.impl.nio.conn.PoolingNHttpClientConnectionManager.execute(PoolingNHttpClientConnectionManager.java:221)
        at org.apache.http.impl.nio.client.CloseableHttpAsyncClientBase$1.run(CloseableHttpAsyncClientBase.java:64)
        at java.base/java.lang.Thread.run(Thread.java:842)
2024.06.24 07:12:47 DEBUG app[][o.a.h.i.n.c.InternalHttpAsyncClient] [exchange: 226] connection request failed
2024.06.24 07:12:47 DEBUG app[][o.e.c.RestClient] request [GET http://127.0.0.1:9001/] failed
java.net.ConnectException: Connection refused: no further information
        at java.base/sun.nio.ch.Net.pollConnect(Native Method)
        at java.base/sun.nio.ch.Net.pollConnectNow(Net.java:672)
        at java.base/sun.nio.ch.SocketChannelImpl.finishConnect(SocketChannelImpl.java:946)
        at org.apache.http.impl.nio.reactor.DefaultConnectingIOReactor.processEvent(DefaultConnectingIOReactor.java:174)
        at org.apache.http.impl.nio.reactor.DefaultConnectingIOReactor.processEvents(DefaultConnectingIOReactor.java:148)
        at org.apache.http.impl.nio.reactor.AbstractMultiworkerIOReactor.execute(AbstractMultiworkerIOReactor.java:351)
        at org.apache.http.impl.nio.conn.PoolingNHttpClientConnectionManager.execute(PoolingNHttpClientConnectionManager.java:221)
        at org.apache.http.impl.nio.client.CloseableHttpAsyncClientBase$1.run(CloseableHttpAsyncClientBase.java:64)
        at java.base/java.lang.Thread.run(Thread.java:842)
2024.06.24 07:12:47 DEBUG app[][o.e.c.RestClient] updated [[host=http://127.0.0.1:9001]] already in blacklist

ganncamp · June 25, 2024, 11:50am

Hi,

Is there anything interesting in your other server logs?

I suspect something’s interfering with ES’s ability to grab port 9001. Next time this happens, you should probably check to see what process is holding that port.

HTH,
Ann

Douglas_Jones · June 25, 2024, 2:13pm

thank you for the reply. nothing is using port 9001.
In addition to trying other ports I also set the app to find any open port.

Still no dice.

ganncamp · June 25, 2024, 2:37pm

Hi,

Ehm… I’m skeptical that will work well. It’s not just Elasticsearch that needs to be on that port, but the SonarQube thread that needs to find it there.

Then perhaps you have a server policy that disallows its use. Or perhaps something between the two processes blocking the communication.

You need to figure out why Elasticsearch isn’t responding on port 9001. And unfortunately, since there’s nothing in your logs, the problem appears to exist entirely outside of SonarQube.

Ann

arturo.palau · June 25, 2024, 4:05pm

@Douglas_Jones, have you checked the <Sonarqube_dir>/logs/es.log logs? If ES is failing to start, a more detailed error should be displayed there.

If it is not there, you might want to check the other log files to see if there is more information on the error.

Topic		Replies	Views
##[error][SQ] API GET '/api/server/version' failed, error is request to http://xx.xx.xx.xx:9000/a SonarQube Server / Community Build	1	37	November 12, 2024
SQ Server - Failed to get server version SonarQube Server / Community Build	18	29	March 19, 2025
Error at SQ startup SonarQube Server / Community Build	2	763	September 26, 2019
Failed to request and parse <link> The underlying connection was closed: An unexpected error occurred on a send SonarQube Server / Community Build sonarqube	3	1002	October 29, 2020
Down due to ElasticSearch error SonarQube Server / Community Build	5	3995	July 1, 2022

SQ randomly started failing. Error message isn't helpful

Related topics