Skip to content
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.

Sign up for GitHub

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

Jump to bottom

Discovery takes more than 3 minutes #279

Closed
nextofsearch opened this issue Nov 13, 2016 · 2 comments
Closed

Discovery takes more than 3 minutes #279

nextofsearch opened this issue Nov 13, 2016 · 2 comments
Assignees
@dadoonet

Comments

@nextofsearch
Copy link

nextofsearch commented Nov 13, 2016 •
edited
Loading

Hi,

ES 1.1 and plugin 2.11
Discovery takes more than 3 mins. Please refer to the following log:

[2016-11-13 22:53:10,214][INFO ][node ] [ES#5] starting ...
[2016-11-13 22:53:10,441][INFO ][org.eclipse.jetty.server.Server] jetty-8.1.0.v20120127
[2016-11-13 22:53:10,518][INFO ][org.eclipse.jetty.server.AbstractConnector] Started SelectChannelConnector@0.0.0.0:9091
[2016-11-13 22:53:10,519][INFO ][transport.couchbase ] [ES#5] bound_address {inet[0.0.0.0/0.0.0.0:9091]}, publish_address {inet[/10.0.1.229:9091]}
[2016-11-13 22:53:10,575][INFO ][transport ] [ES#5] bound_address {inet[/0:0:0:0:0:0:0:0:9300]}, publish_address {inet[/10.0.1.229:9300]}
[2016-11-13 22:53:10,579][TRACE][discovery ] [ES#5] waiting for 30s for the initial state to be set by the discovery
[2016-11-13 22:53:13,173][TRACE][discovery.ec2 ] [ES#5] building dynamic unicast discovery nodes...
[2016-11-13 22:53:13,178][TRACE][discovery.ec2 ] [ES#5] adding i-c93d4c5a, address 10.0.2.94, transport_address inet[/10.0.2.94:9300]
[2016-11-13 22:53:13,179][TRACE][discovery.ec2 ] [ES#5] adding i-7bab99e2, address 10.0.1.229, transport_address inet[/10.0.1.229:9300]
[2016-11-13 22:53:13,180][TRACE][discovery.ec2 ] [ES#5] adding i-7eca5970, address 10.0.0.54, transport_address inet[/10.0.0.54:9300]
[2016-11-13 22:53:13,181][DEBUG][discovery.ec2 ] [ES#5] using dynamic discovery nodes [[#cloud-i-c93d4c5a-0][ip-10-0-1-229][inet[/10.0.2.94:9300]], [#cloud-i-7bab99e2-0][ip-10-0-1-229][inet[/10.0.1.229:9300]], [#cloud-i-7eca5970-0][ip-10-0-1-229][inet[/10.0.0.54:9300]]]
[2016-11-13 22:53:13,182][TRACE][discovery.zen.ping.unicast] [ES#5] [1] connecting (light) to [#cloud-i-c93d4c5a-0][ip-10-0-1-229][inet[/10.0.2.94:9300]]
[2016-11-13 22:53:13,193][TRACE][discovery.zen.ping.unicast] [ES#5] [1] connecting to [ES#5][moCqg2upSgKVC9-J7V2lSw][ip-10-0-1-229][inet[/10.0.1.229:9300]]
[2016-11-13 22:53:13,202][TRACE][discovery.zen.ping.unicast] [ES#5] [1] connecting (light) to [#cloud-i-7eca5970-0][ip-10-0-1-229][inet[/10.0.0.54:9300]]
[2016-11-13 22:53:13,219][TRACE][discovery.zen.ping.unicast] [ES#5] [1] connected to [#cloud-i-7bab99e2-0][ip-10-0-1-229][inet[/10.0.1.229:9300]]
[2016-11-13 22:53:13,219][TRACE][discovery.zen.ping.unicast] [ES#5] [1] sending to [ES#5][moCqg2upSgKVC9-J7V2lSw][ip-10-0-1-229][inet[/10.0.1.229:9300]]
[2016-11-13 22:53:13,222][TRACE][discovery.zen.ping.unicast] [ES#5] [1] connected to [#cloud-i-c93d4c5a-0][ip-10-0-1-229][inet[/10.0.2.94:9300]]
[2016-11-13 22:53:13,222][TRACE][discovery.zen.ping.unicast] [ES#5] [1] sending to [#cloud-i-c93d4c5a-0][ip-10-0-1-229][inet[/10.0.2.94:9300]]
[2016-11-13 22:53:13,313][TRACE][discovery.zen.ping.unicast] [ES#5] [1] connected to [#cloud-i-7eca5970-0][ip-10-0-1-229][inet[/10.0.0.54:9300]]
[2016-11-13 22:53:13,315][TRACE][discovery.zen.ping.unicast] [ES#5] [1] sending to [#cloud-i-7eca5970-0][ip-10-0-1-229][inet[/10.0.0.54:9300]]
[2016-11-13 22:53:13,329][TRACE][discovery.zen.ping.unicast] [ES#5] [1] received response from [#cloud-i-7eca5970-0][ip-10-0-1-229][inet[/10.0.0.54:9300]]: [ping_response{target [[ES#5][moCqg2upSgKVC9-J7V2lSw][ip-10-0-1-229][inet[/10.0.1.229:9300]]], master [null], cluster_name[nudge-profile]}, ping_response{target [[ES#4][SJQ9KYJQSlO7eS5cf_5pBw][ip-10-0-0-54][inet[/10.0.0.54:9300]]], master [[ES#4][SJQ9KYJQSlO7eS5cf_5pBw][ip-10-0-0-54][inet[/10.0.0.54:9300]]], cluster_name[nudge-profile]}]
[2016-11-13 22:53:13,330][TRACE][discovery.zen.ping.unicast] [ES#5] [1] received response from [#cloud-i-c93d4c5a-0][ip-10-0-1-229][inet[/10.0.2.94:9300]]: [ping_response{target [[ES#5][moCqg2upSgKVC9-J7V2lSw][ip-10-0-1-229][inet[/10.0.1.229:9300]]], master [null], cluster_name[nudge-profile]}, ping_response{target [[ES#6][aFOnZOzbR7-0I3Cp1e0wZQ][ip-10-0-2-94][inet[/10.0.2.94:9300]]], master [[ES#4][SJQ9KYJQSlO7eS5cf_5pBw][ip-10-0-0-54][inet[/10.0.0.54:9300]]], cluster_name[nudge-profile]}]
[2016-11-13 22:53:13,332][TRACE][discovery.zen.ping.unicast] [ES#5] [1] received response from [ES#5][moCqg2upSgKVC9-J7V2lSw][ip-10-0-1-229][inet[/10.0.1.229:9300]]: [ping_response{target [[ES#5][moCqg2upSgKVC9-J7V2lSw][ip-10-0-1-229][inet[/10.0.1.229:9300]]], master [null], cluster_name[nudge-profile]}, ping_response{target [[ES#5][moCqg2upSgKVC9-J7V2lSw][ip-10-0-1-229][inet[/10.0.1.229:9300]]], master [null], cluster_name[nudge-profile]}]

It keeps repeating the same "building dynamic unicast discovery nodes..."

[2016-11-13 22:54:16,715][TRACE][discovery.zen.ping.unicast] [ES#5] [2] failed to connect to [#cloud-i-7eca5970-0][ip-10-0-1-229][inet[/10.0.0.54:9300]]
org.elasticsearch.transport.ConnectTransportException: [][inet[/10.0.0.54:9300]] connect_timeout[30s]
at org.elasticsearch.transport.netty.NettyTransport.connectToChannelsLight(NettyTransport.java:683)
at org.elasticsearch.transport.netty.NettyTransport.connectToNode(NettyTransport.java:643)
at org.elasticsearch.transport.netty.NettyTransport.connectToNodeLight(NettyTransport.java:610)
at org.elasticsearch.transport.TransportService.connectToNodeLight(TransportService.java:133)
at org.elasticsearch.discovery.zen.ping.unicast.UnicastZenPing$3.run(UnicastZenPing.java:279)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:744)
Caused by: java.nio.channels.ClosedByInterruptException
at java.nio.channels.spi.AbstractInterruptibleChannel.end(AbstractInterruptibleChannel.java:202)
at sun.nio.ch.SocketChannelImpl.connect(SocketChannelImpl.java:681)
at org.elasticsearch.common.netty.channel.socket.nio.NioClientSocketPipelineSink.connect(NioClientSocketPipelineSink.java:108)
at org.elasticsearch.common.netty.channel.socket.nio.NioClientSocketPipelineSink.eventSunk(NioClientSocketPipelineSink.java:70)
at org.elasticsearch.common.netty.channel.DefaultChannelPipeline.sendDownstream(DefaultChannelPipeline.java:574)
at org.elasticsearch.common.netty.channel.Channels.connect(Channels.java:634)
at org.elasticsearch.common.netty.channel.AbstractChannel.connect(AbstractChannel.java:207)
at org.elasticsearch.common.netty.bootstrap.ClientBootstrap.connect(ClientBootstrap.java:229)
at org.elasticsearch.common.netty.bootstrap.ClientBootstrap.connect(ClientBootstrap.java:182)
at org.elasticsearch.transport.netty.NettyTransport.connectToChannelsLight(NettyTransport.java:680)
... 7 more
[2016-11-13 22:54:16,715][TRACE][discovery.zen.ping.unicast] [ES#5] [2] failed to connect to [#cloud-i-7eca5970-0][ip-10-0-1-229][inet[/10.0.0.54:9300]]
org.elasticsearch.transport.ConnectTransportException: [][inet[/10.0.0.54:9300]] connect_timeout[30s]
at org.elasticsearch.transport.netty.NettyTransport.connectToChannelsLight(NettyTransport.java:683)
at org.elasticsearch.transport.netty.NettyTransport.connectToNode(NettyTransport.java:643)
at org.elasticsearch.transport.netty.NettyTransport.connectToNodeLight(NettyTransport.java:610)
at org.elasticsearch.transport.TransportService.connectToNodeLight(TransportService.java:133)
at org.elasticsearch.discovery.zen.ping.unicast.UnicastZenPing$3.run(UnicastZenPing.java:279)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:744)
Caused by: org.elasticsearch.common.netty.channel.ConnectTimeoutException: connection timed out: /10.0.0.54:9300
at org.elasticsearch.common.netty.channel.socket.nio.NioClientBoss.processConnectTimeout(NioClientBoss.java:137)
at org.elasticsearch.common.netty.channel.socket.nio.NioClientBoss.process(NioClientBoss.java:83)
at org.elasticsearch.common.netty.channel.socket.nio.AbstractNioSelector.run(AbstractNioSelector.java:318)
at org.elasticsearch.common.netty.channel.socket.nio.NioClientBoss.run(NioClientBoss.java:42)
at org.elasticsearch.common.netty.util.ThreadRenamingRunnable.run(ThreadRenamingRunnable.java:108)
at org.elasticsearch.common.netty.util.internal.DeadLockProofWorker$1.run(DeadLockProofWorker.java:42)
... 3 more
[2016-11-13 22:54:21,415][WARN ][discovery.ec2 ] [ES#5] failed to connect to master [[ES#4][SJQ9KYJQSlO7eS5cf_5pBw][ip-10-0-0-54][inet[/10.0.0.54:9300]]], retrying...
org.elasticsearch.transport.ConnectTransportException: [ES#4][inet[/10.0.0.54:9300]] connect_timeout[30s]
at org.elasticsearch.transport.netty.NettyTransport.connectToChannels(NettyTransport.java:736)
at org.elasticsearch.transport.netty.NettyTransport.connectToNode(NettyTransport.java:647)
at org.elasticsearch.transport.netty.NettyTransport.connectToNode(NettyTransport.java:615)
at org.elasticsearch.transport.TransportService.connectToNode(TransportService.java:129)
at org.elasticsearch.discovery.zen.ZenDiscovery.innerJoinCluster(ZenDiscovery.java:338)
at org.elasticsearch.discovery.zen.ZenDiscovery.access$500(ZenDiscovery.java:79)
at org.elasticsearch.discovery.zen.ZenDiscovery$1.run(ZenDiscovery.java:286)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:744)
Caused by: org.elasticsearch.common.netty.channel.ConnectTimeoutException: connection timed out: /10.0.0.54:9300
at org.elasticsearch.common.netty.channel.socket.nio.NioClientBoss.processConnectTimeout(NioClientBoss.java:137)
at org.elasticsearch.common.netty.channel.socket.nio.NioClientBoss.process(NioClientBoss.java:83)
at org.elasticsearch.common.netty.channel.socket.nio.AbstractNioSelector.run(AbstractNioSelector.java:318)
at org.elasticsearch.common.netty.channel.socket.nio.NioClientBoss.run(NioClientBoss.java:42)
at org.elasticsearch.common.netty.util.ThreadRenamingRunnable.run(ThreadRenamingRunnable.java:108)
at org.elasticsearch.common.netty.util.internal.DeadLockProofWorker$1.run(DeadLockProofWorker.java:42)
... 3 more

[2016-11-13 22:56:05,066][TRACE][discovery.ec2 ] [ES#5] building dynamic unicast discovery nodes...
[2016-11-13 22:56:05,066][TRACE][discovery.ec2 ] [ES#5] adding i-c93d4c5a, address 10.0.2.94, transport_address inet[/10.0.2.94:9300]
[2016-11-13 22:56:05,067][TRACE][discovery.ec2 ] [ES#5] adding i-7bab99e2, address 10.0.1.229, transport_address inet[/10.0.1.229:9300]
[2016-11-13 22:56:05,068][TRACE][discovery.ec2 ] [ES#5] adding i-7eca5970, address 10.0.0.54, transport_address inet[/10.0.0.54:9300]
[2016-11-13 22:56:05,068][DEBUG][discovery.ec2 ] [ES#5] using dynamic discovery nodes [[#cloud-i-c93d4c5a-0][ip-10-0-1-229][inet[/10.0.2.94:9300]], [#cloud-i-7bab99e2-0][ip-10-0-1-229][inet[/10.0.1.229:9300]], [#cloud-i-7eca5970-0][ip-10-0-1-229][inet[/10.0.0.54:9300]]]
[2016-11-13 22:56:05,068][TRACE][discovery.zen.ping.unicast] [ES#5] [10] sending to [ES#6][aFOnZOzbR7-0I3Cp1e0wZQ][ip-10-0-2-94][inet[/10.0.2.94:9300]]
[2016-11-13 22:56:05,068][TRACE][discovery.zen.ping.unicast] [ES#5] [10] sending to [ES#5][moCqg2upSgKVC9-J7V2lSw][ip-10-0-1-229][inet[/10.0.1.229:9300]]
[2016-11-13 22:56:05,068][TRACE][discovery.zen.ping.unicast] [ES#5] [10] sending to [ES#4][SJQ9KYJQSlO7eS5cf_5pBw][ip-10-0-0-54][inet[/10.0.0.54:9300]]
[2016-11-13 22:56:05,069][TRACE][discovery.zen.ping.unicast] [ES#5] [10] received response from [ES#5][moCqg2upSgKVC9-J7V2lSw][ip-10-0-1-229][inet[/10.0.1.229:9300]]: [ping_response{target [[ES#5][moCqg2upSgKVC9-J7V2lSw][ip-10-0-1-229][inet[/10.0.1.229:9300]]], master [null], cluster_name[nudge-profile]}, ping_response{target [[ES#5][moCqg2upSgKVC9-J7V2lSw][ip-10-0-1-229][inet[/10.0.1.229:9300]]], master [[ES#4][SJQ9KYJQSlO7eS5cf_5pBw][ip-10-0-0-54][inet[/10.0.0.54:9300]]], cluster_name[nudge-profile]}, ping_response{target [[ES#5][moCqg2upSgKVC9-J7V2lSw][ip-10-0-1-229][inet[/10.0.1.229:9300]]], master [[ES#4][SJQ9KYJQSlO7eS5cf_5pBw][ip-10-0-0-54][inet[/10.0.0.54:9300]]], cluster_name[nudge-profile]}, ping_response{target [[ES#5][moCqg2upSgKVC9-J7V2lSw][ip-10-0-1-229][inet[/10.0.1.229:9300]]], master [[ES#4][SJQ9KYJQSlO7eS5cf_5pBw][ip-10-0-0-54][inet[/10.0.0.54:9300]]], cluster_name[nudge-profile]}]
[2016-11-13 22:56:05,070][TRACE][discovery.zen.ping.unicast] [ES#5] [10] received response from [ES#6][aFOnZOzbR7-0I3Cp1e0wZQ][ip-10-0-2-94][inet[/10.0.2.94:9300]]: [ping_response{target [[ES#5][moCqg2upSgKVC9-J7V2lSw][ip-10-0-1-229][inet[/10.0.1.229:9300]]], master [null], cluster_name[nudge-profile]}, ping_response{target [[ES#5][moCqg2upSgKVC9-J7V2lSw][ip-10-0-1-229][inet[/10.0.1.229:9300]]], master [[ES#4][SJQ9KYJQSlO7eS5cf_5pBw][ip-10-0-0-54][inet[/10.0.0.54:9300]]], cluster_name[nudge-profile]}, ping_response{target [[ES#5][moCqg2upSgKVC9-J7V2lSw][ip-10-0-1-229][inet[/10.0.1.229:9300]]], master [[ES#4][SJQ9KYJQSlO7eS5cf_5pBw][ip-10-0-0-54][inet[/10.0.0.54:9300]]], cluster_name[nudge-profile]}, ping_response{target [[ES#6][aFOnZOzbR7-0I3Cp1e0wZQ][ip-10-0-2-94][inet[/10.0.2.94:9300]]], master [[ES#4][SJQ9KYJQSlO7eS5cf_5pBw][ip-10-0-0-54][inet[/10.0.0.54:9300]]], cluster_name[nudge-profile]}]
[2016-11-13 22:56:05,089][TRACE][discovery.zen.ping.unicast] [ES#5] [10] received response from [ES#4][SJQ9KYJQSlO7eS5cf_5pBw][ip-10-0-0-54][inet[/10.0.0.54:9300]]: [ping_response{target [[ES#5][moCqg2upSgKVC9-J7V2lSw][ip-10-0-1-229][inet[/10.0.1.229:9300]]], master [null], cluster_name[nudge-profile]}, ping_response{target [[ES#5][moCqg2upSgKVC9-J7V2lSw][ip-10-0-1-229][inet[/10.0.1.229:9300]]], master [[ES#4][SJQ9KYJQSlO7eS5cf_5pBw][ip-10-0-0-54][inet[/10.0.0.54:9300]]], cluster_name[nudge-profile]}, ping_response{target [[ES#5][moCqg2upSgKVC9-J7V2lSw][ip-10-0-1-229][inet[/10.0.1.229:9300]]], master [[ES#4][SJQ9KYJQSlO7eS5cf_5pBw][ip-10-0-0-54][inet[/10.0.0.54:9300]]], cluster_name[nudge-profile]}, ping_response{target [[ES#4][SJQ9KYJQSlO7eS5cf_5pBw][ip-10-0-0-54][inet[/10.0.0.54:9300]]], master [[ES#4][SJQ9KYJQSlO7eS5cf_5pBw][ip-10-0-0-54][inet[/10.0.0.54:9300]]], cluster_name[nudge-profile]}]
[2016-11-13 22:56:05,091][TRACE][discovery.zen.ping.unicast] [ES#5] [10] disconnecting from [#cloud-i-7eca5970-0][ip-10-0-1-229][inet[/10.0.0.54:9300]]
[2016-11-13 22:56:05,091][TRACE][discovery.zen.ping.unicast] [ES#5] [10] disconnecting from [#cloud-i-c93d4c5a-0][ip-10-0-1-229][inet[/10.0.2.94:9300]]
[2016-11-13 22:56:05,092][TRACE][discovery.ec2 ] [ES#5] full ping responses:
--> target [[ES#6][aFOnZOzbR7-0I3Cp1e0wZQ][ip-10-0-2-94][inet[/10.0.2.94:9300]]], master [[ES#4][SJQ9KYJQSlO7eS5cf_5pBw][ip-10-0-0-54][inet[/10.0.0.54:9300]]]
--> target [[ES#4][SJQ9KYJQSlO7eS5cf_5pBw][ip-10-0-0-54][inet[/10.0.0.54:9300]]], master [[ES#4][SJQ9KYJQSlO7eS5cf_5pBw][ip-10-0-0-54][inet[/10.0.0.54:9300]]]
[2016-11-13 22:56:05,092][DEBUG][discovery.ec2 ] [ES#5] filtered ping responses: (filter_client[true], filter_data[false])
--> target [[ES#6][aFOnZOzbR7-0I3Cp1e0wZQ][ip-10-0-2-94][inet[/10.0.2.94:9300]]], master [[ES#4][SJQ9KYJQSlO7eS5cf_5pBw][ip-10-0-0-54][inet[/10.0.0.54:9300]]]
--> target [[ES#4][SJQ9KYJQSlO7eS5cf_5pBw][ip-10-0-0-54][inet[/10.0.0.54:9300]]], master [[ES#4][SJQ9KYJQSlO7eS5cf_5pBw][ip-10-0-0-54][inet[/10.0.0.54:9300]]]
[2016-11-13 22:56:05,096][DEBUG][discovery.zen.fd ] [ES#5] [master] starting fault detection against master [[ES#4][SJQ9KYJQSlO7eS5cf_5pBw][ip-10-0-0-54][inet[/10.0.0.54:9300]]], reason [initial_join]
[2016-11-13 22:56:33,011][DEBUG][discovery.zen.publish ] [ES#5] received cluster state version 65

It just works if I wait and the network connection is not an issue here since I can ping other nodes without any problem. I will appreciate any help.
@nextofsearch nextofsearch changed the title Discovery takes more than 2 mins Discovery takes more than 2 minutes Nov 14, 2016
@nextofsearch nextofsearch changed the title Discovery takes more than 2 minutes Discovery takes more than 3 minutes Nov 14, 2016
@dadoonet
Copy link
Member

Is the machine 10.0.0.54 actually running elasticsearch?

@dadoonet dadoonet self-assigned this Nov 26, 2016
@dadoonet
Copy link
Member

dadoonet commented Mar 9, 2017

No news on that. Closing. Feel free to open a discussion on discuss.elastic.co if you still have this problem.

@dadoonet dadoonet closed this as completed Mar 9, 2017
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@dadoonet dadoonet

Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@dadoonet @nextofsearch