[IMPALA-6432] Default rpc_negotiation_timeout_ms may cause queries to fail on large clusters - ASF JIRA

Attach files

Attach Screenshot

Voters

Watch issue

Watchers

Link

Clone

Update Comment Author

Replace String in Comment

Update Comment Visibility

Delete Comments

XML

Word

Printable

JSON

Details

Type: Sub-task
Status: Resolved
Priority: Critical
Resolution: Fixed
Affects Version/s: Impala 2.11.0
Fix Version/s: Impala 2.12.0
Component/s: Distributed Exec
Labels:
None

Epic Color:
ghx-label-4

Description

While running the stress test on a 140 node secure cluster with "default" configs queries were failing with negotiation timeouts.

With rpc_negotiation_timeout_ms=60000 queries appear to run fine, ideally we should understand why this takes very long and bump the default to a more reasonable value.


W0121 16:51:04.014796 156630 negotiation.cc:302] Failed RPC negotiation. Trace:
0121 16:51:00.254978 (+ 0us) reactor.cc:481] Submitting negotiation task for server connection from 10.17.221.35:38297
0121 16:51:03.194696 (+2939718us) server_negotiation.cc:169] Beginning negotiation
0121 16:51:03.194697 (+ 1us) server_negotiation.cc:358] Waiting for connection header
0121 16:51:03.194708 (+ 11us) server_negotiation.cc:366] Connection header received
0121 16:51:03.194720 (+ 12us) server_negotiation.cc:322] Received NEGOTIATE NegotiatePB request
0121 16:51:03.194721 (+ 1us) server_negotiation.cc:407] Received NEGOTIATE request from client
0121 16:51:03.194725 (+ 4us) server_negotiation.cc:334] Sending NEGOTIATE NegotiatePB response
0121 16:51:03.194761 (+ 36us) server_negotiation.cc:190] Negotiated authn=SASL
0121 16:51:03.206182 (+ 11421us) server_negotiation.cc:322] Received SASL_INITIATE NegotiatePB request
0121 16:51:03.206183 (+ 1us) server_negotiation.cc:754] Received SASL_INITIATE request from client
0121 16:51:03.206184 (+ 1us) server_negotiation.cc:765] Client requested to use mechanism: GSSAPI
0121 16:51:03.206190 (+ 6us) server_negotiation.cc:794] Calling sasl_server_start()
0121 16:51:03.990155 (+783965us) server_negotiation.cc:334] Sending SASL_CHALLENGE NegotiatePB response
0121 16:51:04.014736 (+ 24581us) negotiation.cc:293] Negotiation complete: Timed out: Server connection negotiation failed: server connection from 10.17.221.35:38297: BlockingWrite timed out
Metrics: \{"server-negotiator.queue_time_us":2939697}
W0121 16:51:04.014961 156629 negotiation.cc:302] Failed RPC negotiation. Trace:
0121 16:51:00.512560 (+ 0us) reactor.cc:481] Submitting negotiation task for server connection from 10.17.232.27:38602
0121 16:51:03.502222 (+2989662us) server_negotiation.cc:169] Beginning negotiation
0121 16:51:03.502223 (+ 1us) server_negotiation.cc:358] Waiting for connection header
0121 16:51:03.502231 (+ 8us) server_negotiation.cc:366] Connection header received
0121 16:51:03.502242 (+ 11us) server_negotiation.cc:322] Received NEGOTIATE NegotiatePB request
0121 16:51:03.502243 (+ 1us) server_negotiation.cc:407] Received NEGOTIATE request from client
0121 16:51:03.502247 (+ 4us) server_negotiation.cc:334] Sending NEGOTIATE NegotiatePB response
0121 16:51:03.502272 (+ 25us) server_negotiation.cc:190] Negotiated authn=SASL
0121 16:51:03.506579 (+ 4307us) server_negotiation.cc:322] Received SASL_INITIATE NegotiatePB request
0121 16:51:03.506581 (+ 2us) server_negotiation.cc:754] Received SASL_INITIATE request from client
0121 16:51:03.506581 (+ 0us) server_negotiation.cc:765] Client requested to use mechanism: GSSAPI
0121 16:51:03.506588 (+ 7us) server_negotiation.cc:794] Calling sasl_server_start()
0121 16:51:04.003539 (+496951us) server_negotiation.cc:334] Sending SASL_CHALLENGE NegotiatePB response
0121 16:51:04.014903 (+ 11364us) negotiation.cc:293] Negotiation complete: Timed out: Server connection negotiation failed: server connection from 10.17.232.27:38602: BlockingWrite timed out
Metrics: \{"server-negotiator.queue_time_us":2989644}

W0121 16:51:04.026866 156629 negotiation.cc:302] Failed RPC negotiation. Trace:
0121 16:51:00.796311 (+ 0us) reactor.cc:481] Submitting negotiation task for server connection from 10.17.232.48:52481
0121 16:51:04.026814 (+3230503us) server_negotiation.cc:169] Beginning negotiation
0121 16:51:04.026815 (+ 1us) server_negotiation.cc:358] Waiting for connection header
0121 16:51:04.026839 (+ 24us) negotiation.cc:293] Negotiation complete: Timed out: Server connection negotiation failed: server connection from 10.17.232.48:52481
Metrics: \{"server-negotiator.queue_time_us":3230488}
W0121 16:51:04.027504 156632 negotiation.cc:302] Failed RPC negotiation. Trace:
0121 16:51:00.807588 (+ 0us) reactor.cc:481] Submitting negotiation task for server connection from 10.17.232.43:55531
0121 16:51:04.027449 (+3219861us) server_negotiation.cc:169] Beginning negotiation
0121 16:51:04.027450 (+ 1us) server_negotiation.cc:358] Waiting for connection header
0121 16:51:04.027481 (+ 31us) negotiation.cc:293] Negotiation complete: Timed out: Server connection negotiation failed: server connection from 10.17.232.43:55531
Metrics: \{"server-negotiator.queue_time_us":3219845}
W0121 16:51:04.028131 156631 negotiation.cc:302] Failed RPC negotiation. Trace:
0121 16:51:00.809899 (+ 0us) reactor.cc:481] Submitting negotiation task for server connection from 10.17.234.52:41207
0121 16:51:04.028062 (+3218163us) server_negotiation.cc:169] Beginning negotiation
0121 16:51:04.028064 (+ 2us) server_negotiation.cc:358] Waiting for connection header
0121 16:51:04.028094 (+ 30us) negotiation.cc:293] Negotiation complete: Timed out: Server connection negotiation failed: server connection from 10.17.234.52:41207
Metrics: \{"server-negotiator.queue_time_us":3218143}
W0121 16:51:04.028815 156630 negotiation.cc:302] Failed RPC negotiation. Trace:
0121 16:51:00.832191 (+ 0us) reactor.cc:481] Submitting negotiation task for server connection from 10.17.234.39:40621
0121 16:51:04.028765 (+3196574us) server_negotiation.cc:169] Beginning negotiation
0121 16:51:04.028766 (+ 1us) server_negotiation.cc:358] Waiting for connection header
0121 16:51:04.028793 (+ 27us) negotiation.cc:293] Negotiation complete: Timed out: Server connection negotiation failed: server connection from 10.17.234.39:40621
Metrics: \{"server-negotiator.queue_time_us":3196559}