[
https://issues.apache.org/jira/browse/IMPALA-10235?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Sahil Takiar updated IMPALA-10235:
----------------------------------
Description:
Steps to reproduce on master:
{code:java}
stakiar @ stakiar-desktop -bash ~/Impala 2020-10-13 11:13:02 master
[74] → ./bin/impala-shell.sh -q "select sleep(100) from functional.alltypes
limit 25" -p > profile-output.txt
...
Query: select sleep(100) from functional.alltypes limit 25
Query submitted at: 2020-10-13 11:13:07 (Coordinator:
http://stakiar-desktop:25000)
Query progress can be monitored at:
http://stakiar-desktop:25000/query_plan?query_id=694f94671571d4d1:cdec9db900000000
Fetched 25 row(s) in 2.64s
{code}
Attached the contents of {{profile-output.txt}}
Relevant portion of the profile:
{code:java}
Averaged Fragment F00:(Total: 2s603ms, non-child: 272.519us, % non-child:
0.01%)
...
- CompletionTime: -1665218428.000ns
...
- TotalThreadsTotalWallClockTime: -1686005515.000ns
- TotalThreadsSysTime: 0.000ns
- TotalThreadsUserTime: 2.151ms
...
- TotalTime: -1691524485.000ns
{code}
For whatever reason, this only affects the averaged fragment profile. For this
query, there was only one coordinator fragment and thus only one fragment
instance. The coordinator fragment instance showed normal timer values:
{code:java}
Coordinator Fragment F00:
...
- CompletionTime: 2s629ms
...
- TotalThreadsTotalWallClockTime: 2s608ms
- TotalThreadsSysTime: 0.000ns
- TotalThreadsUserTime: 2.151ms
...
- TotalTime: 2s603ms
{code}
was:
Steps to reproduce on master:
{code}
stakiar @ stakiar-desktop -bash ~/Impala 2020-10-13 11:13:02 master
[74] → ./bin/impala-shell.sh -q "select sleep(100) from functional.alltypes
limit 25" -p > profile-output.txt
...
Query: select sleep(100) from functional.alltypes limit 25
Query submitted at: 2020-10-13 11:13:07 (Coordinator:
http://stakiar-desktop:25000)
Query progress can be monitored at:
http://stakiar-desktop:25000/query_plan?query_id=694f94671571d4d1:cdec9db900000000
Fetched 25 row(s) in 2.64s
{code}
Attached the contents of {{profile-output.txt}}
Relevant portion of the profile:
{code}
Averaged Fragment F00:(Total: 2s603ms, non-child: 272.519us, % non-child:
0.01%)
...
- CompletionTime: -1665218428.000ns
...
- TotalThreadsTotalWallClockTime: -1686005515.000ns
- TotalThreadsSysTime: 0.000ns
- TotalThreadsUserTime: 2.151ms
...
- TotalTime: -1691524485.000ns
{code}
For whatever reason, this only affects the averaged fragment profile. For this
query, there was only one coordinator fragment and thus only one fragment
instance. It showed normal values:
{code}
Coordinator Fragment F00:
...
- CompletionTime: 2s629ms
...
- TotalThreadsTotalWallClockTime: 2s608ms
- TotalThreadsSysTime: 0.000ns
- TotalThreadsUserTime: 2.151ms
...
- TotalTime: 2s603ms
{code}
> Averaged timer profile counters can be negative for trivial queries
> -------------------------------------------------------------------
>
> Key: IMPALA-10235
> URL: https://issues.apache.org/jira/browse/IMPALA-10235
> Project: IMPALA
> Issue Type: Bug
> Reporter: Sahil Takiar
> Priority: Major
> Labels: newbie, ramp-up
> Attachments: profile-output.txt
>
>
> Steps to reproduce on master:
> {code:java}
> stakiar @ stakiar-desktop -bash ~/Impala 2020-10-13 11:13:02 master
> [74] → ./bin/impala-shell.sh -q "select sleep(100) from functional.alltypes
> limit 25" -p > profile-output.txt
> ...
> Query: select sleep(100) from functional.alltypes limit 25
> Query submitted at: 2020-10-13 11:13:07 (Coordinator:
> http://stakiar-desktop:25000)
> Query progress can be monitored at:
> http://stakiar-desktop:25000/query_plan?query_id=694f94671571d4d1:cdec9db900000000
> Fetched 25 row(s) in 2.64s
> {code}
> Attached the contents of {{profile-output.txt}}
> Relevant portion of the profile:
> {code:java}
> Averaged Fragment F00:(Total: 2s603ms, non-child: 272.519us, % non-child:
> 0.01%)
> ...
> - CompletionTime: -1665218428.000ns
> ...
> - TotalThreadsTotalWallClockTime: -1686005515.000ns
> - TotalThreadsSysTime: 0.000ns
> - TotalThreadsUserTime: 2.151ms
> ...
> - TotalTime: -1691524485.000ns
> {code}
> For whatever reason, this only affects the averaged fragment profile. For
> this query, there was only one coordinator fragment and thus only one
> fragment instance. The coordinator fragment instance showed normal timer
> values:
> {code:java}
> Coordinator Fragment F00:
> ...
> - CompletionTime: 2s629ms
> ...
> - TotalThreadsTotalWallClockTime: 2s608ms
> - TotalThreadsSysTime: 0.000ns
> - TotalThreadsUserTime: 2.151ms
> ...
> - TotalTime: 2s603ms
> {code}
--
This message was sent by Atlassian Jira
(v8.3.4#803005)
---------------------------------------------------------------------
To unsubscribe, e-mail: issues-all-unsubscr...@impala.apache.org
For additional commands, e-mail: issues-all-h...@impala.apache.org
