No problem, glad I could help. In our test environment I have lots of output and logging turned on, but as soon as it is on production all output and logging is reduced to the bare minimum. Basically, in production we only log caught exceptions.
I would take it out unless you absolutely need it. IMHO. If your jobs are not mission critical and do not need to run as smooth as possible then it's not as important to remove those. /* Joey */ On Wed, May 23, 2012 at 10:21 PM, Mark Kerzner <mark.kerz...@shmsoft.com>wrote: > Joey, > > that did the trick! > > Actually, I am writing to the log with System.out.println() statements, and > I write about 12,000 lines, would that be a problem? I don't really need > this output, so if you think it's inadvisable, I will remove that. > > Also, I hope that if I have not 6,000 maps but 12,000 or even 30,000, it > will still work. > > Well, I will see pretty soon, I guess, with more data. > > Again, thank you. > > Sincerely, > Mark > > On Wed, May 23, 2012 at 9:43 PM, Joey Krabacher <jkrabac...@gmail.com > >wrote: > > > Mark, > > > > Have you tried tweaking the mapred.child.java.opts property in your > > mapred-site.xml? > > > > <property> > > <name>mapred.child.java.opts</name> > > <value>-Xmx2048m</value> > > </property> > > > > This might help. > > It looks like the fatal error came right after the log truncater fired > off. > > Are you outputting anything to the logs manually, or have you looked at > the > > user logs to see if there is anything taking up lots of room? > > > > / * Joey */ > > > > > > On Wed, May 23, 2012 at 9:35 PM, Mark Kerzner <mark.kerz...@shmsoft.com > > >wrote: > > > > > Joey, > > > > > > my errors closely resembles this > > > one< > > > > > > http://mail-archives.apache.org/mod_mbox/hadoop-mapreduce-user/201006.mbox/%3caanlktikr3df4ce-tgiphv9_-evfoed_5-t684nf4y...@mail.gmail.com%3E > > > >in > > > the archives. I can now be much more specific with the errors message, > > > and it is quoted below. I tried -Xmx3096. But I got the same error. > > > > > > Thank you, > > > Mark > > > > > > > > > syslog logs > > > 2012-05-23 20:04:52,349 WARN org.apache.hadoop.util.NativeCodeLoader: > > > Unable to load native-hadoop library for your platform... using > > > builtin-java classes where applicable > > > 2012-05-23 20:04:52,519 INFO org.apache.hadoop.metrics.jvm.JvmMetrics: > > > Initializing JVM Metrics with processName=MAP, sessionId= > > > 2012-05-23 20:04:52,695 INFO org.apache.hadoop.util.ProcessTree: setsid > > > exited with exit code 0 > > > 2012-05-23 20:04:52,699 INFO org.apache.hadoop.mapred.Task: Using > > > ResourceCalculatorPlugin : > > > org.apache.hadoop.util.LinuxResourceCalculatorPlugin@d56b37 > > > 2012-05-23 20:04:52,813 INFO org.apache.hadoop.mapred.MapTask: > > io.sort.mb = > > > 100 > > > 2012-05-23 20:04:52,998 INFO org.apache.hadoop.mapred.MapTask: data > > buffer > > > = 79691776/99614720 > > > 2012-05-23 20:04:52,998 INFO org.apache.hadoop.mapred.MapTask: record > > > buffer = 262144/327680 > > > 2012-05-23 20:04:53,010 WARN > > > org.apache.hadoop.io.compress.snappy.LoadSnappy: Snappy native library > > not > > > loaded > > > 2012-05-23 20:12:29,120 INFO org.apache.hadoop.mapred.MapTask: Spilling > > map > > > output: buffer full= true > > > 2012-05-23 20:12:29,134 INFO org.apache.hadoop.mapred.MapTask: > bufstart = > > > 0; bufend = 79542629; bufvoid = 99614720 > > > 2012-05-23 20:12:29,134 INFO org.apache.hadoop.mapred.MapTask: kvstart > = > > 0; > > > kvend = 228; length = 327680 > > > 2012-05-23 20:12:31,248 INFO org.apache.hadoop.mapred.MapTask: Finished > > > spill 0 > > > 2012-05-23 20:13:01,862 INFO org.apache.hadoop.mapred.MapTask: Spilling > > map > > > output: buffer full= true > > > 2012-05-23 20:13:01,862 INFO org.apache.hadoop.mapred.MapTask: > bufstart = > > > 79542629; bufend = 53863940; bufvoid = 99614720 > > > 2012-05-23 20:13:01,862 INFO org.apache.hadoop.mapred.MapTask: kvstart > = > > > 228; kvend = 431; length = 327680 > > > 2012-05-23 20:13:03,294 INFO org.apache.hadoop.mapred.MapTask: Finished > > > spill 1 > > > 2012-05-23 20:13:48,121 INFO org.apache.hadoop.mapred.MapTask: Spilling > > map > > > output: buffer full= true > > > 2012-05-23 20:13:48,122 INFO org.apache.hadoop.mapred.MapTask: > bufstart = > > > 53863940; bufend = 31696780; bufvoid = 99614720 > > > 2012-05-23 20:13:48,122 INFO org.apache.hadoop.mapred.MapTask: kvstart > = > > > 431; kvend = 861; length = 327680 > > > 2012-05-23 20:13:49,818 INFO org.apache.hadoop.mapred.MapTask: Finished > > > spill 2 > > > 2012-05-23 20:15:25,618 INFO org.apache.hadoop.mapred.MapTask: Spilling > > map > > > output: buffer full= true > > > 2012-05-23 20:15:25,618 INFO org.apache.hadoop.mapred.MapTask: > bufstart = > > > 31696780; bufend = 10267329; bufvoid = 99614720 > > > 2012-05-23 20:15:25,618 INFO org.apache.hadoop.mapred.MapTask: kvstart > = > > > 861; kvend = 1462; length = 327680 > > > 2012-05-23 20:15:27,068 INFO org.apache.hadoop.mapred.MapTask: Finished > > > spill 3 > > > 2012-05-23 20:15:53,519 INFO org.apache.hadoop.mapred.MapTask: Spilling > > map > > > output: buffer full= true > > > 2012-05-23 20:15:53,519 INFO org.apache.hadoop.mapred.MapTask: > bufstart = > > > 10267329; bufend = 85241086; bufvoid = 99614720 > > > 2012-05-23 20:15:53,519 INFO org.apache.hadoop.mapred.MapTask: kvstart > = > > > 1462; kvend = 1642; length = 327680 > > > 2012-05-23 20:15:54,760 INFO org.apache.hadoop.mapred.MapTask: Finished > > > spill 4 > > > 2012-05-23 20:16:26,284 INFO org.apache.hadoop.mapred.MapTask: Spilling > > map > > > output: buffer full= true > > > 2012-05-23 20:16:26,284 INFO org.apache.hadoop.mapred.MapTask: > bufstart = > > > 85241086; bufend = 51305930; bufvoid = 99614720 > > > 2012-05-23 20:16:26,284 INFO org.apache.hadoop.mapred.MapTask: kvstart > = > > > 1642; kvend = 1946; length = 327680 > > > 2012-05-23 20:16:27,566 INFO org.apache.hadoop.mapred.MapTask: Finished > > > spill 5 > > > 2012-05-23 20:16:57,046 INFO org.apache.hadoop.mapred.MapTask: Spilling > > map > > > output: buffer full= true > > > 2012-05-23 20:16:57,046 INFO org.apache.hadoop.mapred.MapTask: > bufstart = > > > 51305930; bufend = 31353466; bufvoid = 99614720 > > > 2012-05-23 20:16:57,046 INFO org.apache.hadoop.mapred.MapTask: kvstart > = > > > 1946; kvend = 2263; length = 327680 > > > 2012-05-23 20:16:58,076 INFO org.apache.hadoop.mapred.MapTask: Finished > > > spill 6 > > > 2012-05-23 20:17:52,820 INFO org.apache.hadoop.mapred.MapTask: Spilling > > map > > > output: buffer full= true > > > 2012-05-23 20:17:52,820 INFO org.apache.hadoop.mapred.MapTask: > bufstart = > > > 31353466; bufend = 10945750; bufvoid = 99614720 > > > 2012-05-23 20:17:52,820 INFO org.apache.hadoop.mapred.MapTask: kvstart > = > > > 2263; kvend = 2755; length = 327680 > > > 2012-05-23 20:17:53,939 INFO org.apache.hadoop.mapred.MapTask: Finished > > > spill 7 > > > 2012-05-23 20:18:19,528 INFO org.apache.hadoop.mapred.MapTask: Spilling > > map > > > output: buffer full= true > > > 2012-05-23 20:18:19,528 INFO org.apache.hadoop.mapred.MapTask: > bufstart = > > > 10945750; bufend = 81838103; bufvoid = 99614720 > > > 2012-05-23 20:18:19,528 INFO org.apache.hadoop.mapred.MapTask: kvstart > = > > > 2755; kvend = 2967; length = 327680 > > > 2012-05-23 20:18:21,145 INFO org.apache.hadoop.mapred.MapTask: Finished > > > spill 8 > > > 2012-05-23 20:18:52,353 INFO org.apache.hadoop.mapred.MapTask: Spilling > > map > > > output: buffer full= true > > > 2012-05-23 20:18:52,353 INFO org.apache.hadoop.mapred.MapTask: > bufstart = > > > 81838103; bufend = 61751422; bufvoid = 99614720 > > > 2012-05-23 20:18:52,353 INFO org.apache.hadoop.mapred.MapTask: kvstart > = > > > 2967; kvend = 3202; length = 327680 > > > 2012-05-23 20:18:53,485 INFO org.apache.hadoop.mapred.MapTask: Finished > > > spill 9 > > > 2012-05-23 20:19:42,993 INFO org.apache.hadoop.mapred.MapTask: Spilling > > map > > > output: buffer full= true > > > 2012-05-23 20:19:42,993 INFO org.apache.hadoop.mapred.MapTask: > bufstart = > > > 61751422; bufend = 38440188; bufvoid = 99614720 > > > 2012-05-23 20:19:42,993 INFO org.apache.hadoop.mapred.MapTask: kvstart > = > > > 3202; kvend = 3628; length = 327680 > > > 2012-05-23 20:19:44,346 INFO org.apache.hadoop.mapred.MapTask: Finished > > > spill 10 > > > 2012-05-23 20:20:47,957 INFO org.apache.hadoop.mapred.MapTask: Spilling > > map > > > output: buffer full= true > > > 2012-05-23 20:20:47,957 INFO org.apache.hadoop.mapred.MapTask: > bufstart = > > > 38440188; bufend = 18376423; bufvoid = 99614720 > > > 2012-05-23 20:20:47,957 INFO org.apache.hadoop.mapred.MapTask: kvstart > = > > > 3628; kvend = 4252; length = 327680 > > > 2012-05-23 20:20:48,767 INFO org.apache.hadoop.mapred.MapTask: Finished > > > spill 11 > > > 2012-05-23 20:21:19,207 INFO org.apache.hadoop.mapred.MapTask: Spilling > > map > > > output: buffer full= true > > > 2012-05-23 20:21:19,207 INFO org.apache.hadoop.mapred.MapTask: > bufstart = > > > 18376423; bufend = 97890160; bufvoid = 99614720 > > > 2012-05-23 20:21:19,207 INFO org.apache.hadoop.mapred.MapTask: kvstart > = > > > 4252; kvend = 4488; length = 327680 > > > 2012-05-23 20:21:20,176 INFO org.apache.hadoop.mapred.MapTask: Finished > > > spill 12 > > > 2012-05-23 20:21:47,395 INFO org.apache.hadoop.mapred.MapTask: Spilling > > map > > > output: buffer full= true > > > 2012-05-23 20:21:47,395 INFO org.apache.hadoop.mapred.MapTask: > bufstart = > > > 97890160; bufend = 77234938; bufvoid = 99614720 > > > 2012-05-23 20:21:47,395 INFO org.apache.hadoop.mapred.MapTask: kvstart > = > > > 4488; kvend = 4771; length = 327680 > > > 2012-05-23 20:21:48,383 INFO org.apache.hadoop.mapred.MapTask: Finished > > > spill 13 > > > 2012-05-23 20:22:21,086 INFO org.apache.hadoop.mapred.MapTask: Spilling > > map > > > output: buffer full= true > > > 2012-05-23 20:22:21,086 INFO org.apache.hadoop.mapred.MapTask: > bufstart = > > > 77234938; bufend = 52962105; bufvoid = 99614720 > > > 2012-05-23 20:22:21,086 INFO org.apache.hadoop.mapred.MapTask: kvstart > = > > > 4771; kvend = 5203; length = 327680 > > > 2012-05-23 20:22:21,641 INFO org.apache.hadoop.mapred.MapTask: Finished > > > spill 14 > > > 2012-05-23 20:22:46,559 INFO org.apache.hadoop.mapred.MapTask: Starting > > > flush of map output > > > 2012-05-23 20:22:46,615 INFO org.apache.hadoop.mapred.MapTask: Finished > > > spill 15 > > > 2012-05-23 20:22:47,606 INFO org.apache.hadoop.mapred.Merger: Merging > 16 > > > sorted segments > > > 2012-05-23 20:22:47,696 INFO org.apache.hadoop.mapred.Merger: Merging 7 > > > intermediate segments out of a total of 16 > > > 2012-05-23 20:22:58,083 INFO > org.apache.hadoop.mapred.TaskLogsTruncater: > > > Initializing logs' truncater with mapRetainSize=-1 and > > reduceRetainSize=-1 > > > 2012-05-23 20:22:58,108 FATAL org.apache.hadoop.mapred.Child: Error > > running > > > child : java.lang.OutOfMemoryError: Java heap space > > > at > org.apache.hadoop.mapred.IFile$Reader.readNextBlock(IFile.java:355) > > > at org.apache.hadoop.mapred.IFile$Reader.next(IFile.java:417) > > > at org.apache.hadoop.mapred.Merger$Segment.next(Merger.java:220) > > > at > > > > > > > > > org.apache.hadoop.mapred.Merger$MergeQueue.adjustPriorityQueue(Merger.java:330) > > > at org.apache.hadoop.mapred.Merger$MergeQueue.next(Merger.java:350) > > > at org.apache.hadoop.mapred.Merger.writeFile(Merger.java:156) > > > at org.apache.hadoop.mapred.Merger$MergeQueue.merge(Merger.java:499) > > > at org.apache.hadoop.mapred.Merger$MergeQueue.merge(Merger.java:381) > > > at org.apache.hadoop.mapred.Merger.merge(Merger.java:77) > > > at > > > > > > > > > org.apache.hadoop.mapred.MapTask$MapOutputBuffer.mergeParts(MapTask.java:1548) > > > at > > > > org.apache.hadoop.mapred.MapTask$MapOutputBuffer.flush(MapTask.java:1180) > > > at > > > > > > org.apache.hadoop.mapred.MapTask$NewOutputCollector.close(MapTask.java:582) > > > at org.apache.hadoop.mapred.MapTask.runNewMapper(MapTask.java:649) > > > at org.apache.hadoop.mapred.MapTask.run(MapTask.java:323) > > > at org.apache.hadoop.mapred.Child$4.run(Child.java:270) > > > at java.security.AccessController.doPrivileged(Native Method) > > > at javax.security.auth.Subject.doAs(Subject.java:396) > > > at > > > > > > > > > org.apache.hadoop.security.UserGroupInformation.doAs(UserGroupInformation.java:1177) > > > at org.apache.hadoop.mapred.Child.main(Child.java:264) > > > > > > On Wed, May 23, 2012 at 2:47 PM, Joey Krabacher <jkrabac...@gmail.com > > > >wrote: > > > > > > > My experience with this sort of problem tells me one of two things > and > > > > maybe both: > > > > > > > > 1. there are some optimizations to the code that can be made > (variable > > > > re-creation inside of loops, etc.) > > > > 2. something has gone horribly wrong with the logic in the mapper. > > > > > > > > To troubleshoot I would output some log entries at specific points in > > the > > > > mapper (be careful not to log every execution of the mapper because > > this > > > > could cause major issues with the disk filling up and that sort of > > > thing.) > > > > > > > > Hope that helps. > > > > > > > > /* Joey */ > > > > > > > > On Wed, May 23, 2012 at 2:16 PM, Mark Kerzner < > > mark.kerz...@shmsoft.com > > > > >wrote: > > > > > > > > > Hi, all, > > > > > > > > > > I got the exception below in the mapper. I already have my global > > > Hadoop > > > > > heap at 5 GB, but is there a specific other setting? Or maybe I > > should > > > > > troubleshoot for memory? > > > > > > > > > > But the same application works in the IDE. > > > > > > > > > > Thank you! > > > > > > > > > > Mark > > > > > > > > > > *stderr logs* > > > > > > > > > > Exception in thread "Thread for syncLogs" > java.lang.OutOfMemoryError: > > > > > Java heap space > > > > > at > > > > java.io.BufferedOutputStream.<init>(BufferedOutputStream.java:76) > > > > > at > > > > java.io.BufferedOutputStream.<init>(BufferedOutputStream.java:59) > > > > > at > > > > > org.apache.hadoop.mapred.TaskLog.writeToIndexFile(TaskLog.java:292) > > > > > at > org.apache.hadoop.mapred.TaskLog.syncLogs(TaskLog.java:365) > > > > > at org.apache.hadoop.mapred.Child$3.run(Child.java:157) > > > > > Exception in thread "communication thread" > > java.lang.OutOfMemoryError: > > > > > Java heap space > > > > > > > > > > Exception: java.lang.OutOfMemoryError thrown from the > > > > > UncaughtExceptionHandler in thread "communication thread" > > > > > > > > > > > > > > >
