Uploaded image for project: 'IMPALA'
  1. IMPALA
  2. IMPALA-5108

idle_session_timeout kicks in later than expected

    Details

    • Type: Bug
    • Status: Resolved
    • Priority: Major
    • Resolution: Fixed
    • Affects Version/s: Impala 2.5.5
    • Fix Version/s: Impala 2.10.0
    • Component/s: Backend
    • Labels:
    • Epic Color:
      ghx-label-1

      Description

      When using idle_session_timeout value of 120 and submitting a query from Hue, I see the connection being idle from tcpdump since:

      05:28:03.474282 IP impalad.21050 > hue.33879: Flags [P.], seq 3261:3368, ack 2107, win 147, options [nop,nop,TS val 512338192 ecr 72619609], length 107
      05:28:03.513861 IP hue.33879 > impalad.21050: Flags [.], ack 3368, win 339, options [nop,nop,TS val 72619649 ecr 512338192], length 0

      However, the query runs from:

      Start Time: 2017-03-22 05:28:01.605899000
      End Time: 2017-03-22 05:31:01.505750000
      

      Query timeline:

      Planner Timeline: 14.973ms
             - Analysis finished: 3.904ms (3.904ms)
             - Equivalence classes computed: 4.433ms (529.525us)
             - Single node plan created: 8.165ms (3.732ms)
             - Distributed plan created: 9.340ms (1.174ms)
             - Lineage info computed: 11.319ms (1.978ms)
             - Planning finished: 14.973ms (3.654ms)
          Query Timeline: 2m59s
             - Start execution: 0.000ns (0.000ns)
             - Planning finished: 17.999ms (17.999ms)
             - Child queries finished: 20.999ms (2.999ms)
             - Rows available: 20.999ms (0.000ns)
             - First row fetched: 1s467ms (1s446ms)
             - Unregister query: 2m59s (2m58s)
        ImpalaServer:
           - ClientFetchWaitTimer: 2m59s
           - RowMaterializationTimer: 0.000ns
      

      It was just a simple select * limit 1. We've had reports of this from various users, noting that while the session is closed eventually, the timings are confusing (and the difference between the configured value and the actual timeout depends on the configured value, it's not a constant 1m offset - with an idle_session_timeout of 180 I had queries timing out only after 4.5 minutes).

      From logs:
      with value of 120:

      I0322 05:31:01.500277 15691 impala-server.cc:1723] Expiring session: 74b43411be11eef:fee3c89065e2f0a2, user:admin, last active: 2017-03-22 12:28:03
      

      with value of 75:

      I0322 05:45:36.058423 17626 impala-server.cc:1723] Expiring session: a442144dff67f1c9:1fe7ecae10a1da4, user:admin, last
       active: 2017-03-22 12:43:46
      

        Attachments

          Activity

            People

            • Assignee:
              pranay_singh Pranay Singh
              Reporter:
              jeszyb Balazs Jeszenszky
            • Votes:
              1 Vote for this issue
              Watchers:
              9 Start watching this issue

              Dates

              • Created:
                Updated:
                Resolved: