Uploaded image for project: 'IMPALA'
  1. IMPALA
  2. IMPALA-2567 KRPC milestone 1
  3. IMPALA-6432

Default rpc_negotiation_timeout_ms may cause queries to fail on large clusters

    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}
      
      

        Attachments

          Issue Links

            Activity

              People

              • Assignee:
                sailesh Sailesh Mukil
                Reporter:
                mmokhtar Mostafa Mokhtar
              • Votes:
                0 Vote for this issue
                Watchers:
                5 Start watching this issue

                Dates

                • Created:
                  Updated:
                  Resolved: