You are viewing a plain text version of this content. The canonical link for it is here.
Posted to user@tez.apache.org by Anandha L Ranganathan <an...@gmail.com> on 2017/05/19 23:14:04 UTC
Tez job SUCCEEDED but still containers (Map/Reducer) are running
We hit with unique problem. Still the tez containers are running but
Hive moved the file from staging location to actual location. Is this
bug in the Tez engine?
I have attached logs and you can see still Map1, Reducer3 , Reducer
4, Reducer 7 are running but DAG is SUCCEEDED.
[2017-04-21 18:08:57,108] {hive_hooks.py:130} INFO - INFO : Map 1:
0(+2)/8 Map 12: 1/1 Map 5: 1/1 Map 8: 1/1 Map 9: 1/1 Reducer 11:
0/1 Reducer 3: 0/308 Reducer 4: 0/2 Reducer 7: 0/1
[2017-04-21 18:09:57,116] {hive_hooks.py:130} INFO - INFO : Map 1:
0(+2)/8 Map 12: 1/1 Map 5: 1/1 Map 8: 1/1 Map 9: 1/1 Reducer 11:
0/1 Reducer 3: 0/308 Reducer 4: 0/2 Reducer 7: 0/1
[2017-04-21 18:09:57,116] {hive_hooks.py:130} INFO - INFO : Map 1:
0(+2)/8 Map 12: 1/1 Map 5: 1/1 Map 8: 1/1 Map 9: 1/1 Reducer 11:
0/1 Reducer 3: 0/308 Reducer 4: 0/2 Reducer 7: 0/1
[2017-04-21 18:29:38,595] {hive_hooks.py:130} INFO - INFO : Map 1:
0(+2)/8 Map 12: 1/1 Map 5: 1/1 Map 8: 1/1 Map 9: 1/1 Reducer 11:
0/1 Reducer 3: 0/308 Reducer 4: 0/2 Reducer 7: 0/1
[2017-04-21 18:29:38,595] {hive_hooks.py:130} INFO - INFO :
[2017-04-21 18:29:38,596] {hive_hooks.py:130} INFO - INFO : Status:
DAG finished successfully in 1560.07 seconds
[2017-04-21 18:29:38,596] {hive_hooks.py:130} INFO - INFO :
[2017-04-21 18:29:38,596] {hive_hooks.py:130} INFO -
[2017-04-21 18:29:38,596] {hive_hooks.py:130} INFO - INFO : METHOD
DURATION(ms)
[2017-04-21 18:29:38,596] {hive_hooks.py:130} INFO - INFO : parse
0
[2017-04-21 18:29:38,596] {hive_hooks.py:130} INFO - INFO :
semanticAnalyze 0
[2017-04-21 18:29:38,596] {hive_hooks.py:130} INFO - INFO :
TezBuildDag 0
[2017-04-21 18:29:38,596] {hive_hooks.py:130} INFO - INFO :
TezSubmitToRunningDag 12,957
[2017-04-21 18:29:38,597] {hive_hooks.py:130} INFO - INFO :
TotalPrepTime 53,372
[2017-04-21 18:29:38,597] {hive_hooks.py:130} INFO -
[2017-04-21 18:29:38,597] {hive_hooks.py:130} INFO - INFO : Loading
data to table dw_insight.d_experiment from
hdfs://dfs-nameservices/data/insight/dwuser/d_experiment/.hive-staging_hive_2017-04-21_18-02-31_741_4202396962843353301-4404/-ext-10000
[2017-04-21 18:29:38,597] {hive_hooks.py:130} INFO - INFO : Table
dw_insight.d_experiment stats: [numFiles=0, numRows=0, totalSize=0,
rawDataSize=0]
[2017-04-21 18:29:38,597] {hive_hooks.py:130} INFO - No rows affected
(1626.877 seconds)
[2017-04-21 18:29:38,604] {hive_hooks.py:130} INFO - 0:
jdbc:hive2://usw2prdpmn01:10000/dw_insight>
[2017-04-21 18:29:38,611] {hive_hooks.py:130} INFO - 0:
jdbc:hive2://usw2prdpmn01:10000/dw_insight> ANALYZE TABLE
${hiveconf:target_t
Re: Tez job SUCCEEDED but still containers (Map/Reducer) are running
Posted by Gopal Vijayaraghavan <go...@apache.org>.
> Here Reducers are still running (marked in red) and DAG finished (marked in green) successfully. Also I looked at the timestamp of logs and something weird happening.
There are 20 second gap which is unexplained for - the status won't print the vertex details if the tasks have already finished.
It is entirely possible your Hive client had a GC pause, while the DAG finished running without a log update.
09:57 -> 29:38
To verify this, you should enable
set hive.tez.exec.print.summary=true;
So that it prints a log line after the DAG finishes.
Cheers,
Gopal
Re: Tez job SUCCEEDED but still containers (Map/Reducer) are running
Posted by Anandha L Ranganathan <an...@gmail.com>.
Siddharth,
I should have been clear in previous email. When I say containers, in
this case it is Tasks (mapper/reducer) . I have copy/pasted some info
from above. Here Reducers are still running (marked in red) and DAG
finished (marked in green) successfully. Also I looked at the timestamp
of logs and something weird happening.
[2017-04-21 18:09:57,116] {hive_hooks.py:130} INFO - INFO : Map 1:
0(+2)/8 Map 12: 1/1 Map 5: 1/1 Map 8: 1/1 Map 9: 1/1 Reducer 11:
0/1 Reducer 3: 0/308 Reducer 4: 0/2 Reducer 7: 0/1
[2017-04-21 18:29:38,595] {hive_hooks.py:130} INFO - INFO : Map 1:
0(+2)/8 Map 12: 1/1 Map 5: 1/1 Map 8: 1/1 Map 9: 1/1 Reducer 11:
0/1 Reducer 3: 0/308 Reducer 4: 0/2 Reducer 7: 0/1[2017-04-21
18:29:38,595] {hive_hooks.py:130} INFO - INFO :
[2017-04-21 18:29:38,596] {hive_hooks.py:130} INFO - INFO : Status:
DAG finished successfully in 1560.07 seconds
Isn't that DAG should wait for all the tasks to be completed before saying
SUCCESS/FAILED ?
Thanks
Anand
On Mon, May 22, 2017 at 11:14 AM, Siddharth Seth <ss...@apache.org> wrote:
> Anandha,
> If you are seeing incorrect results from Hive, I would suggest sending a
> mail to user@hive.
> As Ravi pointed out, containers can continue to run after a query
> completes, due to how container re-use is configured.
>
> On Sun, May 21, 2017 at 11:37 PM, Ravi Teja Chilukuri <
> raviorteja@gmail.com> wrote:
>
>> HI Anandha,
>>
>> | reducers are still running but " DAG finished successfully" and
>> inserted zero records.
>>
>> The "containers" used by reducers can be still running even after the DAG
>> has completed , due to the container re-use, they will be waiting for
>> another "task" to be assigned to the same container.
>> Can you please verify the task logs of the container where you see the
>> reducer is still running, I think the reduce attempt would have already
>> have completed and the container is waiting for a new task.
>>
>> If that is the case, can you verify the hive query which might be causing
>> 0 records being inserted.
>>
>> Thanks,
>> Ravi
>>
>> On Mon, May 22, 2017 at 11:51 AM, Anandha L Ranganathan <
>> analog.sony@gmail.com> wrote:
>>
>>> Thanks Ravi for the information. We will udpate
>>> tez.session.am.dag.submit.timeout.secs to lower value in our config.
>>>
>>> Our main concern is when reducers are still running but " DAG
>>> finished successfully" and inserted zero records.
>>>
>>> [2017-04-21 18:29:38,597] {hive_hooks.py:130} INFO - INFO : Table dw_insight.d_experiment stats: [numFiles=0, numRows=0, totalSize=0, rawDataSize=0]
>>>
>>>
>>> This resulted incorrect result set and data got corrupted.
>>>
>>> Thanks
>>> Anand
>>>
>>> On Sun, May 21, 2017 at 7:18 AM, Ravi Teja Chilukuri <
>>> raviorteja@gmail.com> wrote:
>>>
>>>> Hi Anandha,
>>>>
>>>> If your hive query has completed and still the containers are running,
>>>> you might want to set the param: tez.session.am.dag.submit.timeout.secs
>>>> to a lower value , for the yarn application to be completely shutdown.
>>>> In session mode, by default the AM container waits till 5 minutes for
>>>> any other queries to be fired.
>>>>
>>>>
>>>> Thanks,
>>>> Ravi
>>>>
>>>> On Sat, May 20, 2017 at 4:44 AM, Anandha L Ranganathan <
>>>> analog.sony@gmail.com> wrote:
>>>>
>>>>> We hit with unique problem. Still the tez containers are running but Hive moved the file from staging location to actual location. Is this bug in the Tez engine?
>>>>>
>>>>> I have attached logs and you can see still Map1, Reducer3 , Reducer 4, Reducer 7 are running but DAG is SUCCEEDED.
>>>>>
>>>>>
>>>>>
>>>>> [2017-04-21 18:08:57,108] {hive_hooks.py:130} INFO - INFO : Map 1: 0(+2)/8 Map 12: 1/1 Map 5: 1/1 Map 8: 1/1 Map 9: 1/1 Reducer 11: 0/1 Reducer 3: 0/308 Reducer 4: 0/2 Reducer 7: 0/1
>>>>> [2017-04-21 18:09:57,116] {hive_hooks.py:130} INFO - INFO : Map 1: 0(+2)/8 Map 12: 1/1 Map 5: 1/1 Map 8: 1/1 Map 9: 1/1 Reducer 11: 0/1 Reducer 3: 0/308 Reducer 4: 0/2 Reducer 7: 0/1
>>>>> [2017-04-21 18:09:57,116] {hive_hooks.py:130} INFO - INFO : Map 1: 0(+2)/8 Map 12: 1/1 Map 5: 1/1 Map 8: 1/1 Map 9: 1/1 Reducer 11: 0/1 Reducer 3: 0/308 Reducer 4: 0/2 Reducer 7: 0/1
>>>>> [2017-04-21 18:29:38,595] {hive_hooks.py:130} INFO - INFO : Map 1: 0(+2)/8 Map 12: 1/1 Map 5: 1/1 Map 8: 1/1 Map 9: 1/1 Reducer 11: 0/1 Reducer 3: 0/308 Reducer 4: 0/2 Reducer 7: 0/1
>>>>> [2017-04-21 18:29:38,595] {hive_hooks.py:130} INFO - INFO :
>>>>> [2017-04-21 18:29:38,596] {hive_hooks.py:130} INFO - INFO : Status: DAG finished successfully in 1560.07 seconds
>>>>> [2017-04-21 18:29:38,596] {hive_hooks.py:130} INFO - INFO :
>>>>> [2017-04-21 18:29:38,596] {hive_hooks.py:130} INFO -
>>>>> [2017-04-21 18:29:38,596] {hive_hooks.py:130} INFO - INFO : METHOD DURATION(ms)
>>>>> [2017-04-21 18:29:38,596] {hive_hooks.py:130} INFO - INFO : parse 0
>>>>> [2017-04-21 18:29:38,596] {hive_hooks.py:130} INFO - INFO : semanticAnalyze 0
>>>>> [2017-04-21 18:29:38,596] {hive_hooks.py:130} INFO - INFO : TezBuildDag 0
>>>>> [2017-04-21 18:29:38,596] {hive_hooks.py:130} INFO - INFO : TezSubmitToRunningDag 12,957
>>>>> [2017-04-21 18:29:38,597] {hive_hooks.py:130} INFO - INFO : TotalPrepTime 53,372
>>>>> [2017-04-21 18:29:38,597] {hive_hooks.py:130} INFO -
>>>>> [2017-04-21 18:29:38,597] {hive_hooks.py:130} INFO - INFO : Loading data to table dw_insight.d_experiment from hdfs://dfs-nameservices/data/insight/dwuser/d_experiment/.hive-staging_hive_2017-04-21_18-02-31_741_4202396962843353301-4404/-ext-10000
>>>>> [2017-04-21 18:29:38,597] {hive_hooks.py:130} INFO - INFO : Table dw_insight.d_experiment stats: [numFiles=0, numRows=0, totalSize=0, rawDataSize=0]
>>>>> [2017-04-21 18:29:38,597] {hive_hooks.py:130} INFO - No rows affected (1626.877 seconds)
>>>>> [2017-04-21 18:29:38,604] {hive_hooks.py:130} INFO - 0: jdbc:hive2://usw2prdpmn01:10000/dw_insight>
>>>>> [2017-04-21 18:29:38,611] {hive_hooks.py:130} INFO - 0: jdbc:hive2://usw2prdpmn01:10000/dw_insight> ANALYZE TABLE ${hiveconf:target_t
>>>>>
>>>>>
>>>>
>>>
>>
>
Re: Tez job SUCCEEDED but still containers (Map/Reducer) are running
Posted by Siddharth Seth <ss...@apache.org>.
Anandha,
If you are seeing incorrect results from Hive, I would suggest sending a
mail to user@hive.
As Ravi pointed out, containers can continue to run after a query
completes, due to how container re-use is configured.
On Sun, May 21, 2017 at 11:37 PM, Ravi Teja Chilukuri <ra...@gmail.com>
wrote:
> HI Anandha,
>
> | reducers are still running but " DAG finished successfully" and
> inserted zero records.
>
> The "containers" used by reducers can be still running even after the DAG
> has completed , due to the container re-use, they will be waiting for
> another "task" to be assigned to the same container.
> Can you please verify the task logs of the container where you see the
> reducer is still running, I think the reduce attempt would have already
> have completed and the container is waiting for a new task.
>
> If that is the case, can you verify the hive query which might be causing
> 0 records being inserted.
>
> Thanks,
> Ravi
>
> On Mon, May 22, 2017 at 11:51 AM, Anandha L Ranganathan <
> analog.sony@gmail.com> wrote:
>
>> Thanks Ravi for the information. We will udpate
>> tez.session.am.dag.submit.timeout.secs to lower value in our config.
>>
>> Our main concern is when reducers are still running but " DAG
>> finished successfully" and inserted zero records.
>>
>> [2017-04-21 18:29:38,597] {hive_hooks.py:130} INFO - INFO : Table dw_insight.d_experiment stats: [numFiles=0, numRows=0, totalSize=0, rawDataSize=0]
>>
>>
>> This resulted incorrect result set and data got corrupted.
>>
>> Thanks
>> Anand
>>
>> On Sun, May 21, 2017 at 7:18 AM, Ravi Teja Chilukuri <
>> raviorteja@gmail.com> wrote:
>>
>>> Hi Anandha,
>>>
>>> If your hive query has completed and still the containers are running,
>>> you might want to set the param: tez.session.am.dag.submit.timeout.secs
>>> to a lower value , for the yarn application to be completely shutdown.
>>> In session mode, by default the AM container waits till 5 minutes for
>>> any other queries to be fired.
>>>
>>>
>>> Thanks,
>>> Ravi
>>>
>>> On Sat, May 20, 2017 at 4:44 AM, Anandha L Ranganathan <
>>> analog.sony@gmail.com> wrote:
>>>
>>>> We hit with unique problem. Still the tez containers are running but Hive moved the file from staging location to actual location. Is this bug in the Tez engine?
>>>>
>>>> I have attached logs and you can see still Map1, Reducer3 , Reducer 4, Reducer 7 are running but DAG is SUCCEEDED.
>>>>
>>>>
>>>>
>>>> [2017-04-21 18:08:57,108] {hive_hooks.py:130} INFO - INFO : Map 1: 0(+2)/8 Map 12: 1/1 Map 5: 1/1 Map 8: 1/1 Map 9: 1/1 Reducer 11: 0/1 Reducer 3: 0/308 Reducer 4: 0/2 Reducer 7: 0/1
>>>> [2017-04-21 18:09:57,116] {hive_hooks.py:130} INFO - INFO : Map 1: 0(+2)/8 Map 12: 1/1 Map 5: 1/1 Map 8: 1/1 Map 9: 1/1 Reducer 11: 0/1 Reducer 3: 0/308 Reducer 4: 0/2 Reducer 7: 0/1
>>>> [2017-04-21 18:09:57,116] {hive_hooks.py:130} INFO - INFO : Map 1: 0(+2)/8 Map 12: 1/1 Map 5: 1/1 Map 8: 1/1 Map 9: 1/1 Reducer 11: 0/1 Reducer 3: 0/308 Reducer 4: 0/2 Reducer 7: 0/1
>>>> [2017-04-21 18:29:38,595] {hive_hooks.py:130} INFO - INFO : Map 1: 0(+2)/8 Map 12: 1/1 Map 5: 1/1 Map 8: 1/1 Map 9: 1/1 Reducer 11: 0/1 Reducer 3: 0/308 Reducer 4: 0/2 Reducer 7: 0/1
>>>> [2017-04-21 18:29:38,595] {hive_hooks.py:130} INFO - INFO :
>>>> [2017-04-21 18:29:38,596] {hive_hooks.py:130} INFO - INFO : Status: DAG finished successfully in 1560.07 seconds
>>>> [2017-04-21 18:29:38,596] {hive_hooks.py:130} INFO - INFO :
>>>> [2017-04-21 18:29:38,596] {hive_hooks.py:130} INFO -
>>>> [2017-04-21 18:29:38,596] {hive_hooks.py:130} INFO - INFO : METHOD DURATION(ms)
>>>> [2017-04-21 18:29:38,596] {hive_hooks.py:130} INFO - INFO : parse 0
>>>> [2017-04-21 18:29:38,596] {hive_hooks.py:130} INFO - INFO : semanticAnalyze 0
>>>> [2017-04-21 18:29:38,596] {hive_hooks.py:130} INFO - INFO : TezBuildDag 0
>>>> [2017-04-21 18:29:38,596] {hive_hooks.py:130} INFO - INFO : TezSubmitToRunningDag 12,957
>>>> [2017-04-21 18:29:38,597] {hive_hooks.py:130} INFO - INFO : TotalPrepTime 53,372
>>>> [2017-04-21 18:29:38,597] {hive_hooks.py:130} INFO -
>>>> [2017-04-21 18:29:38,597] {hive_hooks.py:130} INFO - INFO : Loading data to table dw_insight.d_experiment from hdfs://dfs-nameservices/data/insight/dwuser/d_experiment/.hive-staging_hive_2017-04-21_18-02-31_741_4202396962843353301-4404/-ext-10000
>>>> [2017-04-21 18:29:38,597] {hive_hooks.py:130} INFO - INFO : Table dw_insight.d_experiment stats: [numFiles=0, numRows=0, totalSize=0, rawDataSize=0]
>>>> [2017-04-21 18:29:38,597] {hive_hooks.py:130} INFO - No rows affected (1626.877 seconds)
>>>> [2017-04-21 18:29:38,604] {hive_hooks.py:130} INFO - 0: jdbc:hive2://usw2prdpmn01:10000/dw_insight>
>>>> [2017-04-21 18:29:38,611] {hive_hooks.py:130} INFO - 0: jdbc:hive2://usw2prdpmn01:10000/dw_insight> ANALYZE TABLE ${hiveconf:target_t
>>>>
>>>>
>>>
>>
>
Re: Tez job SUCCEEDED but still containers (Map/Reducer) are running
Posted by Ravi Teja Chilukuri <ra...@gmail.com>.
HI Anandha,
| reducers are still running but " DAG finished successfully" and inserted
zero records.
The "containers" used by reducers can be still running even after the DAG
has completed , due to the container re-use, they will be waiting for
another "task" to be assigned to the same container.
Can you please verify the task logs of the container where you see the
reducer is still running, I think the reduce attempt would have already
have completed and the container is waiting for a new task.
If that is the case, can you verify the hive query which might be causing 0
records being inserted.
Thanks,
Ravi
On Mon, May 22, 2017 at 11:51 AM, Anandha L Ranganathan <
analog.sony@gmail.com> wrote:
> Thanks Ravi for the information. We will udpate
> tez.session.am.dag.submit.timeout.secs to lower value in our config.
>
> Our main concern is when reducers are still running but " DAG finished
> successfully" and inserted zero records.
>
> [2017-04-21 18:29:38,597] {hive_hooks.py:130} INFO - INFO : Table dw_insight.d_experiment stats: [numFiles=0, numRows=0, totalSize=0, rawDataSize=0]
>
>
> This resulted incorrect result set and data got corrupted.
>
> Thanks
> Anand
>
> On Sun, May 21, 2017 at 7:18 AM, Ravi Teja Chilukuri <raviorteja@gmail.com
> > wrote:
>
>> Hi Anandha,
>>
>> If your hive query has completed and still the containers are running,
>> you might want to set the param: tez.session.am.dag.submit.timeout.secs
>> to a lower value , for the yarn application to be completely shutdown.
>> In session mode, by default the AM container waits till 5 minutes for any
>> other queries to be fired.
>>
>>
>> Thanks,
>> Ravi
>>
>> On Sat, May 20, 2017 at 4:44 AM, Anandha L Ranganathan <
>> analog.sony@gmail.com> wrote:
>>
>>> We hit with unique problem. Still the tez containers are running but Hive moved the file from staging location to actual location. Is this bug in the Tez engine?
>>>
>>> I have attached logs and you can see still Map1, Reducer3 , Reducer 4, Reducer 7 are running but DAG is SUCCEEDED.
>>>
>>>
>>>
>>> [2017-04-21 18:08:57,108] {hive_hooks.py:130} INFO - INFO : Map 1: 0(+2)/8 Map 12: 1/1 Map 5: 1/1 Map 8: 1/1 Map 9: 1/1 Reducer 11: 0/1 Reducer 3: 0/308 Reducer 4: 0/2 Reducer 7: 0/1
>>> [2017-04-21 18:09:57,116] {hive_hooks.py:130} INFO - INFO : Map 1: 0(+2)/8 Map 12: 1/1 Map 5: 1/1 Map 8: 1/1 Map 9: 1/1 Reducer 11: 0/1 Reducer 3: 0/308 Reducer 4: 0/2 Reducer 7: 0/1
>>> [2017-04-21 18:09:57,116] {hive_hooks.py:130} INFO - INFO : Map 1: 0(+2)/8 Map 12: 1/1 Map 5: 1/1 Map 8: 1/1 Map 9: 1/1 Reducer 11: 0/1 Reducer 3: 0/308 Reducer 4: 0/2 Reducer 7: 0/1
>>> [2017-04-21 18:29:38,595] {hive_hooks.py:130} INFO - INFO : Map 1: 0(+2)/8 Map 12: 1/1 Map 5: 1/1 Map 8: 1/1 Map 9: 1/1 Reducer 11: 0/1 Reducer 3: 0/308 Reducer 4: 0/2 Reducer 7: 0/1
>>> [2017-04-21 18:29:38,595] {hive_hooks.py:130} INFO - INFO :
>>> [2017-04-21 18:29:38,596] {hive_hooks.py:130} INFO - INFO : Status: DAG finished successfully in 1560.07 seconds
>>> [2017-04-21 18:29:38,596] {hive_hooks.py:130} INFO - INFO :
>>> [2017-04-21 18:29:38,596] {hive_hooks.py:130} INFO -
>>> [2017-04-21 18:29:38,596] {hive_hooks.py:130} INFO - INFO : METHOD DURATION(ms)
>>> [2017-04-21 18:29:38,596] {hive_hooks.py:130} INFO - INFO : parse 0
>>> [2017-04-21 18:29:38,596] {hive_hooks.py:130} INFO - INFO : semanticAnalyze 0
>>> [2017-04-21 18:29:38,596] {hive_hooks.py:130} INFO - INFO : TezBuildDag 0
>>> [2017-04-21 18:29:38,596] {hive_hooks.py:130} INFO - INFO : TezSubmitToRunningDag 12,957
>>> [2017-04-21 18:29:38,597] {hive_hooks.py:130} INFO - INFO : TotalPrepTime 53,372
>>> [2017-04-21 18:29:38,597] {hive_hooks.py:130} INFO -
>>> [2017-04-21 18:29:38,597] {hive_hooks.py:130} INFO - INFO : Loading data to table dw_insight.d_experiment from hdfs://dfs-nameservices/data/insight/dwuser/d_experiment/.hive-staging_hive_2017-04-21_18-02-31_741_4202396962843353301-4404/-ext-10000
>>> [2017-04-21 18:29:38,597] {hive_hooks.py:130} INFO - INFO : Table dw_insight.d_experiment stats: [numFiles=0, numRows=0, totalSize=0, rawDataSize=0]
>>> [2017-04-21 18:29:38,597] {hive_hooks.py:130} INFO - No rows affected (1626.877 seconds)
>>> [2017-04-21 18:29:38,604] {hive_hooks.py:130} INFO - 0: jdbc:hive2://usw2prdpmn01:10000/dw_insight>
>>> [2017-04-21 18:29:38,611] {hive_hooks.py:130} INFO - 0: jdbc:hive2://usw2prdpmn01:10000/dw_insight> ANALYZE TABLE ${hiveconf:target_t
>>>
>>>
>>
>
Re: Tez job SUCCEEDED but still containers (Map/Reducer) are running
Posted by Anandha L Ranganathan <an...@gmail.com>.
Thanks Ravi for the information. We will udpate
tez.session.am.dag.submit.timeout.secs
to lower value in our config.
Our main concern is when reducers are still running but " DAG finished
successfully" and inserted zero records.
[2017-04-21 18:29:38,597] {hive_hooks.py:130} INFO - INFO : Table
dw_insight.d_experiment stats: [numFiles=0, numRows=0, totalSize=0,
rawDataSize=0]
This resulted incorrect result set and data got corrupted.
Thanks
Anand
On Sun, May 21, 2017 at 7:18 AM, Ravi Teja Chilukuri <ra...@gmail.com>
wrote:
> Hi Anandha,
>
> If your hive query has completed and still the containers are running, you
> might want to set the param: tez.session.am.dag.submit.timeout.secs to a
> lower value , for the yarn application to be completely shutdown.
> In session mode, by default the AM container waits till 5 minutes for any
> other queries to be fired.
>
>
> Thanks,
> Ravi
>
> On Sat, May 20, 2017 at 4:44 AM, Anandha L Ranganathan <
> analog.sony@gmail.com> wrote:
>
>> We hit with unique problem. Still the tez containers are running but Hive moved the file from staging location to actual location. Is this bug in the Tez engine?
>>
>> I have attached logs and you can see still Map1, Reducer3 , Reducer 4, Reducer 7 are running but DAG is SUCCEEDED.
>>
>>
>>
>> [2017-04-21 18:08:57,108] {hive_hooks.py:130} INFO - INFO : Map 1: 0(+2)/8 Map 12: 1/1 Map 5: 1/1 Map 8: 1/1 Map 9: 1/1 Reducer 11: 0/1 Reducer 3: 0/308 Reducer 4: 0/2 Reducer 7: 0/1
>> [2017-04-21 18:09:57,116] {hive_hooks.py:130} INFO - INFO : Map 1: 0(+2)/8 Map 12: 1/1 Map 5: 1/1 Map 8: 1/1 Map 9: 1/1 Reducer 11: 0/1 Reducer 3: 0/308 Reducer 4: 0/2 Reducer 7: 0/1
>> [2017-04-21 18:09:57,116] {hive_hooks.py:130} INFO - INFO : Map 1: 0(+2)/8 Map 12: 1/1 Map 5: 1/1 Map 8: 1/1 Map 9: 1/1 Reducer 11: 0/1 Reducer 3: 0/308 Reducer 4: 0/2 Reducer 7: 0/1
>> [2017-04-21 18:29:38,595] {hive_hooks.py:130} INFO - INFO : Map 1: 0(+2)/8 Map 12: 1/1 Map 5: 1/1 Map 8: 1/1 Map 9: 1/1 Reducer 11: 0/1 Reducer 3: 0/308 Reducer 4: 0/2 Reducer 7: 0/1
>> [2017-04-21 18:29:38,595] {hive_hooks.py:130} INFO - INFO :
>> [2017-04-21 18:29:38,596] {hive_hooks.py:130} INFO - INFO : Status: DAG finished successfully in 1560.07 seconds
>> [2017-04-21 18:29:38,596] {hive_hooks.py:130} INFO - INFO :
>> [2017-04-21 18:29:38,596] {hive_hooks.py:130} INFO -
>> [2017-04-21 18:29:38,596] {hive_hooks.py:130} INFO - INFO : METHOD DURATION(ms)
>> [2017-04-21 18:29:38,596] {hive_hooks.py:130} INFO - INFO : parse 0
>> [2017-04-21 18:29:38,596] {hive_hooks.py:130} INFO - INFO : semanticAnalyze 0
>> [2017-04-21 18:29:38,596] {hive_hooks.py:130} INFO - INFO : TezBuildDag 0
>> [2017-04-21 18:29:38,596] {hive_hooks.py:130} INFO - INFO : TezSubmitToRunningDag 12,957
>> [2017-04-21 18:29:38,597] {hive_hooks.py:130} INFO - INFO : TotalPrepTime 53,372
>> [2017-04-21 18:29:38,597] {hive_hooks.py:130} INFO -
>> [2017-04-21 18:29:38,597] {hive_hooks.py:130} INFO - INFO : Loading data to table dw_insight.d_experiment from hdfs://dfs-nameservices/data/insight/dwuser/d_experiment/.hive-staging_hive_2017-04-21_18-02-31_741_4202396962843353301-4404/-ext-10000
>> [2017-04-21 18:29:38,597] {hive_hooks.py:130} INFO - INFO : Table dw_insight.d_experiment stats: [numFiles=0, numRows=0, totalSize=0, rawDataSize=0]
>> [2017-04-21 18:29:38,597] {hive_hooks.py:130} INFO - No rows affected (1626.877 seconds)
>> [2017-04-21 18:29:38,604] {hive_hooks.py:130} INFO - 0: jdbc:hive2://usw2prdpmn01:10000/dw_insight>
>> [2017-04-21 18:29:38,611] {hive_hooks.py:130} INFO - 0: jdbc:hive2://usw2prdpmn01:10000/dw_insight> ANALYZE TABLE ${hiveconf:target_t
>>
>>
>
Re: Tez job SUCCEEDED but still containers (Map/Reducer) are running
Posted by Ravi Teja Chilukuri <ra...@gmail.com>.
Hi Anandha,
If your hive query has completed and still the containers are running, you
might want to set the param: tez.session.am.dag.submit.timeout.secs to a
lower value , for the yarn application to be completely shutdown.
In session mode, by default the AM container waits till 5 minutes for any
other queries to be fired.
Thanks,
Ravi
On Sat, May 20, 2017 at 4:44 AM, Anandha L Ranganathan <
analog.sony@gmail.com> wrote:
> We hit with unique problem. Still the tez containers are running but Hive moved the file from staging location to actual location. Is this bug in the Tez engine?
>
> I have attached logs and you can see still Map1, Reducer3 , Reducer 4, Reducer 7 are running but DAG is SUCCEEDED.
>
>
>
> [2017-04-21 18:08:57,108] {hive_hooks.py:130} INFO - INFO : Map 1: 0(+2)/8 Map 12: 1/1 Map 5: 1/1 Map 8: 1/1 Map 9: 1/1 Reducer 11: 0/1 Reducer 3: 0/308 Reducer 4: 0/2 Reducer 7: 0/1
> [2017-04-21 18:09:57,116] {hive_hooks.py:130} INFO - INFO : Map 1: 0(+2)/8 Map 12: 1/1 Map 5: 1/1 Map 8: 1/1 Map 9: 1/1 Reducer 11: 0/1 Reducer 3: 0/308 Reducer 4: 0/2 Reducer 7: 0/1
> [2017-04-21 18:09:57,116] {hive_hooks.py:130} INFO - INFO : Map 1: 0(+2)/8 Map 12: 1/1 Map 5: 1/1 Map 8: 1/1 Map 9: 1/1 Reducer 11: 0/1 Reducer 3: 0/308 Reducer 4: 0/2 Reducer 7: 0/1
> [2017-04-21 18:29:38,595] {hive_hooks.py:130} INFO - INFO : Map 1: 0(+2)/8 Map 12: 1/1 Map 5: 1/1 Map 8: 1/1 Map 9: 1/1 Reducer 11: 0/1 Reducer 3: 0/308 Reducer 4: 0/2 Reducer 7: 0/1
> [2017-04-21 18:29:38,595] {hive_hooks.py:130} INFO - INFO :
> [2017-04-21 18:29:38,596] {hive_hooks.py:130} INFO - INFO : Status: DAG finished successfully in 1560.07 seconds
> [2017-04-21 18:29:38,596] {hive_hooks.py:130} INFO - INFO :
> [2017-04-21 18:29:38,596] {hive_hooks.py:130} INFO -
> [2017-04-21 18:29:38,596] {hive_hooks.py:130} INFO - INFO : METHOD DURATION(ms)
> [2017-04-21 18:29:38,596] {hive_hooks.py:130} INFO - INFO : parse 0
> [2017-04-21 18:29:38,596] {hive_hooks.py:130} INFO - INFO : semanticAnalyze 0
> [2017-04-21 18:29:38,596] {hive_hooks.py:130} INFO - INFO : TezBuildDag 0
> [2017-04-21 18:29:38,596] {hive_hooks.py:130} INFO - INFO : TezSubmitToRunningDag 12,957
> [2017-04-21 18:29:38,597] {hive_hooks.py:130} INFO - INFO : TotalPrepTime 53,372
> [2017-04-21 18:29:38,597] {hive_hooks.py:130} INFO -
> [2017-04-21 18:29:38,597] {hive_hooks.py:130} INFO - INFO : Loading data to table dw_insight.d_experiment from hdfs://dfs-nameservices/data/insight/dwuser/d_experiment/.hive-staging_hive_2017-04-21_18-02-31_741_4202396962843353301-4404/-ext-10000
> [2017-04-21 18:29:38,597] {hive_hooks.py:130} INFO - INFO : Table dw_insight.d_experiment stats: [numFiles=0, numRows=0, totalSize=0, rawDataSize=0]
> [2017-04-21 18:29:38,597] {hive_hooks.py:130} INFO - No rows affected (1626.877 seconds)
> [2017-04-21 18:29:38,604] {hive_hooks.py:130} INFO - 0: jdbc:hive2://usw2prdpmn01:10000/dw_insight>
> [2017-04-21 18:29:38,611] {hive_hooks.py:130} INFO - 0: jdbc:hive2://usw2prdpmn01:10000/dw_insight> ANALYZE TABLE ${hiveconf:target_t
>
>