You are viewing a plain text version of this content. The canonical link for it is here.
Posted to user@pig.apache.org by Avram Aelony <Av...@eharmony.com> on 2009/03/19 22:14:23 UTC
low memory handler?
Hello Pig List,
I am now taking my (tested) pig script that will produce distinct counts and trying to apply it to real data. I am finding however, that though the map stage completes (100%), the reduce stage hangs at 97.77% and then fails to produce output.
It appears that the syslog contains notices of "threshold exceeded" before the ultimate failure...
2009-03-19 10:54:10,525 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 131343896(128265K) committed = 186449920(182080K) max = 186449920(182080K)
2009-03-19 10:54:18,150 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 131311248(128233K) committed = 186449920(182080K) max = 186449920(182080K)
2009-03-19 10:54:25,833 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 133580568(130449K) committed = 186449920(182080K) max = 186449920(182080K)
...
Does this mean that the Hadoop cluster requires tuning?
How can I avoid this memory error?
Regards,
Avram
RE: low memory handler?
Posted by Avram Aelony <Av...@eharmony.com>.
...plenty of disk space...
-A
-----Original Message-----
From: Benjamin Reed [mailto:breed@yahoo-inc.com]
Sent: Friday, March 20, 2009 3:06 PM
To: pig-user@hadoop.apache.org
Subject: Re: low memory handler?
are you running out of diskspace?
ben
Avram Aelony wrote:
> Hi Yiping,
>
> I'm attaching a screenshot PNG of the failures I see. Reduce task attempts were killed on 14 different slaves. Drilling down into each it looks like only slave hadoop09 has errors and SpillableMemoryManager complaints.
>
> It looks like there was a problem writing to file and SpillableMemoryManager problems..
> -Avram
>
>
> Details below..
>
> stderr logs
>
> Exception closing file /user/aaelony/agg_date_from_amf_20090209.csv/_temporary/_attempt_200903201128_0001_r_000017_0/part-00017
> org.apache.hadoop.ipc.RemoteException: java.io.IOException: Could not complete write to file /user/aaelony/agg_date_from_amf_20090209.csv/_temporary/_attempt_200903201128_0001_r_000017_0/part-00017 by DFSClient_attempt_200903201128_0001_r_000017_0
> at org.apache.hadoop.dfs.NameNode.complete(NameNode.java:357)
> at sun.reflect.GeneratedMethodAccessor14.invoke(Unknown Source)
> at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
> at java.lang.reflect.Method.invoke(Method.java:585)
> at org.apache.hadoop.ipc.RPC$Server.call(RPC.java:452)
> at org.apache.hadoop.ipc.Server$Handler.run(Server.java:888)
>
> at org.apache.hadoop.ipc.Client.call(Client.java:715)
> at org.apache.hadoop.ipc.RPC$Invoker.invoke(RPC.java:216)
> at org.apache.hadoop.dfs.$Proxy1.complete(Unknown Source)
> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
> at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
> at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
> at java.lang.reflect.Method.invoke(Method.java:585)
> at org.apache.hadoop.io.retry.RetryInvocationHandler.invokeMethod(RetryInvocationHandler.java:82)
> at org.apache.hadoop.io.retry.RetryInvocationHandler.invoke(RetryInvocationHandler.java:59)
> at org.apache.hadoop.dfs.$Proxy1.complete(Unknown Source)
> at org.apache.hadoop.dfs.DFSClient$DFSOutputStream.closeInternal(DFSClient.java:2726)
> at org.apache.hadoop.dfs.DFSClient$DFSOutputStream.close(DFSClient.java:2647)
> at org.apache.hadoop.dfs.DFSClient.close(DFSClient.java:215)
> at org.apache.hadoop.dfs.DistributedFileSystem.close(DistributedFileSystem.java:243)
> at org.apache.hadoop.fs.FileSystem$Cache.closeAll(FileSystem.java:1385)
> at org.apache.hadoop.fs.FileSystem.closeAll(FileSystem.java:234)
> at org.apache.hadoop.fs.FileSystem$ClientFinalizer.run(FileSystem.java:219)
>
>
>
> syslog logs
>
> 2009-03-20 11:30:25,234 INFO org.apache.hadoop.metrics.jvm.JvmMetrics: Initializing JVM Metrics with processName=SHUFFLE, sessionId=
> 2009-03-20 11:30:25,691 INFO org.apache.hadoop.mapred.ReduceTask: ShuffleRamManager: MemoryLimit=157286400, MaxSingleShuffleLimit=39321600
> 2009-03-20 11:30:25,742 INFO org.apache.hadoop.mapred.ReduceTask: attempt_200903201128_0001_r_000017_0 Thread started: Thread for merging on-disk files
> 2009-03-20 11:30:25,743 INFO org.apache.hadoop.mapred.ReduceTask: attempt_200903201128_0001_r_000017_0 Thread waiting: Thread for merging on-disk files
> 2009-03-20 11:30:25,746 INFO org.apache.hadoop.mapred.ReduceTask: attempt_200903201128_0001_r_000017_0 Need another 4 map output(s) where 0 is already in progress
> 2009-03-20 11:30:25,747 INFO org.apache.hadoop.mapred.ReduceTask: attempt_200903201128_0001_r_000017_0 Thread started: Thread for merging in memory files
> 2009-03-20 11:30:25,748 INFO org.apache.hadoop.mapred.ReduceTask: attempt_200903201128_0001_r_000017_0: Got 0 new map-outputs & number of known map outputs is 0
> 2009-03-20 11:30:25,749 INFO org.apache.hadoop.mapred.ReduceTask: attempt_200903201128_0001_r_000017_0 Scheduled 0 of 0 known outputs (0 slow hosts and 0 dup hosts)
> 2009-03-20 11:31:25,789 INFO org.apache.hadoop.mapred.ReduceTask: attempt_200903201128_0001_r_000017_0 Need another 4 map output(s) where 0 is already in progress
> 2009-03-20 11:31:25,790 INFO org.apache.hadoop.mapred.ReduceTask: attempt_200903201128_0001_r_000017_0: Got 0 new map-outputs & number of known map outputs is 0
> 2009-03-20 11:31:25,790 INFO org.apache.hadoop.mapred.ReduceTask: attempt_200903201128_0001_r_000017_0 Scheduled 0 of 0 known outputs (0 slow hosts and 0 dup hosts)
> 2009-03-20 11:32:25,828 INFO org.apache.hadoop.mapred.ReduceTask: attempt_200903201128_0001_r_000017_0 Need another 4 map output(s) where 0 is already in progress
> 2009-03-20 11:32:25,829 INFO org.apache.hadoop.mapred.ReduceTask: attempt_200903201128_0001_r_000017_0: Got 0 new map-outputs & number of known map outputs is 0
> 2009-03-20 11:32:25,830 INFO org.apache.hadoop.mapred.ReduceTask: attempt_200903201128_0001_r_000017_0 Scheduled 0 of 0 known outputs (0 slow hosts and 0 dup hosts)
> 2009-03-20 11:33:25,867 INFO org.apache.hadoop.mapred.ReduceTask: attempt_200903201128_0001_r_000017_0 Need another 4 map output(s) where 0 is already in progress
> 2009-03-20 11:33:25,869 INFO org.apache.hadoop.mapred.ReduceTask: attempt_200903201128_0001_r_000017_0: Got 0 new map-outputs & number of known map outputs is 0
> 2009-03-20 11:33:25,869 INFO org.apache.hadoop.mapred.ReduceTask: attempt_200903201128_0001_r_000017_0 Scheduled 0 of 0 known outputs (0 slow hosts and 0 dup hosts)
> 2009-03-20 11:34:15,911 INFO org.apache.hadoop.mapred.ReduceTask: attempt_200903201128_0001_r_000017_0: Got 2 new map-outputs & number of known map outputs is 2
> 2009-03-20 11:34:15,911 INFO org.apache.hadoop.mapred.ReduceTask: attempt_200903201128_0001_r_000017_0 Scheduled 2 of 2 known outputs (0 slow hosts and 0 dup hosts)
> 2009-03-20 11:34:15,934 INFO org.apache.hadoop.mapred.ReduceTask: Shuffling 565463819 bytes (565463819 raw bytes) into Local-FS from attempt_200903201128_0001_m_000000_0
> 2009-03-20 11:34:15,934 INFO org.apache.hadoop.mapred.ReduceTask: Shuffling 535596555 bytes (535596555 raw bytes) into Local-FS from attempt_200903201128_0001_m_000003_0
> 2009-03-20 11:34:17,908 INFO org.apache.hadoop.mapred.ReduceTask: attempt_200903201128_0001_r_000017_0: Got 1 new map-outputs & number of known map outputs is 1
> 2009-03-20 11:34:17,909 INFO org.apache.hadoop.mapred.ReduceTask: attempt_200903201128_0001_r_000017_0 Scheduled 1 of 1 known outputs (0 slow hosts and 0 dup hosts)
> 2009-03-20 11:34:17,927 INFO org.apache.hadoop.mapred.ReduceTask: Shuffling 549733386 bytes (549733386 raw bytes) into Local-FS from attempt_200903201128_0001_m_000002_0
> 2009-03-20 11:34:22,930 INFO org.apache.hadoop.mapred.ReduceTask: attempt_200903201128_0001_r_000017_0: Got 1 new map-outputs & number of known map outputs is 1
> 2009-03-20 11:34:22,931 INFO org.apache.hadoop.mapred.ReduceTask: attempt_200903201128_0001_r_000017_0 Scheduled 1 of 1 known outputs (0 slow hosts and 0 dup hosts)
> 2009-03-20 11:34:22,945 INFO org.apache.hadoop.mapred.ReduceTask: Shuffling 559085822 bytes (559085822 raw bytes) into Local-FS from attempt_200903201128_0001_m_000001_0
> 2009-03-20 11:34:25,951 INFO org.apache.hadoop.mapred.ReduceTask: attempt_200903201128_0001_r_000017_0 Need another 4 map output(s) where 4 is already in progress
> 2009-03-20 11:34:26,951 INFO org.apache.hadoop.mapred.ReduceTask: attempt_200903201128_0001_r_000017_0: Got 0 new map-outputs & number of known map outputs is 0
> 2009-03-20 11:34:26,951 INFO org.apache.hadoop.mapred.ReduceTask: attempt_200903201128_0001_r_000017_0 Scheduled 0 of 0 known outputs (0 slow hosts and 0 dup hosts)
> 2009-03-20 11:34:32,493 INFO org.apache.hadoop.mapred.ReduceTask: Read 535596555 bytes from map-output for attempt_200903201128_0001_m_000003_0
> 2009-03-20 11:34:32,505 INFO org.apache.hadoop.mapred.ReduceTask: attempt_200903201128_0001_r_000017_0 Thread waiting: Thread for merging on-disk files
> 2009-03-20 11:34:36,677 INFO org.apache.hadoop.mapred.ReduceTask: Read 565463819 bytes from map-output for attempt_200903201128_0001_m_000000_0
> 2009-03-20 11:34:36,704 INFO org.apache.hadoop.mapred.ReduceTask: attempt_200903201128_0001_r_000017_0 Thread waiting: Thread for merging on-disk files
> 2009-03-20 11:34:37,159 INFO org.apache.hadoop.mapred.ReduceTask: Read 549733386 bytes from map-output for attempt_200903201128_0001_m_000002_0
> 2009-03-20 11:34:37,165 INFO org.apache.hadoop.mapred.ReduceTask: attempt_200903201128_0001_r_000017_0 Thread waiting: Thread for merging on-disk files
> 2009-03-20 11:34:39,732 INFO org.apache.hadoop.mapred.ReduceTask: Read 559085822 bytes from map-output for attempt_200903201128_0001_m_000001_0
> 2009-03-20 11:34:39,736 INFO org.apache.hadoop.mapred.ReduceTask: attempt_200903201128_0001_r_000017_0 Thread waiting: Thread for merging on-disk files
> 2009-03-20 11:34:40,025 INFO org.apache.hadoop.mapred.ReduceTask: Closed ram manager
> 2009-03-20 11:34:40,026 INFO org.apache.hadoop.mapred.ReduceTask: Interleaved on-disk merge complete: 4 files left.
> 2009-03-20 11:34:40,026 INFO org.apache.hadoop.mapred.ReduceTask: In-memory merge complete: 0 files left.
> 2009-03-20 11:34:40,027 INFO org.apache.hadoop.mapred.ReduceTask: Initiating final on-disk merge with 4 files
> 2009-03-20 11:34:40,048 INFO org.apache.hadoop.mapred.Merger: Merging 4 sorted segments
> 2009-03-20 11:34:46,445 INFO org.apache.hadoop.mapred.Merger: Down to the last merge-pass, with 4 segments left of total size: 2209879582 bytes
> 2009-03-20 11:35:08,114 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Collection threshold exceeded) init = 1441792(1408K) used = 267255808(260992K) committed = 305987584(298816K) max = 477233152(466048K)
> 2009-03-20 11:35:27,500 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Collection threshold exceeded) init = 1441792(1408K) used = 243009992(237314K) committed = 294715392(287808K) max = 477233152(466048K)
> 2009-03-20 11:35:44,331 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Collection threshold exceeded) init = 1441792(1408K) used = 294715384(287807K) committed = 347406336(339264K) max = 477233152(466048K)
> 2009-03-20 11:35:50,850 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 335507480(327644K) committed = 347406336(339264K) max = 477233152(466048K)
> 2009-03-20 11:36:05,033 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Collection threshold exceeded) init = 1441792(1408K) used = 256954008(250931K) committed = 338362368(330432K) max = 477233152(466048K)
> 2009-03-20 11:36:23,460 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 334921592(327071K) committed = 420216832(410368K) max = 477233152(466048K)
> 2009-03-20 11:36:40,251 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 334995976(327144K) committed = 420216832(410368K) max = 477233152(466048K)
> 2009-03-20 11:36:56,912 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 334744144(326898K) committed = 420216832(410368K) max = 477233152(466048K)
> 2009-03-20 11:37:13,779 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 336437688(328552K) committed = 420216832(410368K) max = 477233152(466048K)
> 2009-03-20 11:37:30,685 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 341918504(333904K) committed = 420216832(410368K) max = 477233152(466048K)
> 2009-03-20 11:37:47,640 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 334678160(326834K) committed = 420216832(410368K) max = 477233152(466048K)
> 2009-03-20 11:38:04,508 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 335327104(327467K) committed = 420216832(410368K) max = 477233152(466048K)
> 2009-03-20 11:38:21,508 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 340675816(332691K) committed = 420216832(410368K) max = 477233152(466048K)
> 2009-03-20 11:38:38,904 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 339857856(331892K) committed = 420216832(410368K) max = 477233152(466048K)
> 2009-03-20 11:38:55,835 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 341207224(333210K) committed = 420216832(410368K) max = 477233152(466048K)
> 2009-03-20 11:39:13,114 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 339354528(331400K) committed = 420216832(410368K) max = 477233152(466048K)
> 2009-03-20 11:39:30,443 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 334435872(326597K) committed = 420216832(410368K) max = 477233152(466048K)
> 2009-03-20 11:39:47,444 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 341849704(333837K) committed = 420216832(410368K) max = 477233152(466048K)
> 2009-03-20 11:40:04,424 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 334251632(326417K) committed = 420216832(410368K) max = 477233152(466048K)
> 2009-03-20 11:40:21,451 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 341015000(333022K) committed = 420216832(410368K) max = 477233152(466048K)
> 2009-03-20 11:40:38,279 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 341475264(333471K) committed = 420216832(410368K) max = 477233152(466048K)
> 2009-03-20 11:40:55,194 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 340923008(332932K) committed = 420216832(410368K) max = 477233152(466048K)
> 2009-03-20 11:41:12,195 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 334079216(326249K) committed = 420216832(410368K) max = 477233152(466048K)
> 2009-03-20 11:41:28,862 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 334112360(326281K) committed = 420216832(410368K) max = 477233152(466048K)
> 2009-03-20 11:41:45,700 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 334632944(326789K) committed = 420216832(410368K) max = 477233152(466048K)
> 2009-03-20 11:42:02,883 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 341260800(333262K) committed = 420216832(410368K) max = 477233152(466048K)
> 2009-03-20 11:42:20,318 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 341771216(333760K) committed = 420216832(410368K) max = 477233152(466048K)
> 2009-03-20 11:42:37,514 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 340517600(332536K) committed = 420216832(410368K) max = 477233152(466048K)
> 2009-03-20 11:42:54,644 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 334972072(327121K) committed = 420216832(410368K) max = 477233152(466048K)
> 2009-03-20 11:43:11,395 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 334300152(326464K) committed = 420216832(410368K) max = 477233152(466048K)
> 2009-03-20 11:43:28,308 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 341909944(333896K) committed = 420216832(410368K) max = 477233152(466048K)
> 2009-03-20 11:43:45,328 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 341787464(333776K) committed = 420216832(410368K) max = 477233152(466048K)
> 2009-03-20 11:44:02,035 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 339700808(331739K) committed = 420216832(410368K) max = 477233152(466048K)
> 2009-03-20 11:44:19,021 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 341705112(333696K) committed = 420216832(410368K) max = 477233152(466048K)
> 2009-03-20 11:44:35,810 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 339760248(331797K) committed = 420216832(410368K) max = 477233152(466048K)
> 2009-03-20 11:44:53,206 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 339696440(331734K) committed = 420216832(410368K) max = 477233152(466048K)
> 2009-03-20 11:45:10,266 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 340463384(332483K) committed = 420216832(410368K) max = 477233152(466048K)
> 2009-03-20 11:45:27,750 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 341859888(333847K) committed = 420216832(410368K) max = 477233152(466048K)
> 2009-03-20 11:45:45,126 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 340981720(332989K) committed = 420216832(410368K) max = 477233152(466048K)
> 2009-03-20 11:46:02,601 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 341606256(333599K) committed = 420216832(410368K) max = 477233152(466048K)
> 2009-03-20 11:46:19,765 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 341982248(333967K) committed = 420216832(410368K) max = 477233152(466048K)
> 2009-03-20 11:46:36,654 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 341968048(333953K) committed = 420216832(410368K) max = 477233152(466048K)
> 2009-03-20 11:46:54,131 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 341402408(333400K) committed = 420216832(410368K) max = 477233152(466048K)
> 2009-03-20 11:47:10,854 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 334262696(326428K) committed = 420216832(410368K) max = 477233152(466048K)
> 2009-03-20 11:47:27,651 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 339894880(331928K) committed = 420216832(410368K) max = 477233152(466048K)
> 2009-03-20 11:47:44,466 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 335703624(327835K) committed = 420216832(410368K) max = 477233152(466048K)
> 2009-03-20 11:48:01,206 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 335137016(327282K) committed = 420216832(410368K) max = 477233152(466048K)
> 2009-03-20 11:48:17,625 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 335608344(327742K) committed = 420216832(410368K) max = 477233152(466048K)
> 2009-03-20 11:49:04,588 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 334234728(326401K) committed = 420216832(410368K) max = 477233152(466048K)
> 2009-03-20 11:57:52,875 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Collection threshold exceeded) init = 1441792(1408K) used = 318525864(311060K) committed = 428867584(418816K) max = 477233152(466048K)
> 2009-03-20 11:58:17,099 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 334310872(326475K) committed = 428867584(418816K) max = 477233152(466048K)
>
>
>
> -----Original Message-----
> From: Yiping Han [mailto:yhan@yahoo-inc.com]
> Sent: Friday, March 20, 2009 12:05 PM
> To: pig-user@hadoop.apache.org
> Subject: Re: low memory handler?
>
> Avram,
>
> Could you please post your syslog so we see the behavior of
> spillableMemoryManager?
>
>
> -Yiping
>
>
> On 3/20/09 11:46 AM, "Avram Aelony" <Av...@eharmony.com> wrote:
>
>
>> Hi Pig List,
>>
>> After tinkering with the mapred.child.java.opts property -Xmx200m setting and
>> trying 512, 1024, 2048 values (e.g. Xmx512m ), none of these seem to solve the
>> problem. Map tasks complete 100% but Reduce tasks are killed never proceeding
>> past 98.88% complete. I am setting the config changes in hadoop-site.xml.
>>
>> Can you provide guidance as to which parameters are relevant here and what
>> settings to use?
>>
>> Thanks for your help,
>>
>> Avram
>>
>>
>>
>> -----Original Message-----
>> From: Avram Aelony
>> Sent: Thursday, March 19, 2009 2:35 PM
>> To: pig-user@hadoop.apache.org
>> Subject: RE: low memory handler?
>>
>>
>> Thank you, Olga.
>> Will reference
>> http://hadoop.apache.org/core/docs/current/cluster_setup.html#Configuration+Fi
>> les and try to specify more memory.
>>
>> Regards,
>> Avram
>>
>>
>>
>> -----Original Message-----
>> From: Olga Natkovich [mailto:olgan@yahoo-inc.com]
>> Sent: Thursday, March 19, 2009 2:21 PM
>> To: pig-user@hadoop.apache.org
>> Subject: RE: low memory handler?
>>
>> It looks like your tasks are configured to use 200 MB. This is usually
>> not sufficient for large data processing. In general, you need at least
>> 500 MB, 1 GB recommended and if you have more memory on your machine,
>> configuring more can further help your query execution. The amount of
>> course depends on how much memory you have on your machines and how many
>> map and reduce slots they have.
>>
>> Olga
>>
>>
>>> -----Original Message-----
>>> From: Avram Aelony [mailto:AvramAelony@eharmony.com]
>>> Sent: Thursday, March 19, 2009 2:14 PM
>>> To: pig-user@hadoop.apache.org
>>> Subject: low memory handler?
>>>
>>> Hello Pig List,
>>>
>>> I am now taking my (tested) pig script that will produce
>>> distinct counts and trying to apply it to real data. I am
>>> finding however, that though the map stage completes (100%),
>>> the reduce stage hangs at 97.77% and then fails to produce output.
>>>
>>> It appears that the syslog contains notices of "threshold
>>> exceeded" before the ultimate failure...
>>>
>>> 2009-03-19 10:54:10,525 INFO
>>> org.apache.pig.impl.util.SpillableMemoryManager: low memory
>>> handler called (Usage threshold exceeded) init =
>>> 1441792(1408K) used = 131343896(128265K) committed =
>>> 186449920(182080K) max = 186449920(182080K)
>>> 2009-03-19 10:54:18,150 INFO
>>> org.apache.pig.impl.util.SpillableMemoryManager: low memory
>>> handler called (Usage threshold exceeded) init =
>>> 1441792(1408K) used = 131311248(128233K) committed =
>>> 186449920(182080K) max = 186449920(182080K)
>>> 2009-03-19 10:54:25,833 INFO
>>> org.apache.pig.impl.util.SpillableMemoryManager: low memory
>>> handler called (Usage threshold exceeded) init =
>>> 1441792(1408K) used = 133580568(130449K) committed =
>>> 186449920(182080K) max = 186449920(182080K)
>>>
>>> ...
>>>
>>> Does this mean that the Hadoop cluster requires tuning?
>>>
>>> How can I avoid this memory error?
>>>
>>>
>>>
>>> Regards,
>>> Avram
>>>
>>>
>>>
>
> ----------------------
> Yiping Han
> 2MC 8127
> 2811 Mission College Blvd.,
> Santa Clara, CA 95054
> (408)349-4403
> yhan@yahoo-inc.com
>
>
Re: low memory handler?
Posted by Benjamin Reed <br...@yahoo-inc.com>.
are you running out of diskspace?
ben
Avram Aelony wrote:
> Hi Yiping,
>
> I'm attaching a screenshot PNG of the failures I see. Reduce task attempts were killed on 14 different slaves. Drilling down into each it looks like only slave hadoop09 has errors and SpillableMemoryManager complaints.
>
> It looks like there was a problem writing to file and SpillableMemoryManager problems..
> -Avram
>
>
> Details below..
>
> stderr logs
>
> Exception closing file /user/aaelony/agg_date_from_amf_20090209.csv/_temporary/_attempt_200903201128_0001_r_000017_0/part-00017
> org.apache.hadoop.ipc.RemoteException: java.io.IOException: Could not complete write to file /user/aaelony/agg_date_from_amf_20090209.csv/_temporary/_attempt_200903201128_0001_r_000017_0/part-00017 by DFSClient_attempt_200903201128_0001_r_000017_0
> at org.apache.hadoop.dfs.NameNode.complete(NameNode.java:357)
> at sun.reflect.GeneratedMethodAccessor14.invoke(Unknown Source)
> at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
> at java.lang.reflect.Method.invoke(Method.java:585)
> at org.apache.hadoop.ipc.RPC$Server.call(RPC.java:452)
> at org.apache.hadoop.ipc.Server$Handler.run(Server.java:888)
>
> at org.apache.hadoop.ipc.Client.call(Client.java:715)
> at org.apache.hadoop.ipc.RPC$Invoker.invoke(RPC.java:216)
> at org.apache.hadoop.dfs.$Proxy1.complete(Unknown Source)
> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
> at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
> at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
> at java.lang.reflect.Method.invoke(Method.java:585)
> at org.apache.hadoop.io.retry.RetryInvocationHandler.invokeMethod(RetryInvocationHandler.java:82)
> at org.apache.hadoop.io.retry.RetryInvocationHandler.invoke(RetryInvocationHandler.java:59)
> at org.apache.hadoop.dfs.$Proxy1.complete(Unknown Source)
> at org.apache.hadoop.dfs.DFSClient$DFSOutputStream.closeInternal(DFSClient.java:2726)
> at org.apache.hadoop.dfs.DFSClient$DFSOutputStream.close(DFSClient.java:2647)
> at org.apache.hadoop.dfs.DFSClient.close(DFSClient.java:215)
> at org.apache.hadoop.dfs.DistributedFileSystem.close(DistributedFileSystem.java:243)
> at org.apache.hadoop.fs.FileSystem$Cache.closeAll(FileSystem.java:1385)
> at org.apache.hadoop.fs.FileSystem.closeAll(FileSystem.java:234)
> at org.apache.hadoop.fs.FileSystem$ClientFinalizer.run(FileSystem.java:219)
>
>
>
> syslog logs
>
> 2009-03-20 11:30:25,234 INFO org.apache.hadoop.metrics.jvm.JvmMetrics: Initializing JVM Metrics with processName=SHUFFLE, sessionId=
> 2009-03-20 11:30:25,691 INFO org.apache.hadoop.mapred.ReduceTask: ShuffleRamManager: MemoryLimit=157286400, MaxSingleShuffleLimit=39321600
> 2009-03-20 11:30:25,742 INFO org.apache.hadoop.mapred.ReduceTask: attempt_200903201128_0001_r_000017_0 Thread started: Thread for merging on-disk files
> 2009-03-20 11:30:25,743 INFO org.apache.hadoop.mapred.ReduceTask: attempt_200903201128_0001_r_000017_0 Thread waiting: Thread for merging on-disk files
> 2009-03-20 11:30:25,746 INFO org.apache.hadoop.mapred.ReduceTask: attempt_200903201128_0001_r_000017_0 Need another 4 map output(s) where 0 is already in progress
> 2009-03-20 11:30:25,747 INFO org.apache.hadoop.mapred.ReduceTask: attempt_200903201128_0001_r_000017_0 Thread started: Thread for merging in memory files
> 2009-03-20 11:30:25,748 INFO org.apache.hadoop.mapred.ReduceTask: attempt_200903201128_0001_r_000017_0: Got 0 new map-outputs & number of known map outputs is 0
> 2009-03-20 11:30:25,749 INFO org.apache.hadoop.mapred.ReduceTask: attempt_200903201128_0001_r_000017_0 Scheduled 0 of 0 known outputs (0 slow hosts and 0 dup hosts)
> 2009-03-20 11:31:25,789 INFO org.apache.hadoop.mapred.ReduceTask: attempt_200903201128_0001_r_000017_0 Need another 4 map output(s) where 0 is already in progress
> 2009-03-20 11:31:25,790 INFO org.apache.hadoop.mapred.ReduceTask: attempt_200903201128_0001_r_000017_0: Got 0 new map-outputs & number of known map outputs is 0
> 2009-03-20 11:31:25,790 INFO org.apache.hadoop.mapred.ReduceTask: attempt_200903201128_0001_r_000017_0 Scheduled 0 of 0 known outputs (0 slow hosts and 0 dup hosts)
> 2009-03-20 11:32:25,828 INFO org.apache.hadoop.mapred.ReduceTask: attempt_200903201128_0001_r_000017_0 Need another 4 map output(s) where 0 is already in progress
> 2009-03-20 11:32:25,829 INFO org.apache.hadoop.mapred.ReduceTask: attempt_200903201128_0001_r_000017_0: Got 0 new map-outputs & number of known map outputs is 0
> 2009-03-20 11:32:25,830 INFO org.apache.hadoop.mapred.ReduceTask: attempt_200903201128_0001_r_000017_0 Scheduled 0 of 0 known outputs (0 slow hosts and 0 dup hosts)
> 2009-03-20 11:33:25,867 INFO org.apache.hadoop.mapred.ReduceTask: attempt_200903201128_0001_r_000017_0 Need another 4 map output(s) where 0 is already in progress
> 2009-03-20 11:33:25,869 INFO org.apache.hadoop.mapred.ReduceTask: attempt_200903201128_0001_r_000017_0: Got 0 new map-outputs & number of known map outputs is 0
> 2009-03-20 11:33:25,869 INFO org.apache.hadoop.mapred.ReduceTask: attempt_200903201128_0001_r_000017_0 Scheduled 0 of 0 known outputs (0 slow hosts and 0 dup hosts)
> 2009-03-20 11:34:15,911 INFO org.apache.hadoop.mapred.ReduceTask: attempt_200903201128_0001_r_000017_0: Got 2 new map-outputs & number of known map outputs is 2
> 2009-03-20 11:34:15,911 INFO org.apache.hadoop.mapred.ReduceTask: attempt_200903201128_0001_r_000017_0 Scheduled 2 of 2 known outputs (0 slow hosts and 0 dup hosts)
> 2009-03-20 11:34:15,934 INFO org.apache.hadoop.mapred.ReduceTask: Shuffling 565463819 bytes (565463819 raw bytes) into Local-FS from attempt_200903201128_0001_m_000000_0
> 2009-03-20 11:34:15,934 INFO org.apache.hadoop.mapred.ReduceTask: Shuffling 535596555 bytes (535596555 raw bytes) into Local-FS from attempt_200903201128_0001_m_000003_0
> 2009-03-20 11:34:17,908 INFO org.apache.hadoop.mapred.ReduceTask: attempt_200903201128_0001_r_000017_0: Got 1 new map-outputs & number of known map outputs is 1
> 2009-03-20 11:34:17,909 INFO org.apache.hadoop.mapred.ReduceTask: attempt_200903201128_0001_r_000017_0 Scheduled 1 of 1 known outputs (0 slow hosts and 0 dup hosts)
> 2009-03-20 11:34:17,927 INFO org.apache.hadoop.mapred.ReduceTask: Shuffling 549733386 bytes (549733386 raw bytes) into Local-FS from attempt_200903201128_0001_m_000002_0
> 2009-03-20 11:34:22,930 INFO org.apache.hadoop.mapred.ReduceTask: attempt_200903201128_0001_r_000017_0: Got 1 new map-outputs & number of known map outputs is 1
> 2009-03-20 11:34:22,931 INFO org.apache.hadoop.mapred.ReduceTask: attempt_200903201128_0001_r_000017_0 Scheduled 1 of 1 known outputs (0 slow hosts and 0 dup hosts)
> 2009-03-20 11:34:22,945 INFO org.apache.hadoop.mapred.ReduceTask: Shuffling 559085822 bytes (559085822 raw bytes) into Local-FS from attempt_200903201128_0001_m_000001_0
> 2009-03-20 11:34:25,951 INFO org.apache.hadoop.mapred.ReduceTask: attempt_200903201128_0001_r_000017_0 Need another 4 map output(s) where 4 is already in progress
> 2009-03-20 11:34:26,951 INFO org.apache.hadoop.mapred.ReduceTask: attempt_200903201128_0001_r_000017_0: Got 0 new map-outputs & number of known map outputs is 0
> 2009-03-20 11:34:26,951 INFO org.apache.hadoop.mapred.ReduceTask: attempt_200903201128_0001_r_000017_0 Scheduled 0 of 0 known outputs (0 slow hosts and 0 dup hosts)
> 2009-03-20 11:34:32,493 INFO org.apache.hadoop.mapred.ReduceTask: Read 535596555 bytes from map-output for attempt_200903201128_0001_m_000003_0
> 2009-03-20 11:34:32,505 INFO org.apache.hadoop.mapred.ReduceTask: attempt_200903201128_0001_r_000017_0 Thread waiting: Thread for merging on-disk files
> 2009-03-20 11:34:36,677 INFO org.apache.hadoop.mapred.ReduceTask: Read 565463819 bytes from map-output for attempt_200903201128_0001_m_000000_0
> 2009-03-20 11:34:36,704 INFO org.apache.hadoop.mapred.ReduceTask: attempt_200903201128_0001_r_000017_0 Thread waiting: Thread for merging on-disk files
> 2009-03-20 11:34:37,159 INFO org.apache.hadoop.mapred.ReduceTask: Read 549733386 bytes from map-output for attempt_200903201128_0001_m_000002_0
> 2009-03-20 11:34:37,165 INFO org.apache.hadoop.mapred.ReduceTask: attempt_200903201128_0001_r_000017_0 Thread waiting: Thread for merging on-disk files
> 2009-03-20 11:34:39,732 INFO org.apache.hadoop.mapred.ReduceTask: Read 559085822 bytes from map-output for attempt_200903201128_0001_m_000001_0
> 2009-03-20 11:34:39,736 INFO org.apache.hadoop.mapred.ReduceTask: attempt_200903201128_0001_r_000017_0 Thread waiting: Thread for merging on-disk files
> 2009-03-20 11:34:40,025 INFO org.apache.hadoop.mapred.ReduceTask: Closed ram manager
> 2009-03-20 11:34:40,026 INFO org.apache.hadoop.mapred.ReduceTask: Interleaved on-disk merge complete: 4 files left.
> 2009-03-20 11:34:40,026 INFO org.apache.hadoop.mapred.ReduceTask: In-memory merge complete: 0 files left.
> 2009-03-20 11:34:40,027 INFO org.apache.hadoop.mapred.ReduceTask: Initiating final on-disk merge with 4 files
> 2009-03-20 11:34:40,048 INFO org.apache.hadoop.mapred.Merger: Merging 4 sorted segments
> 2009-03-20 11:34:46,445 INFO org.apache.hadoop.mapred.Merger: Down to the last merge-pass, with 4 segments left of total size: 2209879582 bytes
> 2009-03-20 11:35:08,114 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Collection threshold exceeded) init = 1441792(1408K) used = 267255808(260992K) committed = 305987584(298816K) max = 477233152(466048K)
> 2009-03-20 11:35:27,500 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Collection threshold exceeded) init = 1441792(1408K) used = 243009992(237314K) committed = 294715392(287808K) max = 477233152(466048K)
> 2009-03-20 11:35:44,331 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Collection threshold exceeded) init = 1441792(1408K) used = 294715384(287807K) committed = 347406336(339264K) max = 477233152(466048K)
> 2009-03-20 11:35:50,850 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 335507480(327644K) committed = 347406336(339264K) max = 477233152(466048K)
> 2009-03-20 11:36:05,033 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Collection threshold exceeded) init = 1441792(1408K) used = 256954008(250931K) committed = 338362368(330432K) max = 477233152(466048K)
> 2009-03-20 11:36:23,460 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 334921592(327071K) committed = 420216832(410368K) max = 477233152(466048K)
> 2009-03-20 11:36:40,251 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 334995976(327144K) committed = 420216832(410368K) max = 477233152(466048K)
> 2009-03-20 11:36:56,912 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 334744144(326898K) committed = 420216832(410368K) max = 477233152(466048K)
> 2009-03-20 11:37:13,779 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 336437688(328552K) committed = 420216832(410368K) max = 477233152(466048K)
> 2009-03-20 11:37:30,685 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 341918504(333904K) committed = 420216832(410368K) max = 477233152(466048K)
> 2009-03-20 11:37:47,640 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 334678160(326834K) committed = 420216832(410368K) max = 477233152(466048K)
> 2009-03-20 11:38:04,508 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 335327104(327467K) committed = 420216832(410368K) max = 477233152(466048K)
> 2009-03-20 11:38:21,508 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 340675816(332691K) committed = 420216832(410368K) max = 477233152(466048K)
> 2009-03-20 11:38:38,904 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 339857856(331892K) committed = 420216832(410368K) max = 477233152(466048K)
> 2009-03-20 11:38:55,835 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 341207224(333210K) committed = 420216832(410368K) max = 477233152(466048K)
> 2009-03-20 11:39:13,114 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 339354528(331400K) committed = 420216832(410368K) max = 477233152(466048K)
> 2009-03-20 11:39:30,443 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 334435872(326597K) committed = 420216832(410368K) max = 477233152(466048K)
> 2009-03-20 11:39:47,444 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 341849704(333837K) committed = 420216832(410368K) max = 477233152(466048K)
> 2009-03-20 11:40:04,424 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 334251632(326417K) committed = 420216832(410368K) max = 477233152(466048K)
> 2009-03-20 11:40:21,451 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 341015000(333022K) committed = 420216832(410368K) max = 477233152(466048K)
> 2009-03-20 11:40:38,279 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 341475264(333471K) committed = 420216832(410368K) max = 477233152(466048K)
> 2009-03-20 11:40:55,194 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 340923008(332932K) committed = 420216832(410368K) max = 477233152(466048K)
> 2009-03-20 11:41:12,195 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 334079216(326249K) committed = 420216832(410368K) max = 477233152(466048K)
> 2009-03-20 11:41:28,862 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 334112360(326281K) committed = 420216832(410368K) max = 477233152(466048K)
> 2009-03-20 11:41:45,700 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 334632944(326789K) committed = 420216832(410368K) max = 477233152(466048K)
> 2009-03-20 11:42:02,883 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 341260800(333262K) committed = 420216832(410368K) max = 477233152(466048K)
> 2009-03-20 11:42:20,318 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 341771216(333760K) committed = 420216832(410368K) max = 477233152(466048K)
> 2009-03-20 11:42:37,514 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 340517600(332536K) committed = 420216832(410368K) max = 477233152(466048K)
> 2009-03-20 11:42:54,644 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 334972072(327121K) committed = 420216832(410368K) max = 477233152(466048K)
> 2009-03-20 11:43:11,395 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 334300152(326464K) committed = 420216832(410368K) max = 477233152(466048K)
> 2009-03-20 11:43:28,308 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 341909944(333896K) committed = 420216832(410368K) max = 477233152(466048K)
> 2009-03-20 11:43:45,328 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 341787464(333776K) committed = 420216832(410368K) max = 477233152(466048K)
> 2009-03-20 11:44:02,035 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 339700808(331739K) committed = 420216832(410368K) max = 477233152(466048K)
> 2009-03-20 11:44:19,021 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 341705112(333696K) committed = 420216832(410368K) max = 477233152(466048K)
> 2009-03-20 11:44:35,810 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 339760248(331797K) committed = 420216832(410368K) max = 477233152(466048K)
> 2009-03-20 11:44:53,206 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 339696440(331734K) committed = 420216832(410368K) max = 477233152(466048K)
> 2009-03-20 11:45:10,266 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 340463384(332483K) committed = 420216832(410368K) max = 477233152(466048K)
> 2009-03-20 11:45:27,750 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 341859888(333847K) committed = 420216832(410368K) max = 477233152(466048K)
> 2009-03-20 11:45:45,126 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 340981720(332989K) committed = 420216832(410368K) max = 477233152(466048K)
> 2009-03-20 11:46:02,601 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 341606256(333599K) committed = 420216832(410368K) max = 477233152(466048K)
> 2009-03-20 11:46:19,765 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 341982248(333967K) committed = 420216832(410368K) max = 477233152(466048K)
> 2009-03-20 11:46:36,654 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 341968048(333953K) committed = 420216832(410368K) max = 477233152(466048K)
> 2009-03-20 11:46:54,131 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 341402408(333400K) committed = 420216832(410368K) max = 477233152(466048K)
> 2009-03-20 11:47:10,854 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 334262696(326428K) committed = 420216832(410368K) max = 477233152(466048K)
> 2009-03-20 11:47:27,651 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 339894880(331928K) committed = 420216832(410368K) max = 477233152(466048K)
> 2009-03-20 11:47:44,466 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 335703624(327835K) committed = 420216832(410368K) max = 477233152(466048K)
> 2009-03-20 11:48:01,206 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 335137016(327282K) committed = 420216832(410368K) max = 477233152(466048K)
> 2009-03-20 11:48:17,625 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 335608344(327742K) committed = 420216832(410368K) max = 477233152(466048K)
> 2009-03-20 11:49:04,588 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 334234728(326401K) committed = 420216832(410368K) max = 477233152(466048K)
> 2009-03-20 11:57:52,875 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Collection threshold exceeded) init = 1441792(1408K) used = 318525864(311060K) committed = 428867584(418816K) max = 477233152(466048K)
> 2009-03-20 11:58:17,099 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 334310872(326475K) committed = 428867584(418816K) max = 477233152(466048K)
>
>
>
> -----Original Message-----
> From: Yiping Han [mailto:yhan@yahoo-inc.com]
> Sent: Friday, March 20, 2009 12:05 PM
> To: pig-user@hadoop.apache.org
> Subject: Re: low memory handler?
>
> Avram,
>
> Could you please post your syslog so we see the behavior of
> spillableMemoryManager?
>
>
> -Yiping
>
>
> On 3/20/09 11:46 AM, "Avram Aelony" <Av...@eharmony.com> wrote:
>
>
>> Hi Pig List,
>>
>> After tinkering with the mapred.child.java.opts property -Xmx200m setting and
>> trying 512, 1024, 2048 values (e.g. Xmx512m ), none of these seem to solve the
>> problem. Map tasks complete 100% but Reduce tasks are killed never proceeding
>> past 98.88% complete. I am setting the config changes in hadoop-site.xml.
>>
>> Can you provide guidance as to which parameters are relevant here and what
>> settings to use?
>>
>> Thanks for your help,
>>
>> Avram
>>
>>
>>
>> -----Original Message-----
>> From: Avram Aelony
>> Sent: Thursday, March 19, 2009 2:35 PM
>> To: pig-user@hadoop.apache.org
>> Subject: RE: low memory handler?
>>
>>
>> Thank you, Olga.
>> Will reference
>> http://hadoop.apache.org/core/docs/current/cluster_setup.html#Configuration+Fi
>> les and try to specify more memory.
>>
>> Regards,
>> Avram
>>
>>
>>
>> -----Original Message-----
>> From: Olga Natkovich [mailto:olgan@yahoo-inc.com]
>> Sent: Thursday, March 19, 2009 2:21 PM
>> To: pig-user@hadoop.apache.org
>> Subject: RE: low memory handler?
>>
>> It looks like your tasks are configured to use 200 MB. This is usually
>> not sufficient for large data processing. In general, you need at least
>> 500 MB, 1 GB recommended and if you have more memory on your machine,
>> configuring more can further help your query execution. The amount of
>> course depends on how much memory you have on your machines and how many
>> map and reduce slots they have.
>>
>> Olga
>>
>>
>>> -----Original Message-----
>>> From: Avram Aelony [mailto:AvramAelony@eharmony.com]
>>> Sent: Thursday, March 19, 2009 2:14 PM
>>> To: pig-user@hadoop.apache.org
>>> Subject: low memory handler?
>>>
>>> Hello Pig List,
>>>
>>> I am now taking my (tested) pig script that will produce
>>> distinct counts and trying to apply it to real data. I am
>>> finding however, that though the map stage completes (100%),
>>> the reduce stage hangs at 97.77% and then fails to produce output.
>>>
>>> It appears that the syslog contains notices of "threshold
>>> exceeded" before the ultimate failure...
>>>
>>> 2009-03-19 10:54:10,525 INFO
>>> org.apache.pig.impl.util.SpillableMemoryManager: low memory
>>> handler called (Usage threshold exceeded) init =
>>> 1441792(1408K) used = 131343896(128265K) committed =
>>> 186449920(182080K) max = 186449920(182080K)
>>> 2009-03-19 10:54:18,150 INFO
>>> org.apache.pig.impl.util.SpillableMemoryManager: low memory
>>> handler called (Usage threshold exceeded) init =
>>> 1441792(1408K) used = 131311248(128233K) committed =
>>> 186449920(182080K) max = 186449920(182080K)
>>> 2009-03-19 10:54:25,833 INFO
>>> org.apache.pig.impl.util.SpillableMemoryManager: low memory
>>> handler called (Usage threshold exceeded) init =
>>> 1441792(1408K) used = 133580568(130449K) committed =
>>> 186449920(182080K) max = 186449920(182080K)
>>>
>>> ...
>>>
>>> Does this mean that the Hadoop cluster requires tuning?
>>>
>>> How can I avoid this memory error?
>>>
>>>
>>>
>>> Regards,
>>> Avram
>>>
>>>
>>>
>
> ----------------------
> Yiping Han
> 2MC 8127
> 2811 Mission College Blvd.,
> Santa Clara, CA 95054
> (408)349-4403
> yhan@yahoo-inc.com
>
>
RE: low memory handler?
Posted by Avram Aelony <Av...@eharmony.com>.
Hi Yiping,
I'm attaching a screenshot PNG of the failures I see. Reduce task attempts were killed on 14 different slaves. Drilling down into each it looks like only slave hadoop09 has errors and SpillableMemoryManager complaints.
It looks like there was a problem writing to file and SpillableMemoryManager problems..
-Avram
Details below..
stderr logs
Exception closing file /user/aaelony/agg_date_from_amf_20090209.csv/_temporary/_attempt_200903201128_0001_r_000017_0/part-00017
org.apache.hadoop.ipc.RemoteException: java.io.IOException: Could not complete write to file /user/aaelony/agg_date_from_amf_20090209.csv/_temporary/_attempt_200903201128_0001_r_000017_0/part-00017 by DFSClient_attempt_200903201128_0001_r_000017_0
at org.apache.hadoop.dfs.NameNode.complete(NameNode.java:357)
at sun.reflect.GeneratedMethodAccessor14.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:585)
at org.apache.hadoop.ipc.RPC$Server.call(RPC.java:452)
at org.apache.hadoop.ipc.Server$Handler.run(Server.java:888)
at org.apache.hadoop.ipc.Client.call(Client.java:715)
at org.apache.hadoop.ipc.RPC$Invoker.invoke(RPC.java:216)
at org.apache.hadoop.dfs.$Proxy1.complete(Unknown Source)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:585)
at org.apache.hadoop.io.retry.RetryInvocationHandler.invokeMethod(RetryInvocationHandler.java:82)
at org.apache.hadoop.io.retry.RetryInvocationHandler.invoke(RetryInvocationHandler.java:59)
at org.apache.hadoop.dfs.$Proxy1.complete(Unknown Source)
at org.apache.hadoop.dfs.DFSClient$DFSOutputStream.closeInternal(DFSClient.java:2726)
at org.apache.hadoop.dfs.DFSClient$DFSOutputStream.close(DFSClient.java:2647)
at org.apache.hadoop.dfs.DFSClient.close(DFSClient.java:215)
at org.apache.hadoop.dfs.DistributedFileSystem.close(DistributedFileSystem.java:243)
at org.apache.hadoop.fs.FileSystem$Cache.closeAll(FileSystem.java:1385)
at org.apache.hadoop.fs.FileSystem.closeAll(FileSystem.java:234)
at org.apache.hadoop.fs.FileSystem$ClientFinalizer.run(FileSystem.java:219)
syslog logs
2009-03-20 11:30:25,234 INFO org.apache.hadoop.metrics.jvm.JvmMetrics: Initializing JVM Metrics with processName=SHUFFLE, sessionId=
2009-03-20 11:30:25,691 INFO org.apache.hadoop.mapred.ReduceTask: ShuffleRamManager: MemoryLimit=157286400, MaxSingleShuffleLimit=39321600
2009-03-20 11:30:25,742 INFO org.apache.hadoop.mapred.ReduceTask: attempt_200903201128_0001_r_000017_0 Thread started: Thread for merging on-disk files
2009-03-20 11:30:25,743 INFO org.apache.hadoop.mapred.ReduceTask: attempt_200903201128_0001_r_000017_0 Thread waiting: Thread for merging on-disk files
2009-03-20 11:30:25,746 INFO org.apache.hadoop.mapred.ReduceTask: attempt_200903201128_0001_r_000017_0 Need another 4 map output(s) where 0 is already in progress
2009-03-20 11:30:25,747 INFO org.apache.hadoop.mapred.ReduceTask: attempt_200903201128_0001_r_000017_0 Thread started: Thread for merging in memory files
2009-03-20 11:30:25,748 INFO org.apache.hadoop.mapred.ReduceTask: attempt_200903201128_0001_r_000017_0: Got 0 new map-outputs & number of known map outputs is 0
2009-03-20 11:30:25,749 INFO org.apache.hadoop.mapred.ReduceTask: attempt_200903201128_0001_r_000017_0 Scheduled 0 of 0 known outputs (0 slow hosts and 0 dup hosts)
2009-03-20 11:31:25,789 INFO org.apache.hadoop.mapred.ReduceTask: attempt_200903201128_0001_r_000017_0 Need another 4 map output(s) where 0 is already in progress
2009-03-20 11:31:25,790 INFO org.apache.hadoop.mapred.ReduceTask: attempt_200903201128_0001_r_000017_0: Got 0 new map-outputs & number of known map outputs is 0
2009-03-20 11:31:25,790 INFO org.apache.hadoop.mapred.ReduceTask: attempt_200903201128_0001_r_000017_0 Scheduled 0 of 0 known outputs (0 slow hosts and 0 dup hosts)
2009-03-20 11:32:25,828 INFO org.apache.hadoop.mapred.ReduceTask: attempt_200903201128_0001_r_000017_0 Need another 4 map output(s) where 0 is already in progress
2009-03-20 11:32:25,829 INFO org.apache.hadoop.mapred.ReduceTask: attempt_200903201128_0001_r_000017_0: Got 0 new map-outputs & number of known map outputs is 0
2009-03-20 11:32:25,830 INFO org.apache.hadoop.mapred.ReduceTask: attempt_200903201128_0001_r_000017_0 Scheduled 0 of 0 known outputs (0 slow hosts and 0 dup hosts)
2009-03-20 11:33:25,867 INFO org.apache.hadoop.mapred.ReduceTask: attempt_200903201128_0001_r_000017_0 Need another 4 map output(s) where 0 is already in progress
2009-03-20 11:33:25,869 INFO org.apache.hadoop.mapred.ReduceTask: attempt_200903201128_0001_r_000017_0: Got 0 new map-outputs & number of known map outputs is 0
2009-03-20 11:33:25,869 INFO org.apache.hadoop.mapred.ReduceTask: attempt_200903201128_0001_r_000017_0 Scheduled 0 of 0 known outputs (0 slow hosts and 0 dup hosts)
2009-03-20 11:34:15,911 INFO org.apache.hadoop.mapred.ReduceTask: attempt_200903201128_0001_r_000017_0: Got 2 new map-outputs & number of known map outputs is 2
2009-03-20 11:34:15,911 INFO org.apache.hadoop.mapred.ReduceTask: attempt_200903201128_0001_r_000017_0 Scheduled 2 of 2 known outputs (0 slow hosts and 0 dup hosts)
2009-03-20 11:34:15,934 INFO org.apache.hadoop.mapred.ReduceTask: Shuffling 565463819 bytes (565463819 raw bytes) into Local-FS from attempt_200903201128_0001_m_000000_0
2009-03-20 11:34:15,934 INFO org.apache.hadoop.mapred.ReduceTask: Shuffling 535596555 bytes (535596555 raw bytes) into Local-FS from attempt_200903201128_0001_m_000003_0
2009-03-20 11:34:17,908 INFO org.apache.hadoop.mapred.ReduceTask: attempt_200903201128_0001_r_000017_0: Got 1 new map-outputs & number of known map outputs is 1
2009-03-20 11:34:17,909 INFO org.apache.hadoop.mapred.ReduceTask: attempt_200903201128_0001_r_000017_0 Scheduled 1 of 1 known outputs (0 slow hosts and 0 dup hosts)
2009-03-20 11:34:17,927 INFO org.apache.hadoop.mapred.ReduceTask: Shuffling 549733386 bytes (549733386 raw bytes) into Local-FS from attempt_200903201128_0001_m_000002_0
2009-03-20 11:34:22,930 INFO org.apache.hadoop.mapred.ReduceTask: attempt_200903201128_0001_r_000017_0: Got 1 new map-outputs & number of known map outputs is 1
2009-03-20 11:34:22,931 INFO org.apache.hadoop.mapred.ReduceTask: attempt_200903201128_0001_r_000017_0 Scheduled 1 of 1 known outputs (0 slow hosts and 0 dup hosts)
2009-03-20 11:34:22,945 INFO org.apache.hadoop.mapred.ReduceTask: Shuffling 559085822 bytes (559085822 raw bytes) into Local-FS from attempt_200903201128_0001_m_000001_0
2009-03-20 11:34:25,951 INFO org.apache.hadoop.mapred.ReduceTask: attempt_200903201128_0001_r_000017_0 Need another 4 map output(s) where 4 is already in progress
2009-03-20 11:34:26,951 INFO org.apache.hadoop.mapred.ReduceTask: attempt_200903201128_0001_r_000017_0: Got 0 new map-outputs & number of known map outputs is 0
2009-03-20 11:34:26,951 INFO org.apache.hadoop.mapred.ReduceTask: attempt_200903201128_0001_r_000017_0 Scheduled 0 of 0 known outputs (0 slow hosts and 0 dup hosts)
2009-03-20 11:34:32,493 INFO org.apache.hadoop.mapred.ReduceTask: Read 535596555 bytes from map-output for attempt_200903201128_0001_m_000003_0
2009-03-20 11:34:32,505 INFO org.apache.hadoop.mapred.ReduceTask: attempt_200903201128_0001_r_000017_0 Thread waiting: Thread for merging on-disk files
2009-03-20 11:34:36,677 INFO org.apache.hadoop.mapred.ReduceTask: Read 565463819 bytes from map-output for attempt_200903201128_0001_m_000000_0
2009-03-20 11:34:36,704 INFO org.apache.hadoop.mapred.ReduceTask: attempt_200903201128_0001_r_000017_0 Thread waiting: Thread for merging on-disk files
2009-03-20 11:34:37,159 INFO org.apache.hadoop.mapred.ReduceTask: Read 549733386 bytes from map-output for attempt_200903201128_0001_m_000002_0
2009-03-20 11:34:37,165 INFO org.apache.hadoop.mapred.ReduceTask: attempt_200903201128_0001_r_000017_0 Thread waiting: Thread for merging on-disk files
2009-03-20 11:34:39,732 INFO org.apache.hadoop.mapred.ReduceTask: Read 559085822 bytes from map-output for attempt_200903201128_0001_m_000001_0
2009-03-20 11:34:39,736 INFO org.apache.hadoop.mapred.ReduceTask: attempt_200903201128_0001_r_000017_0 Thread waiting: Thread for merging on-disk files
2009-03-20 11:34:40,025 INFO org.apache.hadoop.mapred.ReduceTask: Closed ram manager
2009-03-20 11:34:40,026 INFO org.apache.hadoop.mapred.ReduceTask: Interleaved on-disk merge complete: 4 files left.
2009-03-20 11:34:40,026 INFO org.apache.hadoop.mapred.ReduceTask: In-memory merge complete: 0 files left.
2009-03-20 11:34:40,027 INFO org.apache.hadoop.mapred.ReduceTask: Initiating final on-disk merge with 4 files
2009-03-20 11:34:40,048 INFO org.apache.hadoop.mapred.Merger: Merging 4 sorted segments
2009-03-20 11:34:46,445 INFO org.apache.hadoop.mapred.Merger: Down to the last merge-pass, with 4 segments left of total size: 2209879582 bytes
2009-03-20 11:35:08,114 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Collection threshold exceeded) init = 1441792(1408K) used = 267255808(260992K) committed = 305987584(298816K) max = 477233152(466048K)
2009-03-20 11:35:27,500 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Collection threshold exceeded) init = 1441792(1408K) used = 243009992(237314K) committed = 294715392(287808K) max = 477233152(466048K)
2009-03-20 11:35:44,331 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Collection threshold exceeded) init = 1441792(1408K) used = 294715384(287807K) committed = 347406336(339264K) max = 477233152(466048K)
2009-03-20 11:35:50,850 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 335507480(327644K) committed = 347406336(339264K) max = 477233152(466048K)
2009-03-20 11:36:05,033 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Collection threshold exceeded) init = 1441792(1408K) used = 256954008(250931K) committed = 338362368(330432K) max = 477233152(466048K)
2009-03-20 11:36:23,460 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 334921592(327071K) committed = 420216832(410368K) max = 477233152(466048K)
2009-03-20 11:36:40,251 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 334995976(327144K) committed = 420216832(410368K) max = 477233152(466048K)
2009-03-20 11:36:56,912 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 334744144(326898K) committed = 420216832(410368K) max = 477233152(466048K)
2009-03-20 11:37:13,779 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 336437688(328552K) committed = 420216832(410368K) max = 477233152(466048K)
2009-03-20 11:37:30,685 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 341918504(333904K) committed = 420216832(410368K) max = 477233152(466048K)
2009-03-20 11:37:47,640 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 334678160(326834K) committed = 420216832(410368K) max = 477233152(466048K)
2009-03-20 11:38:04,508 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 335327104(327467K) committed = 420216832(410368K) max = 477233152(466048K)
2009-03-20 11:38:21,508 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 340675816(332691K) committed = 420216832(410368K) max = 477233152(466048K)
2009-03-20 11:38:38,904 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 339857856(331892K) committed = 420216832(410368K) max = 477233152(466048K)
2009-03-20 11:38:55,835 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 341207224(333210K) committed = 420216832(410368K) max = 477233152(466048K)
2009-03-20 11:39:13,114 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 339354528(331400K) committed = 420216832(410368K) max = 477233152(466048K)
2009-03-20 11:39:30,443 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 334435872(326597K) committed = 420216832(410368K) max = 477233152(466048K)
2009-03-20 11:39:47,444 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 341849704(333837K) committed = 420216832(410368K) max = 477233152(466048K)
2009-03-20 11:40:04,424 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 334251632(326417K) committed = 420216832(410368K) max = 477233152(466048K)
2009-03-20 11:40:21,451 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 341015000(333022K) committed = 420216832(410368K) max = 477233152(466048K)
2009-03-20 11:40:38,279 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 341475264(333471K) committed = 420216832(410368K) max = 477233152(466048K)
2009-03-20 11:40:55,194 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 340923008(332932K) committed = 420216832(410368K) max = 477233152(466048K)
2009-03-20 11:41:12,195 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 334079216(326249K) committed = 420216832(410368K) max = 477233152(466048K)
2009-03-20 11:41:28,862 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 334112360(326281K) committed = 420216832(410368K) max = 477233152(466048K)
2009-03-20 11:41:45,700 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 334632944(326789K) committed = 420216832(410368K) max = 477233152(466048K)
2009-03-20 11:42:02,883 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 341260800(333262K) committed = 420216832(410368K) max = 477233152(466048K)
2009-03-20 11:42:20,318 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 341771216(333760K) committed = 420216832(410368K) max = 477233152(466048K)
2009-03-20 11:42:37,514 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 340517600(332536K) committed = 420216832(410368K) max = 477233152(466048K)
2009-03-20 11:42:54,644 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 334972072(327121K) committed = 420216832(410368K) max = 477233152(466048K)
2009-03-20 11:43:11,395 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 334300152(326464K) committed = 420216832(410368K) max = 477233152(466048K)
2009-03-20 11:43:28,308 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 341909944(333896K) committed = 420216832(410368K) max = 477233152(466048K)
2009-03-20 11:43:45,328 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 341787464(333776K) committed = 420216832(410368K) max = 477233152(466048K)
2009-03-20 11:44:02,035 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 339700808(331739K) committed = 420216832(410368K) max = 477233152(466048K)
2009-03-20 11:44:19,021 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 341705112(333696K) committed = 420216832(410368K) max = 477233152(466048K)
2009-03-20 11:44:35,810 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 339760248(331797K) committed = 420216832(410368K) max = 477233152(466048K)
2009-03-20 11:44:53,206 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 339696440(331734K) committed = 420216832(410368K) max = 477233152(466048K)
2009-03-20 11:45:10,266 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 340463384(332483K) committed = 420216832(410368K) max = 477233152(466048K)
2009-03-20 11:45:27,750 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 341859888(333847K) committed = 420216832(410368K) max = 477233152(466048K)
2009-03-20 11:45:45,126 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 340981720(332989K) committed = 420216832(410368K) max = 477233152(466048K)
2009-03-20 11:46:02,601 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 341606256(333599K) committed = 420216832(410368K) max = 477233152(466048K)
2009-03-20 11:46:19,765 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 341982248(333967K) committed = 420216832(410368K) max = 477233152(466048K)
2009-03-20 11:46:36,654 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 341968048(333953K) committed = 420216832(410368K) max = 477233152(466048K)
2009-03-20 11:46:54,131 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 341402408(333400K) committed = 420216832(410368K) max = 477233152(466048K)
2009-03-20 11:47:10,854 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 334262696(326428K) committed = 420216832(410368K) max = 477233152(466048K)
2009-03-20 11:47:27,651 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 339894880(331928K) committed = 420216832(410368K) max = 477233152(466048K)
2009-03-20 11:47:44,466 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 335703624(327835K) committed = 420216832(410368K) max = 477233152(466048K)
2009-03-20 11:48:01,206 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 335137016(327282K) committed = 420216832(410368K) max = 477233152(466048K)
2009-03-20 11:48:17,625 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 335608344(327742K) committed = 420216832(410368K) max = 477233152(466048K)
2009-03-20 11:49:04,588 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 334234728(326401K) committed = 420216832(410368K) max = 477233152(466048K)
2009-03-20 11:57:52,875 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Collection threshold exceeded) init = 1441792(1408K) used = 318525864(311060K) committed = 428867584(418816K) max = 477233152(466048K)
2009-03-20 11:58:17,099 INFO org.apache.pig.impl.util.SpillableMemoryManager: low memory handler called (Usage threshold exceeded) init = 1441792(1408K) used = 334310872(326475K) committed = 428867584(418816K) max = 477233152(466048K)
-----Original Message-----
From: Yiping Han [mailto:yhan@yahoo-inc.com]
Sent: Friday, March 20, 2009 12:05 PM
To: pig-user@hadoop.apache.org
Subject: Re: low memory handler?
Avram,
Could you please post your syslog so we see the behavior of
spillableMemoryManager?
-Yiping
On 3/20/09 11:46 AM, "Avram Aelony" <Av...@eharmony.com> wrote:
> Hi Pig List,
>
> After tinkering with the mapred.child.java.opts property -Xmx200m setting and
> trying 512, 1024, 2048 values (e.g. Xmx512m ), none of these seem to solve the
> problem. Map tasks complete 100% but Reduce tasks are killed never proceeding
> past 98.88% complete. I am setting the config changes in hadoop-site.xml.
>
> Can you provide guidance as to which parameters are relevant here and what
> settings to use?
>
> Thanks for your help,
>
> Avram
>
>
>
> -----Original Message-----
> From: Avram Aelony
> Sent: Thursday, March 19, 2009 2:35 PM
> To: pig-user@hadoop.apache.org
> Subject: RE: low memory handler?
>
>
> Thank you, Olga.
> Will reference
> http://hadoop.apache.org/core/docs/current/cluster_setup.html#Configuration+Fi
> les and try to specify more memory.
>
> Regards,
> Avram
>
>
>
> -----Original Message-----
> From: Olga Natkovich [mailto:olgan@yahoo-inc.com]
> Sent: Thursday, March 19, 2009 2:21 PM
> To: pig-user@hadoop.apache.org
> Subject: RE: low memory handler?
>
> It looks like your tasks are configured to use 200 MB. This is usually
> not sufficient for large data processing. In general, you need at least
> 500 MB, 1 GB recommended and if you have more memory on your machine,
> configuring more can further help your query execution. The amount of
> course depends on how much memory you have on your machines and how many
> map and reduce slots they have.
>
> Olga
>
>> -----Original Message-----
>> From: Avram Aelony [mailto:AvramAelony@eharmony.com]
>> Sent: Thursday, March 19, 2009 2:14 PM
>> To: pig-user@hadoop.apache.org
>> Subject: low memory handler?
>>
>> Hello Pig List,
>>
>> I am now taking my (tested) pig script that will produce
>> distinct counts and trying to apply it to real data. I am
>> finding however, that though the map stage completes (100%),
>> the reduce stage hangs at 97.77% and then fails to produce output.
>>
>> It appears that the syslog contains notices of "threshold
>> exceeded" before the ultimate failure...
>>
>> 2009-03-19 10:54:10,525 INFO
>> org.apache.pig.impl.util.SpillableMemoryManager: low memory
>> handler called (Usage threshold exceeded) init =
>> 1441792(1408K) used = 131343896(128265K) committed =
>> 186449920(182080K) max = 186449920(182080K)
>> 2009-03-19 10:54:18,150 INFO
>> org.apache.pig.impl.util.SpillableMemoryManager: low memory
>> handler called (Usage threshold exceeded) init =
>> 1441792(1408K) used = 131311248(128233K) committed =
>> 186449920(182080K) max = 186449920(182080K)
>> 2009-03-19 10:54:25,833 INFO
>> org.apache.pig.impl.util.SpillableMemoryManager: low memory
>> handler called (Usage threshold exceeded) init =
>> 1441792(1408K) used = 133580568(130449K) committed =
>> 186449920(182080K) max = 186449920(182080K)
>>
>> ...
>>
>> Does this mean that the Hadoop cluster requires tuning?
>>
>> How can I avoid this memory error?
>>
>>
>>
>> Regards,
>> Avram
>>
>>
----------------------
Yiping Han
2MC 8127
2811 Mission College Blvd.,
Santa Clara, CA 95054
(408)349-4403
yhan@yahoo-inc.com
Re: low memory handler?
Posted by Yiping Han <yh...@yahoo-inc.com>.
Avram,
Could you please post your syslog so we see the behavior of
spillableMemoryManager?
-Yiping
On 3/20/09 11:46 AM, "Avram Aelony" <Av...@eharmony.com> wrote:
> Hi Pig List,
>
> After tinkering with the mapred.child.java.opts property -Xmx200m setting and
> trying 512, 1024, 2048 values (e.g. Xmx512m ), none of these seem to solve the
> problem. Map tasks complete 100% but Reduce tasks are killed never proceeding
> past 98.88% complete. I am setting the config changes in hadoop-site.xml.
>
> Can you provide guidance as to which parameters are relevant here and what
> settings to use?
>
> Thanks for your help,
>
> Avram
>
>
>
> -----Original Message-----
> From: Avram Aelony
> Sent: Thursday, March 19, 2009 2:35 PM
> To: pig-user@hadoop.apache.org
> Subject: RE: low memory handler?
>
>
> Thank you, Olga.
> Will reference
> http://hadoop.apache.org/core/docs/current/cluster_setup.html#Configuration+Fi
> les and try to specify more memory.
>
> Regards,
> Avram
>
>
>
> -----Original Message-----
> From: Olga Natkovich [mailto:olgan@yahoo-inc.com]
> Sent: Thursday, March 19, 2009 2:21 PM
> To: pig-user@hadoop.apache.org
> Subject: RE: low memory handler?
>
> It looks like your tasks are configured to use 200 MB. This is usually
> not sufficient for large data processing. In general, you need at least
> 500 MB, 1 GB recommended and if you have more memory on your machine,
> configuring more can further help your query execution. The amount of
> course depends on how much memory you have on your machines and how many
> map and reduce slots they have.
>
> Olga
>
>> -----Original Message-----
>> From: Avram Aelony [mailto:AvramAelony@eharmony.com]
>> Sent: Thursday, March 19, 2009 2:14 PM
>> To: pig-user@hadoop.apache.org
>> Subject: low memory handler?
>>
>> Hello Pig List,
>>
>> I am now taking my (tested) pig script that will produce
>> distinct counts and trying to apply it to real data. I am
>> finding however, that though the map stage completes (100%),
>> the reduce stage hangs at 97.77% and then fails to produce output.
>>
>> It appears that the syslog contains notices of "threshold
>> exceeded" before the ultimate failure...
>>
>> 2009-03-19 10:54:10,525 INFO
>> org.apache.pig.impl.util.SpillableMemoryManager: low memory
>> handler called (Usage threshold exceeded) init =
>> 1441792(1408K) used = 131343896(128265K) committed =
>> 186449920(182080K) max = 186449920(182080K)
>> 2009-03-19 10:54:18,150 INFO
>> org.apache.pig.impl.util.SpillableMemoryManager: low memory
>> handler called (Usage threshold exceeded) init =
>> 1441792(1408K) used = 131311248(128233K) committed =
>> 186449920(182080K) max = 186449920(182080K)
>> 2009-03-19 10:54:25,833 INFO
>> org.apache.pig.impl.util.SpillableMemoryManager: low memory
>> handler called (Usage threshold exceeded) init =
>> 1441792(1408K) used = 133580568(130449K) committed =
>> 186449920(182080K) max = 186449920(182080K)
>>
>> ...
>>
>> Does this mean that the Hadoop cluster requires tuning?
>>
>> How can I avoid this memory error?
>>
>>
>>
>> Regards,
>> Avram
>>
>>
----------------------
Yiping Han
2MC 8127
2811 Mission College Blvd.,
Santa Clara, CA 95054
(408)349-4403
yhan@yahoo-inc.com
RE: low memory handler?
Posted by Avram Aelony <Av...@eharmony.com>.
Hi Pig List,
After tinkering with the mapred.child.java.opts property -Xmx200m setting and trying 512, 1024, 2048 values (e.g. Xmx512m ), none of these seem to solve the problem. Map tasks complete 100% but Reduce tasks are killed never proceeding past 98.88% complete. I am setting the config changes in hadoop-site.xml.
Can you provide guidance as to which parameters are relevant here and what settings to use?
Thanks for your help,
Avram
-----Original Message-----
From: Avram Aelony
Sent: Thursday, March 19, 2009 2:35 PM
To: pig-user@hadoop.apache.org
Subject: RE: low memory handler?
Thank you, Olga.
Will reference http://hadoop.apache.org/core/docs/current/cluster_setup.html#Configuration+Files and try to specify more memory.
Regards,
Avram
-----Original Message-----
From: Olga Natkovich [mailto:olgan@yahoo-inc.com]
Sent: Thursday, March 19, 2009 2:21 PM
To: pig-user@hadoop.apache.org
Subject: RE: low memory handler?
It looks like your tasks are configured to use 200 MB. This is usually
not sufficient for large data processing. In general, you need at least
500 MB, 1 GB recommended and if you have more memory on your machine,
configuring more can further help your query execution. The amount of
course depends on how much memory you have on your machines and how many
map and reduce slots they have.
Olga
> -----Original Message-----
> From: Avram Aelony [mailto:AvramAelony@eharmony.com]
> Sent: Thursday, March 19, 2009 2:14 PM
> To: pig-user@hadoop.apache.org
> Subject: low memory handler?
>
> Hello Pig List,
>
> I am now taking my (tested) pig script that will produce
> distinct counts and trying to apply it to real data. I am
> finding however, that though the map stage completes (100%),
> the reduce stage hangs at 97.77% and then fails to produce output.
>
> It appears that the syslog contains notices of "threshold
> exceeded" before the ultimate failure...
>
> 2009-03-19 10:54:10,525 INFO
> org.apache.pig.impl.util.SpillableMemoryManager: low memory
> handler called (Usage threshold exceeded) init =
> 1441792(1408K) used = 131343896(128265K) committed =
> 186449920(182080K) max = 186449920(182080K)
> 2009-03-19 10:54:18,150 INFO
> org.apache.pig.impl.util.SpillableMemoryManager: low memory
> handler called (Usage threshold exceeded) init =
> 1441792(1408K) used = 131311248(128233K) committed =
> 186449920(182080K) max = 186449920(182080K)
> 2009-03-19 10:54:25,833 INFO
> org.apache.pig.impl.util.SpillableMemoryManager: low memory
> handler called (Usage threshold exceeded) init =
> 1441792(1408K) used = 133580568(130449K) committed =
> 186449920(182080K) max = 186449920(182080K)
>
> ...
>
> Does this mean that the Hadoop cluster requires tuning?
>
> How can I avoid this memory error?
>
>
>
> Regards,
> Avram
>
>
RE: low memory handler?
Posted by Avram Aelony <Av...@eharmony.com>.
Thank you, Olga.
Will reference http://hadoop.apache.org/core/docs/current/cluster_setup.html#Configuration+Files and try to specify more memory.
Regards,
Avram
-----Original Message-----
From: Olga Natkovich [mailto:olgan@yahoo-inc.com]
Sent: Thursday, March 19, 2009 2:21 PM
To: pig-user@hadoop.apache.org
Subject: RE: low memory handler?
It looks like your tasks are configured to use 200 MB. This is usually
not sufficient for large data processing. In general, you need at least
500 MB, 1 GB recommended and if you have more memory on your machine,
configuring more can further help your query execution. The amount of
course depends on how much memory you have on your machines and how many
map and reduce slots they have.
Olga
> -----Original Message-----
> From: Avram Aelony [mailto:AvramAelony@eharmony.com]
> Sent: Thursday, March 19, 2009 2:14 PM
> To: pig-user@hadoop.apache.org
> Subject: low memory handler?
>
> Hello Pig List,
>
> I am now taking my (tested) pig script that will produce
> distinct counts and trying to apply it to real data. I am
> finding however, that though the map stage completes (100%),
> the reduce stage hangs at 97.77% and then fails to produce output.
>
> It appears that the syslog contains notices of "threshold
> exceeded" before the ultimate failure...
>
> 2009-03-19 10:54:10,525 INFO
> org.apache.pig.impl.util.SpillableMemoryManager: low memory
> handler called (Usage threshold exceeded) init =
> 1441792(1408K) used = 131343896(128265K) committed =
> 186449920(182080K) max = 186449920(182080K)
> 2009-03-19 10:54:18,150 INFO
> org.apache.pig.impl.util.SpillableMemoryManager: low memory
> handler called (Usage threshold exceeded) init =
> 1441792(1408K) used = 131311248(128233K) committed =
> 186449920(182080K) max = 186449920(182080K)
> 2009-03-19 10:54:25,833 INFO
> org.apache.pig.impl.util.SpillableMemoryManager: low memory
> handler called (Usage threshold exceeded) init =
> 1441792(1408K) used = 133580568(130449K) committed =
> 186449920(182080K) max = 186449920(182080K)
>
> ...
>
> Does this mean that the Hadoop cluster requires tuning?
>
> How can I avoid this memory error?
>
>
>
> Regards,
> Avram
>
>
RE: low memory handler?
Posted by Olga Natkovich <ol...@yahoo-inc.com>.
It looks like your tasks are configured to use 200 MB. This is usually
not sufficient for large data processing. In general, you need at least
500 MB, 1 GB recommended and if you have more memory on your machine,
configuring more can further help your query execution. The amount of
course depends on how much memory you have on your machines and how many
map and reduce slots they have.
Olga
> -----Original Message-----
> From: Avram Aelony [mailto:AvramAelony@eharmony.com]
> Sent: Thursday, March 19, 2009 2:14 PM
> To: pig-user@hadoop.apache.org
> Subject: low memory handler?
>
> Hello Pig List,
>
> I am now taking my (tested) pig script that will produce
> distinct counts and trying to apply it to real data. I am
> finding however, that though the map stage completes (100%),
> the reduce stage hangs at 97.77% and then fails to produce output.
>
> It appears that the syslog contains notices of "threshold
> exceeded" before the ultimate failure...
>
> 2009-03-19 10:54:10,525 INFO
> org.apache.pig.impl.util.SpillableMemoryManager: low memory
> handler called (Usage threshold exceeded) init =
> 1441792(1408K) used = 131343896(128265K) committed =
> 186449920(182080K) max = 186449920(182080K)
> 2009-03-19 10:54:18,150 INFO
> org.apache.pig.impl.util.SpillableMemoryManager: low memory
> handler called (Usage threshold exceeded) init =
> 1441792(1408K) used = 131311248(128233K) committed =
> 186449920(182080K) max = 186449920(182080K)
> 2009-03-19 10:54:25,833 INFO
> org.apache.pig.impl.util.SpillableMemoryManager: low memory
> handler called (Usage threshold exceeded) init =
> 1441792(1408K) used = 133580568(130449K) committed =
> 186449920(182080K) max = 186449920(182080K)
>
> ...
>
> Does this mean that the Hadoop cluster requires tuning?
>
> How can I avoid this memory error?
>
>
>
> Regards,
> Avram
>
>