kudu-user mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Todd Lipcon <t...@cloudera.com>
Subject Re: What does "Failed RPC negotiation" in kudu-tserver.WARNING
Date Sat, 17 Jun 2017 20:48:48 GMT
Yea, that's a known bug that the Java client, as it is used by Impala, ends
up connecting to tablet servers and often disconnecting during negotiation.
The TS is just warning because it saw a client connect and then disconnect
mid-negotiation.

Todd

On Jun 17, 2017 9:46 AM, "Jean-Daniel Cryans" <jdcryans@apache.org> wrote:

> Hi Jason,
>
> This looks a lot like KUDU-1963 which AFAIK isn't fixed in the Kudu client
> that ships with that version of Impala (1.3.0). I think it's safe to
> ignore? Todd might have a better idea.
>
> J-D
>
> On Fri, Jun 16, 2017 at 11:41 PM, Jason Heo <jason.heo.sde@gmail.com>
> wrote:
>
>> Hi.
>>
>> I'm using Apache Kudu 1.4.0 and Impala 2.8.0
>>
>> I'm getting an error message like this in kudu-tserver.WARNING
>>
>> W0617 08:10:20.838203 57169 negotiation.cc:303] Failed RPC negotiation.
>> Trace:
>>
>> 0617 08:10:20.698376 (+     0us) reactor.cc:449] Submitting negotiation
>> task for server connection from ip_addr:56080
>>
>> 0617 08:10:20.698518 (+   142us) server_negotiation.cc:167] Beginning
>> negotiation
>>
>> 0617 08:10:20.698520 (+     2us) server_negotiation.cc:355] Waiting for
>> connection header
>>
>> 0617 08:10:20.835482 (+136962us) server_negotiation.cc:363] Connection
>> header received
>>
>> 0617 08:10:20.835705 (+   223us) server_negotiation.cc:319] Received
>> NEGOTIATE NegotiatePB request
>>
>> 0617 08:10:20.835706 (+     1us) server_negotiation.cc:404] Received
>> NEGOTIATE request from client
>>
>> 0617 08:10:20.835716 (+    10us) server_negotiation.cc:331] Sending
>> NEGOTIATE NegotiatePB response
>>
>> 0617 08:10:20.835738 (+    22us) server_negotiation.cc:188] Negotiated
>> authn=SASL
>>
>> 0617 08:10:20.836866 (+  1128us) server_negotiation.cc:319] Received
>> SASL_INITIATE NegotiatePB request
>>
>> 0617 08:10:20.836867 (+     1us) server_negotiation.cc:751] Received
>> SASL_INITIATE request from client
>>
>> 0617 08:10:20.836867 (+     0us) server_negotiation.cc:762] Client
>> requested to use mechanism: PLAIN
>>
>> 0617 08:10:20.836874 (+     7us) server_negotiation.cc:791] Calling
>> sasl_server_start()
>>
>> 0617 08:10:20.836891 (+    17us) server_negotiation.cc:947] Received
>> PLAIN auth.
>>
>> 0617 08:10:20.836894 (+     3us) server_negotiation.cc:331] Sending
>> SASL_SUCCESS NegotiatePB response
>>
>> 0617 08:10:20.836912 (+    18us) server_negotiation.cc:892] Waiting for
>> connection context
>>
>> 0617 08:10:20.838113 (+  1201us) negotiation.cc:294] Negotiation
>> complete: Network error: Server connection negotiation failed: server
>> connection from ip_addr:56080: BlockingRecv error: Recv() got EOF from
>> remote (error 108)
>>
>> Metrics: {"negotiator.queue_time_us":116,"thread_start_us":106,"threa
>> ds_started":1}
>>
>>
>> The Query is sent from impala, and following error was logged in impalad
>> log
>>
>>
>> I0617 08:10:15.072661 160189 Frontend.java:890] Compiling query: show
>> range partitions kudu_table_name
>>
>> I0617 08:10:15.073048 160189 Frontend.java:832] Requesting prioritized
>> load of table(s): default.kudu_table_name
>>
>> I0617 08:10:20.632325 160189 Frontend.java:921] Compiled query.
>>
>> E0617 08:10:20.868751 27432 TabletClient.java:706] [Peer
>> b3e92a30fbc3470c8211040b81e62272] Unexpected exception from downstream
>> on [id: 0x8d796a22, /ip_addr:56080 :> hostname/ip_addr:7050]
>>
>> Java exception follows:
>>
>> java.lang.NullPointerException
>>
>>         at org.apache.kudu.client.TabletClient.sendQueuedRpcs(TabletCli
>> ent.java:725)
>>
>>         at org.apache.kudu.client.TabletClient.messageReceived(TabletCl
>> ient.java:361)
>>
>>         at org.apache.kudu.client.shaded.org.jboss.netty.channel.Simple
>> ChannelUpstreamHandler.handleUpstream(SimpleChannelUpstreamH
>> andler.java:70)
>>
>>         at org.apache.kudu.client.TabletClient.handleUpstream(TabletCli
>> ent.java:595)
>>
>>         at org.apache.kudu.client.shaded.org.jboss.netty.channel.Defaul
>> tChannelPipeline.sendUpstream(DefaultChannelPipeline.java:564)
>>
>>         at org.apache.kudu.client.shaded.org.jboss.netty.channel.Defaul
>> tChannelPipeline$DefaultChannelHandlerContext.sendUpstream(D
>> efaultChannelPipeline.java:791)
>>
>>         at org.apache.kudu.client.shaded.org.jboss.netty.handler.timeou
>> t.ReadTimeoutHandler.messageReceived(ReadTimeoutHandler.java:184)
>>
>>         at org.apache.kudu.client.shaded.org.jboss.netty.channel.Simple
>> ChannelUpstreamHandler.handleUpstream(SimpleChannelUpstreamH
>> andler.java:70)
>>
>>         at org.apache.kudu.client.shaded.org.jboss.netty.channel.Defaul
>> tChannelPipeline.sendUpstream(DefaultChannelPipeline.java:564)
>>
>>         at org.apache.kudu.client.shaded.org.jboss.netty.channel.Defaul
>> tChannelPipeline$DefaultChannelHandlerContext.sendUpstream(D
>> efaultChannelPipeline.java:791)
>>
>>         at org.apache.kudu.client.shaded.org.jboss.netty.handler.codec.
>> oneone.OneToOneDecoder.handleUpstream(OneToOneDecoder.java:68)
>>
>>         at org.apache.kudu.client.shaded.org.jboss.netty.channel.Defaul
>> tChannelPipeline.sendUpstream(DefaultChannelPipeline.java:564)
>>
>>         at org.apache.kudu.client.shaded.org.jboss.netty.channel.Defaul
>> tChannelPipeline$DefaultChannelHandlerContext.sendUpstream(D
>> efaultChannelPipeline.java:791)
>>
>>         at org.apache.kudu.client.shaded.org.jboss.netty.handler.codec.
>> frame.FrameDecoder.messageReceived(FrameDecoder.java:291)
>>
>>         at org.apache.kudu.client.shaded.org.jboss.netty.channel.Simple
>> ChannelUpstreamHandler.handleUpstream(SimpleChannelUpstreamH
>> andler.java:70)
>>
>>         at org.apache.kudu.client.shaded.org.jboss.netty.channel.Defaul
>> tChannelPipeline.sendUpstream(DefaultChannelPipeline.java:564)
>>
>>         at org.apache.kudu.client.shaded.org.jboss.netty.channel.Defaul
>> tChannelPipeline.sendUpstream(DefaultChannelPipeline.java:559)
>>
>>         at org.apache.kudu.client.shaded.org.jboss.netty.channel.Channe
>> ls.fireMessageReceived(Channels.java:268)
>>
>>         at org.apache.kudu.client.shaded.org.jboss.netty.channel.Channe
>> ls.fireMessageReceived(Channels.java:255)
>>
>>         at org.apache.kudu.client.Negotiator.finish(Negotiator.java:636)
>>
>>         at org.apache.kudu.client.Negotiator.handleSuccessResponse(Nego
>> tiator.java:624)
>>
>>         at org.apache.kudu.client.Negotiator.handleSaslMessage(Negotiat
>> or.java:265)
>>
>>         at org.apache.kudu.client.Negotiator.handleResponse(Negotiator.
>> java:244)
>>
>>
>> But impala returned the result of query without and error. Above error
>> messages are logged from time to time, I didn't catch this error message
>> until looking into log files.
>>
>> It seems kudu-tserver and impalad work well. Can I ignore this messages?
>>
>> Thanks.
>>
>> Regards,
>>
>> Jason
>>
>>
>

Mime
View raw message