hadoop-mapreduce-user mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From wd ...@wdicc.com>
Subject Re: some map run really slow
Date Sat, 13 Aug 2011 05:14:53 GMT
Thanks, the io.sort.mb is 200M here, I'll do more test on it.

On Fri, Aug 12, 2011 at 8:47 PM, Florin P <florinpico@yahoo.com> wrote:
> Hello!
>  We've encountered some slow map process when sending large amounts of data from the
mapper process to the reducer process. The output of the map process will be first written
into a buffer whose size is given by the
> io.sort.mb property defined in core-site.xml. Its default value is 100. Here is its explanation:
> io.sort.mb-->"The total amount of buffer memory to use while sorting files, in megabytes.
By default, gives each merge stream 1MB, which should minimize seeks".
>  The problem is that when this buffer is full, then a process named "spill" will write
the its content to your harddisk. Then, a copy phase will take output from the harddisk+buffer
to the the reducer machine (via HTTP) where again it is written to a buffer and when that
buffer is full then it will be flushed to harddriver.
>  Bottom line, the more map output data you have the more IO operations you'll encounter.
So that it was in mour case.
>  I hope that this help.
> Regards,
>  Florin
>
>
> --- On Fri, 8/12/11, wd <wd@wdicc.com> wrote:
>
>> From: wd <wd@wdicc.com>
>> Subject: Re: some map run really slow
>> To: mapreduce-user@hadoop.apache.org
>> Date: Friday, August 12, 2011, 6:26 AM
>> yes, there is a reduce. In fact, I'm
>> using hive to run map reduce
>> jobs, and the reducer is a perl script.
>>
>> The data send to reducer is about 1/3 or 1/4 of map input
>> data.
>>
>> On Fri, Aug 12, 2011 at 5:26 PM, Florin P <florinpico@yahoo.com>
>> wrote:
>> > Hello!
>> >  Di you have a reducer class involved? If yes, what
>> is the amount of data that you are sending from the mapper
>> to the reducer?
>> > Regards,
>> > Florin
>> >
>> > --- On Fri, 8/12/11, wd <wd@wdicc.com>
>> wrote:
>> >
>> >> From: wd <wd@wdicc.com>
>> >> Subject: some map run really slow
>> >> To: mapreduce-user@hadoop.apache.org
>> >> Date: Friday, August 12, 2011, 4:14 AM
>> >> hi,
>> >> Here is the log for map run in one map/reduce.
>> >>
>> >> map1, run 1mins, 2sec, and processed 48572 rows
>> >>
>> >> 2011-08-12 01:34:28,313 INFO
>> >> org.apache.hadoop.hive.ql.exec.MapOperator:
>> Initializing
>> >> Self 10 MAP
>> >> 2011-08-12 01:34:28,313 INFO
>> >> org.apache.hadoop.hive.ql.exec.TableScanOperator:
>> >> Initializing Self 0
>> >> TS
>> >> 2011-08-12 01:34:28,313 INFO
>> >> org.apache.hadoop.hive.ql.exec.TableScanOperator:
>> Operator
>> >> 0 TS
>> >> initialized
>> >> 2011-08-12 01:34:28,313 INFO
>> >> org.apache.hadoop.hive.ql.exec.TableScanOperator:
>> >> Initializing
>> >> children of 0 TS
>> >> 2011-08-12 01:34:28,313 INFO
>> >> org.apache.hadoop.hive.ql.exec.FilterOperator:
>> Initializing
>> >> child 1
>> >> FIL
>> >> 2011-08-12 01:34:28,313 INFO
>> >> org.apache.hadoop.hive.ql.exec.FilterOperator:
>> Initializing
>> >> Self 1 FIL
>> >> 2011-08-12 01:34:28,318 INFO
>> >> org.apache.hadoop.hive.ql.exec.FilterOperator:
>> Operator 1
>> >> FIL
>> >> initialized
>> >> 2011-08-12 01:34:28,318 INFO
>> >> org.apache.hadoop.hive.ql.exec.FilterOperator:
>> Initializing
>> >> children
>> >> of 1 FIL
>> >> 2011-08-12 01:34:28,318 INFO
>> >> org.apache.hadoop.hive.ql.exec.FilterOperator:
>> Initializing
>> >> child 2
>> >> FIL
>> >> 2011-08-12 01:34:28,318 INFO
>> >> org.apache.hadoop.hive.ql.exec.FilterOperator:
>> Initializing
>> >> Self 2 FIL
>> >> 2011-08-12 01:34:28,318 INFO
>> >> org.apache.hadoop.hive.ql.exec.FilterOperator:
>> Operator 2
>> >> FIL
>> >> initialized
>> >> 2011-08-12 01:34:28,318 INFO
>> >> org.apache.hadoop.hive.ql.exec.FilterOperator:
>> Initializing
>> >> children
>> >> of 2 FIL
>> >> 2011-08-12 01:34:28,318 INFO
>> >> org.apache.hadoop.hive.ql.exec.SelectOperator:
>> Initializing
>> >> child 3
>> >> SEL
>> >> 2011-08-12 01:34:28,318 INFO
>> >> org.apache.hadoop.hive.ql.exec.SelectOperator:
>> Initializing
>> >> Self 3 SEL
>> >> 2011-08-12 01:34:28,407 INFO
>> >> org.apache.hadoop.hive.ql.exec.SelectOperator:
>> Operator 3
>> >> SEL
>> >> initialized
>> >> 2011-08-12 01:34:28,407 INFO
>> >> org.apache.hadoop.hive.ql.exec.SelectOperator:
>> Initializing
>> >> children
>> >> of 3 SEL
>> >> 2011-08-12 01:34:28,407 INFO
>> >>
>> org.apache.hadoop.hive.ql.exec.ReduceSinkOperator:
>> >> Initializing child
>> >> 4 RS
>> >> 2011-08-12 01:34:28,407 INFO
>> >>
>> org.apache.hadoop.hive.ql.exec.ReduceSinkOperator:
>> >> Initializing Self 4
>> >> RS
>> >> 2011-08-12 01:34:28,408 INFO
>> >> org.apache.hadoop.hive.ql.exec.ReduceSinkOperator:
>> Using
>> >> tag = -1
>> >> 2011-08-12 01:34:28,420 INFO
>> >> org.apache.hadoop.hive.ql.exec.ReduceSinkOperator:
>> Operator
>> >> 4 RS
>> >> initialized
>> >> 2011-08-12 01:34:28,420 INFO
>> >>
>> org.apache.hadoop.hive.ql.exec.ReduceSinkOperator:
>> >> Initialization Done
>> >> 4 RS
>> >> 2011-08-12 01:34:28,420 INFO
>> >> org.apache.hadoop.hive.ql.exec.SelectOperator:
>> >> Initialization Done 3
>> >> SEL
>> >> 2011-08-12 01:34:28,420 INFO
>> >> org.apache.hadoop.hive.ql.exec.FilterOperator:
>> >> Initialization Done 2
>> >> FIL
>> >> 2011-08-12 01:34:28,420 INFO
>> >> org.apache.hadoop.hive.ql.exec.FilterOperator:
>> >> Initialization Done 1
>> >> FIL
>> >> 2011-08-12 01:34:28,420 INFO
>> >> org.apache.hadoop.hive.ql.exec.TableScanOperator:
>> >> Initialization Done
>> >> 0 TS
>> >> 2011-08-12 01:34:28,420 INFO
>> >> org.apache.hadoop.hive.ql.exec.MapOperator:
>> Initialization
>> >> Done 10 MAP
>> >> 2011-08-12 01:34:28,423 INFO
>> >> org.apache.hadoop.hive.ql.exec.MapOperator:
>> Processing
>> >> path
>> >>
>> hdfs://l-etl1.s.cn5:9000/user/hive/warehouse/beacon_logs/dt=20110811/tmp_b.20110811
>> >> 2011-08-12 01:34:28,423 INFO
>> >> org.apache.hadoop.hive.ql.exec.MapOperator:
>> Processing
>> >> alias
>> >> m:test_logs for file
>> >>
>> hdfs://test1:9000/user/hive/warehouse/test_logs/dt=20110811
>> >> 2011-08-12 01:34:28,424 INFO
>> >> org.apache.hadoop.hive.ql.exec.MapOperator: 10
>> forwarding 1
>> >> rows
>> >> 2011-08-12 01:34:28,424 INFO
>> >> org.apache.hadoop.hive.ql.exec.TableScanOperator:
>> 0
>> >> forwarding 1 rows
>> >> 2011-08-12 01:34:28,427 INFO
>> >> org.apache.hadoop.hive.ql.exec.FilterOperator: 1
>> forwarding
>> >> 1 rows
>> >> 2011-08-12 01:34:28,427 INFO
>> >> org.apache.hadoop.hive.ql.exec.FilterOperator: 2
>> forwarding
>> >> 1 rows
>> >> 2011-08-12 01:34:28,430 INFO
>> >> org.apache.hadoop.hive.ql.exec.SelectOperator: 3
>> forwarding
>> >> 1 rows
>> >> 2011-08-12 01:34:28,432 INFO ExecMapper:
>> ExecMapper:
>> >> processing 1
>> >> rows: used memory = 217548568
>> >> 2011-08-12 01:34:28,440 INFO
>> >> org.apache.hadoop.hive.ql.exec.MapOperator: 10
>> forwarding
>> >> 10 rows
>> >> 2011-08-12 01:34:28,440 INFO
>> >> org.apache.hadoop.hive.ql.exec.TableScanOperator:
>> 0
>> >> forwarding 10 rows
>> >> 2011-08-12 01:34:28,441 INFO ExecMapper:
>> ExecMapper:
>> >> processing 10
>> >> rows: used memory = 217760328
>> >> 2011-08-12 01:34:28,443 INFO
>> >> org.apache.hadoop.hive.ql.exec.FilterOperator: 1
>> forwarding
>> >> 10 rows
>> >> 2011-08-12 01:34:28,443 INFO
>> >> org.apache.hadoop.hive.ql.exec.FilterOperator: 2
>> forwarding
>> >> 10 rows
>> >> 2011-08-12 01:34:28,444 INFO
>> >> org.apache.hadoop.hive.ql.exec.SelectOperator: 3
>> forwarding
>> >> 10 rows
>> >> 2011-08-12 01:34:28,486 INFO
>> >> org.apache.hadoop.hive.ql.exec.MapOperator: 10
>> forwarding
>> >> 100 rows
>> >> 2011-08-12 01:34:28,487 INFO
>> >> org.apache.hadoop.hive.ql.exec.TableScanOperator:
>> 0
>> >> forwarding 100
>> >> rows
>> >> 2011-08-12 01:34:28,487 INFO ExecMapper:
>> ExecMapper:
>> >> processing 100
>> >> rows: used memory = 218813320
>> >> 2011-08-12 01:34:28,499 INFO
>> >> org.apache.hadoop.hive.ql.exec.FilterOperator: 1
>> forwarding
>> >> 100 rows
>> >> 2011-08-12 01:34:28,499 INFO
>> >> org.apache.hadoop.hive.ql.exec.FilterOperator: 2
>> forwarding
>> >> 100 rows
>> >> 2011-08-12 01:34:28,499 INFO
>> >> org.apache.hadoop.hive.ql.exec.SelectOperator: 3
>> forwarding
>> >> 100 rows
>> >> 2011-08-12 01:34:30,451 INFO
>> >> org.apache.hadoop.hive.ql.exec.MapOperator: 10
>> forwarding
>> >> 1000 rows
>> >> 2011-08-12 01:34:30,451 INFO
>> >> org.apache.hadoop.hive.ql.exec.TableScanOperator:
>> 0
>> >> forwarding 1000
>> >> rows
>> >> 2011-08-12 01:34:30,451 INFO ExecMapper:
>> ExecMapper:
>> >> processing 1000
>> >> rows: used memory = 216809296
>> >> 2011-08-12 01:34:31,050 INFO
>> >> org.apache.hadoop.hive.ql.exec.FilterOperator: 1
>> forwarding
>> >> 1000 rows
>> >> 2011-08-12 01:34:31,050 INFO
>> >> org.apache.hadoop.hive.ql.exec.FilterOperator: 2
>> forwarding
>> >> 1000 rows
>> >> 2011-08-12 01:34:31,050 INFO
>> >> org.apache.hadoop.hive.ql.exec.SelectOperator: 3
>> forwarding
>> >> 1000 rows
>> >> 2011-08-12 01:34:52,125 INFO
>> >> org.apache.hadoop.hive.ql.exec.MapOperator: 10
>> forwarding
>> >> 10000 rows
>> >> 2011-08-12 01:34:52,125 INFO
>> >> org.apache.hadoop.hive.ql.exec.TableScanOperator:
>> 0
>> >> forwarding 10000
>> >> rows
>> >> 2011-08-12 01:34:52,125 INFO ExecMapper:
>> ExecMapper:
>> >> processing 10000
>> >> rows: used memory = 216713344
>> >> 2011-08-12 01:34:55,876 INFO
>> >> org.apache.hadoop.hive.ql.exec.FilterOperator: 1
>> forwarding
>> >> 10000 rows
>> >> 2011-08-12 01:34:55,876 INFO
>> >> org.apache.hadoop.hive.ql.exec.FilterOperator: 2
>> forwarding
>> >> 10000 rows
>> >> 2011-08-12 01:34:55,876 INFO
>> >> org.apache.hadoop.hive.ql.exec.SelectOperator: 3
>> forwarding
>> >> 10000 rows
>> >> 2011-08-12 01:35:28,859 INFO
>> >> org.apache.hadoop.hive.ql.exec.MapOperator: 10
>> finished.
>> >> closing...
>> >> 2011-08-12 01:35:28,859 INFO
>> >> org.apache.hadoop.hive.ql.exec.MapOperator: 10
>> forwarded
>> >> 48572 rows
>> >> 2011-08-12 01:35:28,859 INFO
>> >> org.apache.hadoop.hive.ql.exec.MapOperator:
>> >> DESERIALIZE_ERRORS:0
>> >> 2011-08-12 01:35:28,859 INFO
>> >> org.apache.hadoop.hive.ql.exec.TableScanOperator:
>> 0
>> >> finished.
>> >> closing...
>> >> 2011-08-12 01:35:28,859 INFO
>> >> org.apache.hadoop.hive.ql.exec.TableScanOperator:
>> 0
>> >> forwarded 48572
>> >> rows
>> >> 2011-08-12 01:35:28,859 INFO
>> >> org.apache.hadoop.hive.ql.exec.FilterOperator: 1
>> finished.
>> >> closing...
>> >> 2011-08-12 01:35:28,859 INFO
>> >> org.apache.hadoop.hive.ql.exec.FilterOperator: 1
>> forwarded
>> >> 37222 rows
>> >> 2011-08-12 01:35:28,859 INFO
>> >> org.apache.hadoop.hive.ql.exec.FilterOperator:
>> >> PASSED:37222
>> >> 2011-08-12 01:35:28,859 INFO
>> >> org.apache.hadoop.hive.ql.exec.FilterOperator:
>> >> FILTERED:11350
>> >> 2011-08-12 01:35:28,859 INFO
>> >> org.apache.hadoop.hive.ql.exec.FilterOperator: 2
>> finished.
>> >> closing...
>> >> 2011-08-12 01:35:28,859 INFO
>> >> org.apache.hadoop.hive.ql.exec.FilterOperator: 2
>> forwarded
>> >> 37222 rows
>> >> 2011-08-12 01:35:28,859 INFO
>> >> org.apache.hadoop.hive.ql.exec.FilterOperator:
>> >> PASSED:37222
>> >> 2011-08-12 01:35:28,859 INFO
>> >> org.apache.hadoop.hive.ql.exec.FilterOperator:
>> FILTERED:0
>> >> 2011-08-12 01:35:28,859 INFO
>> >> org.apache.hadoop.hive.ql.exec.SelectOperator: 3
>> finished.
>> >> closing...
>> >> 2011-08-12 01:35:28,860 INFO
>> >> org.apache.hadoop.hive.ql.exec.SelectOperator: 3
>> forwarded
>> >> 37222 rows
>> >> 2011-08-12 01:35:28,860 INFO
>> >> org.apache.hadoop.hive.ql.exec.ReduceSinkOperator:
>> 4
>> >> finished.
>> >> closing...
>> >> 2011-08-12 01:35:28,860 INFO
>> >> org.apache.hadoop.hive.ql.exec.ReduceSinkOperator:
>> 4
>> >> forwarded 0 rows
>> >> 2011-08-12 01:35:28,860 INFO
>> >> org.apache.hadoop.hive.ql.exec.SelectOperator: 3
>> Close
>> >> done
>> >> 2011-08-12 01:35:28,860 INFO
>> >> org.apache.hadoop.hive.ql.exec.FilterOperator: 2
>> Close
>> >> done
>> >> 2011-08-12 01:35:28,860 INFO
>> >> org.apache.hadoop.hive.ql.exec.FilterOperator: 1
>> Close
>> >> done
>> >> 2011-08-12 01:35:28,860 INFO
>> >> org.apache.hadoop.hive.ql.exec.TableScanOperator:
>> 0 Close
>> >> done
>> >> 2011-08-12 01:35:28,860 INFO
>> >> org.apache.hadoop.hive.ql.exec.MapOperator: 10
>> Close done
>> >> 2011-08-12 01:35:28,860 INFO ExecMapper:
>> ExecMapper:
>> >> processed 48572
>> >> rows: used memory = 245403616
>> >> 2011-08-12 01:35:28,864 INFO
>> >> org.apache.hadoop.mapred.MapTask:
>> >> Starting flush of map output
>> >> 2011-08-12 01:35:29,094 INFO
>> >> org.apache.hadoop.mapred.MapTask: Finished spill
>> 0
>> >> 2011-08-12 01:35:29,097 INFO
>> >> org.apache.hadoop.mapred.TaskRunner:
>> >> Task:attempt_201108111828_0008_m_000126_0 is done.
>> And is
>> >> in the
>> >> process of commiting
>> >> 2011-08-12 01:35:29,100 INFO
>> >> org.apache.hadoop.mapred.TaskRunner: Task
>> >> 'attempt_201108111828_0008_m_000126_0' done.
>> >>
>> >>
>> >> map2, run 7sec, processed 81078 rows
>> >>
>> >> 2011-08-12 01:34:32,160 INFO
>> >> org.apache.hadoop.hive.ql.exec.MapOperator:
>> Initializing
>> >> Self 10 MAP
>> >> 2011-08-12 01:34:32,160 INFO
>> >> org.apache.hadoop.hive.ql.exec.TableScanOperator:
>> >> Initializing Self 0
>> >> TS
>> >> 2011-08-12 01:34:32,160 INFO
>> >> org.apache.hadoop.hive.ql.exec.TableScanOperator:
>> Operator
>> >> 0 TS
>> >> initialized
>> >> 2011-08-12 01:34:32,160 INFO
>> >> org.apache.hadoop.hive.ql.exec.TableScanOperator:
>> >> Initializing
>> >> children of 0 TS
>> >> 2011-08-12 01:34:32,160 INFO
>> >> org.apache.hadoop.hive.ql.exec.FilterOperator:
>> Initializing
>> >> child 1
>> >> FIL
>> >> 2011-08-12 01:34:32,160 INFO
>> >> org.apache.hadoop.hive.ql.exec.FilterOperator:
>> Initializing
>> >> Self 1 FIL
>> >> 2011-08-12 01:34:32,166 INFO
>> >> org.apache.hadoop.hive.ql.exec.FilterOperator:
>> Operator 1
>> >> FIL
>> >> initialized
>> >> 2011-08-12 01:34:32,166 INFO
>> >> org.apache.hadoop.hive.ql.exec.FilterOperator:
>> Initializing
>> >> children
>> >> of 1 FIL
>> >> 2011-08-12 01:34:32,166 INFO
>> >> org.apache.hadoop.hive.ql.exec.FilterOperator:
>> Initializing
>> >> child 2
>> >> FIL
>> >> 2011-08-12 01:34:32,166 INFO
>> >> org.apache.hadoop.hive.ql.exec.FilterOperator:
>> Initializing
>> >> Self 2 FIL
>> >> 2011-08-12 01:34:32,166 INFO
>> >> org.apache.hadoop.hive.ql.exec.FilterOperator:
>> Operator 2
>> >> FIL
>> >> initialized
>> >> 2011-08-12 01:34:32,166 INFO
>> >> org.apache.hadoop.hive.ql.exec.FilterOperator:
>> Initializing
>> >> children
>> >> of 2 FIL
>> >> 2011-08-12 01:34:32,166 INFO
>> >> org.apache.hadoop.hive.ql.exec.SelectOperator:
>> Initializing
>> >> child 3
>> >> SEL
>> >> 2011-08-12 01:34:32,166 INFO
>> >> org.apache.hadoop.hive.ql.exec.SelectOperator:
>> Initializing
>> >> Self 3 SEL
>> >> 2011-08-12 01:34:32,286 INFO
>> >> org.apache.hadoop.hive.ql.exec.SelectOperator:
>> Operator 3
>> >> SEL
>> >> initialized
>> >> 2011-08-12 01:34:32,286 INFO
>> >> org.apache.hadoop.hive.ql.exec.SelectOperator:
>> Initializing
>> >> children
>> >> of 3 SEL
>> >> 2011-08-12 01:34:32,286 INFO
>> >>
>> org.apache.hadoop.hive.ql.exec.ReduceSinkOperator:
>> >> Initializing child
>> >> 4 RS
>> >> 2011-08-12 01:34:32,286 INFO
>> >>
>> org.apache.hadoop.hive.ql.exec.ReduceSinkOperator:
>> >> Initializing Self 4
>> >> RS
>> >> 2011-08-12 01:34:32,286 INFO
>> >> org.apache.hadoop.hive.ql.exec.ReduceSinkOperator:
>> Using
>> >> tag = -1
>> >> 2011-08-12 01:34:32,302 INFO
>> >> org.apache.hadoop.hive.ql.exec.ReduceSinkOperator:
>> Operator
>> >> 4 RS
>> >> initialized
>> >> 2011-08-12 01:34:32,302 INFO
>> >>
>> org.apache.hadoop.hive.ql.exec.ReduceSinkOperator:
>> >> Initialization Done
>> >> 4 RS
>> >> 2011-08-12 01:34:32,302 INFO
>> >> org.apache.hadoop.hive.ql.exec.SelectOperator:
>> >> Initialization Done 3
>> >> SEL
>> >> 2011-08-12 01:34:32,302 INFO
>> >> org.apache.hadoop.hive.ql.exec.FilterOperator:
>> >> Initialization Done 2
>> >> FIL
>> >> 2011-08-12 01:34:32,302 INFO
>> >> org.apache.hadoop.hive.ql.exec.FilterOperator:
>> >> Initialization Done 1
>> >> FIL
>> >> 2011-08-12 01:34:32,302 INFO
>> >> org.apache.hadoop.hive.ql.exec.TableScanOperator:
>> >> Initialization Done
>> >> 0 TS
>> >> 2011-08-12 01:34:32,302 INFO
>> >> org.apache.hadoop.hive.ql.exec.MapOperator:
>> Initialization
>> >> Done 10 MAP
>> >> 2011-08-12 01:34:32,305 INFO
>> >> org.apache.hadoop.hive.ql.exec.MapOperator:
>> Processing
>> >> path
>> >>
>> hdfs://test1:9000/user/hive/warehouse/test_logs/dt=20110811/tmp_b.20110811
>> >> 2011-08-12 01:34:32,306 INFO
>> >> org.apache.hadoop.hive.ql.exec.MapOperator:
>> Processing
>> >> alias
>> >> m:test_logs for file
>> >>
>> hdfs://l-etl1.s.cn5:9000/user/hive/warehouse/test_logs/dt=20110811
>> >> 2011-08-12 01:34:32,307 INFO
>> >> org.apache.hadoop.hive.ql.exec.MapOperator: 10
>> forwarding 1
>> >> rows
>> >> 2011-08-12 01:34:32,307 INFO
>> >> org.apache.hadoop.hive.ql.exec.TableScanOperator:
>> 0
>> >> forwarding 1 rows
>> >> 2011-08-12 01:34:32,311 INFO ExecMapper:
>> ExecMapper:
>> >> processing 1
>> >> rows: used memory = 280854088
>> >> 2011-08-12 01:34:32,313 INFO
>> >> org.apache.hadoop.hive.ql.exec.MapOperator: 10
>> forwarding
>> >> 10 rows
>> >> 2011-08-12 01:34:32,313 INFO
>> >> org.apache.hadoop.hive.ql.exec.TableScanOperator:
>> 0
>> >> forwarding 10 rows
>> >> 2011-08-12 01:34:32,314 INFO ExecMapper:
>> ExecMapper:
>> >> processing 10
>> >> rows: used memory = 280854088
>> >> 2011-08-12 01:34:32,335 INFO
>> >> org.apache.hadoop.hive.ql.exec.MapOperator: 10
>> forwarding
>> >> 100 rows
>> >> 2011-08-12 01:34:32,335 INFO
>> >> org.apache.hadoop.hive.ql.exec.TableScanOperator:
>> 0
>> >> forwarding 100
>> >> rows
>> >> 2011-08-12 01:34:32,335 INFO ExecMapper:
>> ExecMapper:
>> >> processing 100
>> >> rows: used memory = 280854088
>> >> 2011-08-12 01:34:32,416 INFO
>> >> org.apache.hadoop.hive.ql.exec.MapOperator: 10
>> forwarding
>> >> 1000 rows
>> >> 2011-08-12 01:34:32,416 INFO
>> >> org.apache.hadoop.hive.ql.exec.TableScanOperator:
>> 0
>> >> forwarding 1000
>> >> rows
>> >> 2011-08-12 01:34:32,416 INFO ExecMapper:
>> ExecMapper:
>> >> processing 1000
>> >> rows: used memory = 280854088
>> >> 2011-08-12 01:34:32,911 INFO
>> >> org.apache.hadoop.hive.ql.exec.MapOperator: 10
>> forwarding
>> >> 10000 rows
>> >> 2011-08-12 01:34:32,911 INFO
>> >> org.apache.hadoop.hive.ql.exec.TableScanOperator:
>> 0
>> >> forwarding 10000
>> >> rows
>> >> 2011-08-12 01:34:32,911 INFO ExecMapper:
>> ExecMapper:
>> >> processing 10000
>> >> rows: used memory = 280854088
>> >> 2011-08-12 01:34:33,522 INFO
>> >> org.apache.hadoop.hive.ql.exec.FilterOperator: 1
>> forwarding
>> >> 1 rows
>> >> 2011-08-12 01:34:33,523 INFO
>> >> org.apache.hadoop.hive.ql.exec.FilterOperator: 2
>> forwarding
>> >> 1 rows
>> >> 2011-08-12 01:34:33,527 INFO
>> >> org.apache.hadoop.hive.ql.exec.SelectOperator: 3
>> forwarding
>> >> 1 rows
>> >> 2011-08-12 01:34:33,538 INFO
>> >> org.apache.hadoop.hive.ql.exec.FilterOperator: 1
>> forwarding
>> >> 10 rows
>> >> 2011-08-12 01:34:33,538 INFO
>> >> org.apache.hadoop.hive.ql.exec.FilterOperator: 2
>> forwarding
>> >> 10 rows
>> >> 2011-08-12 01:34:33,538 INFO
>> >> org.apache.hadoop.hive.ql.exec.SelectOperator: 3
>> forwarding
>> >> 10 rows
>> >> 2011-08-12 01:34:33,580 INFO
>> >> org.apache.hadoop.hive.ql.exec.FilterOperator: 1
>> forwarding
>> >> 100 rows
>> >> 2011-08-12 01:34:33,580 INFO
>> >> org.apache.hadoop.hive.ql.exec.FilterOperator: 2
>> forwarding
>> >> 100 rows
>> >> 2011-08-12 01:34:33,581 INFO
>> >> org.apache.hadoop.hive.ql.exec.SelectOperator: 3
>> forwarding
>> >> 100 rows
>> >> 2011-08-12 01:34:33,839 INFO
>> >> org.apache.hadoop.hive.ql.exec.FilterOperator: 1
>> forwarding
>> >> 1000 rows
>> >> 2011-08-12 01:34:33,839 INFO
>> >> org.apache.hadoop.hive.ql.exec.FilterOperator: 2
>> forwarding
>> >> 1000 rows
>> >> 2011-08-12 01:34:33,839 INFO
>> >> org.apache.hadoop.hive.ql.exec.SelectOperator: 3
>> forwarding
>> >> 1000 rows
>> >> 2011-08-12 01:34:34,755 INFO
>> >> org.apache.hadoop.hive.ql.exec.FilterOperator: 1
>> forwarding
>> >> 10000 rows
>> >> 2011-08-12 01:34:34,755 INFO
>> >> org.apache.hadoop.hive.ql.exec.FilterOperator: 2
>> forwarding
>> >> 10000 rows
>> >> 2011-08-12 01:34:34,755 INFO
>> >> org.apache.hadoop.hive.ql.exec.SelectOperator: 3
>> forwarding
>> >> 10000 rows
>> >> 2011-08-12 01:34:37,268 INFO
>> >> org.apache.hadoop.hive.ql.exec.MapOperator: 10
>> finished.
>> >> closing...
>> >> 2011-08-12 01:34:37,268 INFO
>> >> org.apache.hadoop.hive.ql.exec.MapOperator: 10
>> forwarded
>> >> 81078 rows
>> >> 2011-08-12 01:34:37,268 INFO
>> >> org.apache.hadoop.hive.ql.exec.MapOperator:
>> >> DESERIALIZE_ERRORS:0
>> >> 2011-08-12 01:34:37,268 INFO
>> >> org.apache.hadoop.hive.ql.exec.TableScanOperator:
>> 0
>> >> finished.
>> >> closing...
>> >> 2011-08-12 01:34:37,268 INFO
>> >> org.apache.hadoop.hive.ql.exec.TableScanOperator:
>> 0
>> >> forwarded 81078
>> >> rows
>> >> 2011-08-12 01:34:37,268 INFO
>> >> org.apache.hadoop.hive.ql.exec.FilterOperator: 1
>> finished.
>> >> closing...
>> >> 2011-08-12 01:34:37,269 INFO
>> >> org.apache.hadoop.hive.ql.exec.FilterOperator: 1
>> forwarded
>> >> 16791 rows
>> >> 2011-08-12 01:34:37,269 INFO
>> >> org.apache.hadoop.hive.ql.exec.FilterOperator:
>> >> FILTERED:64287
>> >> 2011-08-12 01:34:37,269 INFO
>> >> org.apache.hadoop.hive.ql.exec.FilterOperator:
>> >> PASSED:16791
>> >> 2011-08-12 01:34:37,269 INFO
>> >> org.apache.hadoop.hive.ql.exec.FilterOperator: 2
>> finished.
>> >> closing...
>> >> 2011-08-12 01:34:37,269 INFO
>> >> org.apache.hadoop.hive.ql.exec.FilterOperator: 2
>> forwarded
>> >> 16791 rows
>> >> 2011-08-12 01:34:37,269 INFO
>> >> org.apache.hadoop.hive.ql.exec.FilterOperator:
>> FILTERED:0
>> >> 2011-08-12 01:34:37,269 INFO
>> >> org.apache.hadoop.hive.ql.exec.FilterOperator:
>> >> PASSED:16791
>> >> 2011-08-12 01:34:37,269 INFO
>> >> org.apache.hadoop.hive.ql.exec.SelectOperator: 3
>> finished.
>> >> closing...
>> >> 2011-08-12 01:34:37,269 INFO
>> >> org.apache.hadoop.hive.ql.exec.SelectOperator: 3
>> forwarded
>> >> 16791 rows
>> >> 2011-08-12 01:34:37,269 INFO
>> >> org.apache.hadoop.hive.ql.exec.ReduceSinkOperator:
>> 4
>> >> finished.
>> >> closing...
>> >> 2011-08-12 01:34:37,269 INFO
>> >> org.apache.hadoop.hive.ql.exec.ReduceSinkOperator:
>> 4
>> >> forwarded 0 rows
>> >> 2011-08-12 01:34:37,269 INFO
>> >> org.apache.hadoop.hive.ql.exec.SelectOperator: 3
>> Close
>> >> done
>> >> 2011-08-12 01:34:37,269 INFO
>> >> org.apache.hadoop.hive.ql.exec.FilterOperator: 2
>> Close
>> >> done
>> >> 2011-08-12 01:34:37,269 INFO
>> >> org.apache.hadoop.hive.ql.exec.FilterOperator: 1
>> Close
>> >> done
>> >> 2011-08-12 01:34:37,269 INFO
>> >> org.apache.hadoop.hive.ql.exec.TableScanOperator:
>> 0 Close
>> >> done
>> >> 2011-08-12 01:34:37,269 INFO
>> >> org.apache.hadoop.hive.ql.exec.MapOperator: 10
>> Close done
>> >> 2011-08-12 01:34:37,269 INFO ExecMapper:
>> ExecMapper:
>> >> processed 81078
>> >> rows: used memory = 244564320
>> >> 2011-08-12 01:34:37,274 INFO
>> >> org.apache.hadoop.mapred.MapTask:
>> >> Starting flush of map output
>> >> 2011-08-12 01:34:37,465 INFO
>> >> org.apache.hadoop.mapred.MapTask: Finished spill
>> 0
>> >> 2011-08-12 01:34:37,470 INFO
>> >> org.apache.hadoop.mapred.TaskRunner:
>> >> Task:attempt_201108111828_0008_m_000128_0 is done.
>> And is
>> >> in the
>> >> process of commiting
>> >> 2011-08-12 01:34:37,475 INFO
>> >> org.apache.hadoop.mapred.TaskRunner: Task
>> >> 'attempt_201108111828_0008_m_000128_0' done.
>> >>
>> >> why this happen? how to avoid the slow map?
>> >>
>> >
>>
>

Mime
View raw message