impala-issues mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Balazs Jeszenszky (JIRA)" <j...@apache.org>
Subject [jira] [Updated] (IMPALA-5108) idle_session_timeout kicks in later than expected
Date Wed, 22 Mar 2017 12:50:41 GMT

     [ https://issues.apache.org/jira/browse/IMPALA-5108?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]

Balazs Jeszenszky updated IMPALA-5108:
--------------------------------------
    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:

{code:java}
Start Time: 2017-03-22 05:28:01.605899000
End Time: 2017-03-22 05:31:01.505750000
{code}

Query timeline:
{code:java}
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
{code}
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:
{code:java}
I0322 05:31:01.500277 15691 impala-server.cc:1723] Expiring session: 74b43411be11eef:fee3c89065e2f0a2,
user:admin, last active: 2017-03-22 12:28:03
{code}

with value of 75:
{code:java}
I0322 05:45:36.058423 17626 impala-server.cc:1723] Expiring session: a442144dff67f1c9:1fe7ecae10a1da4,
user:admin, last
 active: 2017-03-22 12:43:46
{code}

  was:
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:

{code:java}
Start Time: 2017-03-22 05:28:01.605899000
End Time: 2017-03-22 05:31:01.505750000
{code}

Query timeline:
{code:java}
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
{code}
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


> idle_session_timeout kicks in later than expected
> -------------------------------------------------
>
>                 Key: IMPALA-5108
>                 URL: https://issues.apache.org/jira/browse/IMPALA-5108
>             Project: IMPALA
>          Issue Type: Bug
>          Components: be
>    Affects Versions: Impala 2.5.5
>            Reporter: Balazs Jeszenszky
>
> 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:
> {code:java}
> Start Time: 2017-03-22 05:28:01.605899000
> End Time: 2017-03-22 05:31:01.505750000
> {code}
> Query timeline:
> {code:java}
> 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
> {code}
> 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:
> {code:java}
> I0322 05:31:01.500277 15691 impala-server.cc:1723] Expiring session: 74b43411be11eef:fee3c89065e2f0a2,
user:admin, last active: 2017-03-22 12:28:03
> {code}
> with value of 75:
> {code:java}
> I0322 05:45:36.058423 17626 impala-server.cc:1723] Expiring session: a442144dff67f1c9:1fe7ecae10a1da4,
user:admin, last
>  active: 2017-03-22 12:43:46
> {code}



--
This message was sent by Atlassian JIRA
(v6.3.15#6346)

Mime
View raw message