New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Noisy startup when elasticsearch is unavailable #3861

Closed
kroepke opened this Issue May 22, 2017 · 2 comments

Comments

Projects
None yet
3 participants
@kroepke
Member

kroepke commented May 22, 2017

With the new HTTP client the server startup is logging very noisily when elasticsearch isn't reachable:


2017-05-22 15:15:14,349 ERROR: org.graylog2.periodical.BatchedElasticSearchOutputFlushThread - Caught exception while trying to flush output: {}
org.graylog2.indexer.ElasticsearchException: Couldn't check connection status of Elasticsearch
	at org.graylog2.indexer.cluster.jest.JestUtils.execute(JestUtils.java:59) ~[classes/:?]
	at org.graylog2.indexer.cluster.jest.JestUtils.execute(JestUtils.java:70) ~[classes/:?]
	at org.graylog2.indexer.cluster.Cluster.isConnected(Cluster.java:165) ~[classes/:?]
	at org.graylog2.outputs.BlockingBatchedESOutput.forceFlushIfTimedout(BlockingBatchedESOutput.java:148) ~[classes/:?]
	at org.graylog2.periodical.BatchedElasticSearchOutputFlushThread.doRun(BatchedElasticSearchOutputFlushThread.java:82) [classes/:?]
	at org.graylog2.plugin.periodical.Periodical.run(Periodical.java:77) [classes/:?]
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:1.8.0_121]
	at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308) [?:1.8.0_121]
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180) [?:1.8.0_121]
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294) [?:1.8.0_121]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [?:1.8.0_121]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [?:1.8.0_121]
	at java.lang.Thread.run(Thread.java:745) [?:1.8.0_121]
Caused by: io.searchbox.client.config.exception.CouldNotConnectException: Could not connect to http://127.0.0.1:9200
	at io.searchbox.client.http.JestHttpClient.execute(JestHttpClient.java:70) ~[jest-2.4.5.jar:?]
	at org.graylog2.indexer.cluster.jest.JestUtils.execute(JestUtils.java:54) ~[classes/:?]
	... 12 more
Caused by: org.apache.http.conn.HttpHostConnectException: Connect to 127.0.0.1:9200 [/127.0.0.1] failed: Connection refused (Connection refused)
	at org.apache.http.impl.conn.DefaultHttpClientConnectionOperator.connect(DefaultHttpClientConnectionOperator.java:159) ~[httpclient-4.5.3.jar:4.5.3]
	at org.apache.http.impl.conn.PoolingHttpClientConnectionManager.connect(PoolingHttpClientConnectionManager.java:359) ~[httpclient-4.5.3.jar:4.5.3]
	at org.apache.http.impl.execchain.MainClientExec.establishRoute(MainClientExec.java:381) ~[httpclient-4.5.3.jar:4.5.3]
	at org.apache.http.impl.execchain.MainClientExec.execute(MainClientExec.java:237) ~[httpclient-4.5.3.jar:4.5.3]
	at org.apache.http.impl.execchain.ProtocolExec.execute(ProtocolExec.java:185) ~[httpclient-4.5.3.jar:4.5.3]
	at org.apache.http.impl.execchain.RetryExec.execute(RetryExec.java:89) ~[httpclient-4.5.3.jar:4.5.3]
	at org.apache.http.impl.execchain.RedirectExec.execute(RedirectExec.java:111) ~[httpclient-4.5.3.jar:4.5.3]
	at org.apache.http.impl.client.InternalHttpClient.doExecute(InternalHttpClient.java:185) ~[httpclient-4.5.3.jar:4.5.3]
	at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:83) ~[httpclient-4.5.3.jar:4.5.3]
	at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:108) ~[httpclient-4.5.3.jar:4.5.3]
	at io.searchbox.client.http.JestHttpClient.executeRequest(JestHttpClient.java:132) ~[jest-2.4.5.jar:?]
	at io.searchbox.client.http.JestHttpClient.execute(JestHttpClient.java:67) ~[jest-2.4.5.jar:?]
	at org.graylog2.indexer.cluster.jest.JestUtils.execute(JestUtils.java:54) ~[classes/:?]
	... 12 more
Caused by: java.net.ConnectException: Connection refused (Connection refused)
	at java.net.PlainSocketImpl.socketConnect(Native Method) ~[?:1.8.0_121]
	at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:350) ~[?:1.8.0_121]
	at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:206) ~[?:1.8.0_121]
	at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:188) ~[?:1.8.0_121]
	at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:392) ~[?:1.8.0_121]
	at java.net.Socket.connect(Socket.java:589) ~[?:1.8.0_121]
	at org.apache.http.conn.socket.PlainConnectionSocketFactory.connectSocket(PlainConnectionSocketFactory.java:75) ~[httpclient-4.5.3.jar:4.5.3]
	at org.apache.http.impl.conn.DefaultHttpClientConnectionOperator.connect(DefaultHttpClientConnectionOperator.java:142) ~[httpclient-4.5.3.jar:4.5.3]
	at org.apache.http.impl.conn.PoolingHttpClientConnectionManager.connect(PoolingHttpClientConnectionManager.java:359) ~[httpclient-4.5.3.jar:4.5.3]
	at org.apache.http.impl.execchain.MainClientExec.establishRoute(MainClientExec.java:381) ~[httpclient-4.5.3.jar:4.5.3]
	at org.apache.http.impl.execchain.MainClientExec.execute(MainClientExec.java:237) ~[httpclient-4.5.3.jar:4.5.3]
	at org.apache.http.impl.execchain.ProtocolExec.execute(ProtocolExec.java:185) ~[httpclient-4.5.3.jar:4.5.3]
	at org.apache.http.impl.execchain.RetryExec.execute(RetryExec.java:89) ~[httpclient-4.5.3.jar:4.5.3]
	at org.apache.http.impl.execchain.RedirectExec.execute(RedirectExec.java:111) ~[httpclient-4.5.3.jar:4.5.3]
	at org.apache.http.impl.client.InternalHttpClient.doExecute(InternalHttpClient.java:185) ~[httpclient-4.5.3.jar:4.5.3]
	at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:83) ~[httpclient-4.5.3.jar:4.5.3]
	at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:108) ~[httpclient-4.5.3.jar:4.5.3]
	at io.searchbox.client.http.JestHttpClient.executeRequest(JestHttpClient.java:132) ~[jest-2.4.5.jar:?]
	at io.searchbox.client.http.JestHttpClient.execute(JestHttpClient.java:67) ~[jest-2.4.5.jar:?]
	at org.graylog2.indexer.cluster.jest.JestUtils.execute(JestUtils.java:54) ~[classes/:?]
	... 12 more

For this type of error it should be enough to log single lines. Previous version have also eventually failed the graylog server start, but I'm not sure if we still want that behavior.

@kroepke kroepke added the bug label May 22, 2017

@kroepke kroepke added this to the 2.3.0 milestone May 22, 2017

@kroepke kroepke changed the title from Nosiy startup when elasticsearch is unavailable to Noisy startup when elasticsearch is unavailable May 22, 2017

@joschi

This comment has been minimized.

Contributor

joschi commented May 22, 2017

@kroepke

Previous version have also eventually failed the graylog server start

We've changed that around Graylog 1.0.0 if I remember correctly (shortly after introducing the Kafka-based disk journal).

@bernd

This comment has been minimized.

Member

bernd commented May 30, 2017

The problem here is that this will quickly fill up the server log because I am getting this long stack trace every output_flush_interval seconds.

@bernd bernd added the triaged label Jun 19, 2017

@bernd bernd self-assigned this Jun 21, 2017

bernd added a commit that referenced this issue Jun 23, 2017

Avoid noisy stack traces when Elasticsearch is not available
Only log stack traces if debug logging is enabled.

Closes #3861

@bernd bernd added the in progress label Jun 23, 2017

@joschi joschi closed this in #3934 Jun 27, 2017

@wafflebot wafflebot bot removed the in progress label Jun 27, 2017

joschi added a commit that referenced this issue Jun 27, 2017

Avoid noisy stack traces when Elasticsearch is not available (#3934)
Only log stack traces if debug logging is enabled.

Closes #3861
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment