hadoop-mapreduce-user mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Florin P <florinp...@yahoo.com>
Subject Re: some map run really slow
Date Fri, 12 Aug 2011 12:47:33 GMT
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