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 <florinp...@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 <w...@wdicc.com> wrote: > >> From: wd <w...@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 <florinp...@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 <w...@wdicc.com> >> wrote: >> > >> >> From: wd <w...@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? >> >> >> > >> >
