AnsweredAssumed Answered

Weird Hive issues: Large Text Files, Splits, and odd java issues

Question asked by mandoskippy on Aug 21, 2014
Latest reply on Aug 21, 2014 by mandoskippy
We are running a query on a bunch of data and there are large, non-compressed txt files in this data.  Our splits are laid out and the file is getting split up properly (it's a roughly 4GB file, with the standard splits) however, some splits are just failing/timing out with the weirdest and most least helpful hive errors I've seen. Granted this data may be messed up, I am wondering if there is something else going on here. Note when my job is trying to run, there are node heart beat issues as well, AND when I tried to do a tail on the fail via NFS it took a long time (There were other operations happening on the MapR NFS server, so it may or may not be related there...)  Thoughts on what these errors mean or how to trouble shoot?

Task Logs: 'attempt_201408081313_0194_m_000361_1'


stdout logs

2014-08-21 12:32:56
Full thread dump Java HotSpot(TM) 64-Bit Server VM (23.25-b01 mixed mode):

"SpillThread" daemon prio=10 tid=0x00007f7f34919000 nid=0x6ec8 waiting on condition [0x00007f7f06b99000]
   java.lang.Thread.State: WAITING (parking)
        at sun.misc.Unsafe.park(Native Method)
        - parking to wait for  <0x00000000d6bf3240> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
        at java.util.concurrent.locks.LockSupport.park(LockSupport.java:186)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2043)
        at org.apache.hadoop.mapred.MapTask$MapOutputBuffer$SpillThread.run(MapTask.java:1474)

"MapR RA" daemon prio=10 tid=0x00007f7f348f8000 nid=0x6ec7 in Object.wait() [0x00007f7f076a3000]
   java.lang.Thread.State: WAITING (on object monitor)
        at java.lang.Object.wait(Native Method)
        - waiting on <0x00000000d6bf51c0> (a com.mapr.fs.MapRFsInStream$RAThread)
        at java.lang.Object.wait(Object.java:503)
        at com.mapr.fs.MapRFsInStream$RAThread.run(MapRFsInStream.java:577)
        - locked <0x00000000d6bf51c0> (a com.mapr.fs.MapRFsInStream$RAThread)
        at java.lang.Thread.run(Thread.java:724)

"communication thread" daemon prio=10 tid=0x00007f7f3470e000 nid=0x6ebe in Object.wait() [0x00007f7f077cc000]
   java.lang.Thread.State: TIMED_WAITING (on object monitor)
        at java.lang.Object.wait(Native Method)
        - waiting on <0x00000000d6befed0> (a java.util.concurrent.atomic.AtomicBoolean)
        at org.apache.hadoop.mapred.Task$TaskReporter.run(Task.java:672)
        - locked <0x00000000d6befed0> (a java.util.concurrent.atomic.AtomicBoolean)
        at java.lang.Thread.run(Thread.java:724)

"Thread for syncLogs" daemon prio=10 tid=0x00007f7f34699800 nid=0x6eb3 waiting on condition [0x00007f7f09dd7000]
   java.lang.Thread.State: TIMED_WAITING (sleeping)
        at java.lang.Thread.sleep(Native Method)
        at org.apache.hadoop.mapred.Child$3.run(Child.java:162)

"sendParams-0" daemon prio=10 tid=0x00007f7f34697000 nid=0x6eb2 waiting on condition [0x00007f7f09ed8000]
   java.lang.Thread.State: TIMED_WAITING (parking)
        at sun.misc.Unsafe.park(Native Method)
        - parking to wait for  <0x00000000d6bf5348> (a java.util.concurrent.SynchronousQueue$TransferStack)
        at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226)
        at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460)
        at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:359)
        at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:942)
        at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1068)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
        at java.lang.Thread.run(Thread.java:724)

"IPC Client (47) connection to /127.0.0.1:48997 from job_201408081313_0194" daemon prio=10 tid=0x00007f7f34694800 nid=0x6eb1 in Object.wait() [0x00007f7f09fd9000]
   java.lang.Thread.State: TIMED_WAITING (on object monitor)
        at java.lang.Object.wait(Native Method)
        - waiting on <0x00000000d6bf53f0> (a org.apache.hadoop.ipc.Client$Connection)
        at org.apache.hadoop.ipc.Client$Connection.waitForWork(Client.java:718)
        - locked <0x00000000d6bf53f0> (a org.apache.hadoop.ipc.Client$Connection)
        at org.apache.hadoop.ipc.Client$Connection.run(Client.java:761)

"Service Thread" daemon prio=10 tid=0x00007f7f3410a800 nid=0x6eaf runnable [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"C2 CompilerThread1" daemon prio=10 tid=0x00007f7f34108800 nid=0x6eae waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"C2 CompilerThread0" daemon prio=10 tid=0x00007f7f34106000 nid=0x6ead waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"Signal Dispatcher" daemon prio=10 tid=0x00007f7f34104000 nid=0x6eac waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"Finalizer" daemon prio=10 tid=0x00007f7f340b5000 nid=0x6eab in Object.wait() [0x00007f7f0d124000]
   java.lang.Thread.State: WAITING (on object monitor)
        at java.lang.Object.wait(Native Method)
        - waiting on <0x00000000d6bee578> (a java.lang.ref.ReferenceQueue$Lock)
        at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:135)
        - locked <0x00000000d6bee578> (a java.lang.ref.ReferenceQueue$Lock)
        at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:151)
        at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:189)

"Reference Handler" daemon prio=10 tid=0x00007f7f340b3000 nid=0x6eaa in Object.wait() [0x00007f7f0d225000]
   java.lang.Thread.State: WAITING (on object monitor)
        at java.lang.Object.wait(Native Method)
        - waiting on <0x00000000d6bedf60> (a java.lang.ref.Reference$Lock)
        at java.lang.Object.wait(Object.java:503)
        at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:133)
        - locked <0x00000000d6bedf60> (a java.lang.ref.Reference$Lock)

"main" prio=10 tid=0x00007f7f3400a000 nid=0x6e96 runnable [0x00007f7f3a699000]
   java.lang.Thread.State: RUNNABLE
        at org.apache.hadoop.io.Text.setCapacity(Text.java:240)
        at org.apache.hadoop.io.Text.append(Text.java:216)
        at org.apache.hadoop.util.LineReader.readDefaultLine(LineReader.java:230)
        at org.apache.hadoop.util.LineReader.readLine(LineReader.java:169)
        at org.apache.hadoop.mapred.LineRecordReader.next(LineRecordReader.java:203)
        - locked <0x00000000d6bf56e0> (a org.apache.hadoop.mapred.LineRecordReader)
        at org.apache.hadoop.mapred.LineRecordReader.next(LineRecordReader.java:43)
        at org.apache.hadoop.hive.ql.io.HiveContextAwareRecordReader.doNext(HiveContextAwareRecordReader.java:351)
        at org.apache.hadoop.hive.ql.io.CombineHiveRecordReader.doNext(CombineHiveRecordReader.java:101)
        at org.apache.hadoop.hive.ql.io.CombineHiveRecordReader.doNext(CombineHiveRecordReader.java:41)
        at org.apache.hadoop.hive.ql.io.HiveContextAwareRecordReader.next(HiveContextAwareRecordReader.java:123)
        at org.apache.hadoop.hive.shims.HadoopShimsSecure$CombineFileRecordReader.doNextWithExceptionHandler(HadoopShimsSecure.java:261)
        at org.apache.hadoop.hive.shims.HadoopShimsSecure$CombineFileRecordReader.next(HadoopShimsSecure.java:178)
        at org.apache.hadoop.mapred.MapTask$TrackedRecordReader.moveToNext(MapTask.java:227)
        - eliminated <0x00000000d6bf57d8> (a org.apache.hadoop.mapred.MapTask$TrackedRecordReader)
        at org.apache.hadoop.mapred.MapTask$TrackedRecordReader.next(MapTask.java:212)
        - locked <0x00000000d6bf57d8> (a org.apache.hadoop.mapred.MapTask$TrackedRecordReader)
        at org.apache.hadoop.mapred.MapRunner.run(MapRunner.java:48)
        at org.apache.hadoop.mapred.MapTask.runOldMapper(MapTask.java:417)
        at org.apache.hadoop.mapred.MapTask.run(MapTask.java:348)
        at org.apache.hadoop.mapred.Child$4.run(Child.java:282)
        at java.security.AccessController.doPrivileged(Native Method)
        at javax.security.auth.Subject.doAs(Subject.java:415)
        at org.apache.hadoop.security.UserGroupInformation.doAs(UserGroupInformation.java:1117)
        at org.apache.hadoop.mapred.Child.main(Child.java:271)

"VM Thread" prio=10 tid=0x00007f7f340ab000 nid=0x6ea9 runnable

"GC task thread#0 (ParallelGC)" prio=10 tid=0x00007f7f34013000 nid=0x6e97 runnable

"GC task thread#1 (ParallelGC)" prio=10 tid=0x00007f7f34014800 nid=0x6e98 runnable

"GC task thread#2 (ParallelGC)" prio=10 tid=0x00007f7f34016800 nid=0x6e99 runnable

"GC task thread#3 (ParallelGC)" prio=10 tid=0x00007f7f34018800 nid=0x6e9a runnable

"GC task thread#4 (ParallelGC)" prio=10 tid=0x00007f7f3401a000 nid=0x6e9b runnable

"GC task thread#5 (ParallelGC)" prio=10 tid=0x00007f7f3401c000 nid=0x6e9c runnable

"GC task thread#6 (ParallelGC)" prio=10 tid=0x00007f7f3401e000 nid=0x6e9d runnable

"GC task thread#7 (ParallelGC)" prio=10 tid=0x00007f7f3401f800 nid=0x6e9e runnable

"GC task thread#8 (ParallelGC)" prio=10 tid=0x00007f7f34021800 nid=0x6e9f runnable

"GC task thread#9 (ParallelGC)" prio=10 tid=0x00007f7f34023800 nid=0x6ea0 runnable

"GC task thread#10 (ParallelGC)" prio=10 tid=0x00007f7f34025000 nid=0x6ea1 runnable

"GC task thread#11 (ParallelGC)" prio=10 tid=0x00007f7f34027000 nid=0x6ea2 runnable

"GC task thread#12 (ParallelGC)" prio=10 tid=0x00007f7f34029000 nid=0x6ea3 runnable

"GC task thread#13 (ParallelGC)" prio=10 tid=0x00007f7f3402b000 nid=0x6ea4 runnable

"GC task thread#14 (ParallelGC)" prio=10 tid=0x00007f7f3402c800 nid=0x6ea5 runnable

"GC task thread#15 (ParallelGC)" prio=10 tid=0x00007f7f3402e800 nid=0x6ea6 runnable

"GC task thread#16 (ParallelGC)" prio=10 tid=0x00007f7f34030800 nid=0x6ea7 runnable

"GC task thread#17 (ParallelGC)" prio=10 tid=0x00007f7f34032000 nid=0x6ea8 runnable

"VM Periodic Task Thread" prio=10 tid=0x00007f7f34114800 nid=0x6eb0 waiting on condition

JNI global references: 190

Heap
 PSYoungGen      total 233024K, used 72376K [0x00000000eaab0000, 0x0000000100000000, 0x0000000100000000)
  eden space 116544K, 62% used [0x00000000eaab0000,0x00000000ef15e020,0x00000000f1c80000)
  from space 116480K, 0% used [0x00000000f1c80000,0x00000000f1c80000,0x00000000f8e40000)
  to   space 116480K, 0% used [0x00000000f8e40000,0x00000000f8e40000,0x0000000100000000)
 ParOldGen       total 699072K, used 452067K [0x00000000c0000000, 0x00000000eaab0000, 0x00000000eaab0000)
  object space 699072K, 64% used [0x00000000c0000000,0x00000000db978d58,0x00000000eaab0000)
 PSPermGen       total 21504K, used 15698K [0x00000000bae00000, 0x00000000bc300000, 0x00000000c0000000)
  object space 21504K, 73% used [0x00000000bae00000,0x00000000bbd549b0,0x00000000bc300000)


stderr logs


syslog logs

2014-08-21 12:22:45,742 INFO org.apache.hadoop.mapred.Child: JVM: jvm_201408081313_0194_m_1422366458 pid: 28305
2014-08-21 12:22:46,469 INFO org.apache.hadoop.mapred.TaskRunner: Creating symlink: /tmp/mapr-hadoop/mapred/local/taskTracker/distcache/-8245383958482546028_1531870852_2036229689/maprfs/user/hive/scratchdir/hive_2014-08-21_12-20-16_965_1732863509675244983-2/-mr-10004/33b1177f-f3b1-416d-a7c5-670a03c2d428/map.xml <- /tmp/mapr-hadoop/mapred/local/taskTracker/mapr/jobcache/job_201408081313_0194/attempt_201408081313_0194_m_000361_1/work/map.xml
2014-08-21 12:22:46,470 INFO org.apache.hadoop.mapred.TaskRunner: Creating symlink: /tmp/mapr-hadoop/mapred/local/taskTracker/distcache/5505713183818715015_450441634_2036229719/maprfs/user/hive/scratchdir/hive_2014-08-21_12-20-16_965_1732863509675244983-2/-mr-10004/33b1177f-f3b1-416d-a7c5-670a03c2d428/reduce.xml <- /tmp/mapr-hadoop/mapred/local/taskTracker/mapr/jobcache/job_201408081313_0194/attempt_201408081313_0194_m_000361_1/work/reduce.xml
2014-08-21 12:22:46,477 INFO org.apache.hadoop.filecache.TrackerDistributedCacheManager: Creating symlink: /tmp/mapr-hadoop/mapred/local/taskTracker/mapr/jobcache/job_201408081313_0194/jars/job.jar <- /tmp/mapr-hadoop/mapred/local/taskTracker/mapr/jobcache/job_201408081313_0194/attempt_201408081313_0194_m_000361_1/work/job.jar
2014-08-21 12:22:46,478 INFO org.apache.hadoop.filecache.TrackerDistributedCacheManager: Creating symlink: /tmp/mapr-hadoop/mapred/local/taskTracker/mapr/jobcache/job_201408081313_0194/jars/.job.jar.crc <- /tmp/mapr-hadoop/mapred/local/taskTracker/mapr/jobcache/job_201408081313_0194/attempt_201408081313_0194_m_000361_1/work/.job.jar.crc
2014-08-21 12:22:46,511 INFO org.apache.hadoop.mapred.Child: Starting task attempt_201408081313_0194_m_000361_1
2014-08-21 12:22:46,513 INFO org.apache.hadoop.metrics.jvm.JvmMetrics: Initializing JVM Metrics with processName=MAP, sessionId=
2014-08-21 12:22:46,637 INFO org.apache.hadoop.mapreduce.util.ProcessTree: setsid exited with exit code 0
2014-08-21 12:22:46,646 WARN org.apache.hadoop.mapreduce.util.ProcfsBasedProcessTree: /proc/<pid>/status does not have information about swap space used(VmSwap). Can not track swap usage of a task.
2014-08-21 12:22:46,647 INFO org.apache.hadoop.mapred.Task:  Using ResourceCalculatorPlugin : org.apache.hadoop.mapreduce.util.LinuxResourceCalculatorPlugin@7de04525
2014-08-21 12:22:47,079 INFO org.apache.hadoop.hive.ql.log.PerfLogger: <PERFLOG method=deserializePlan from=org.apache.hadoop.hive.ql.exec.Utilities>
2014-08-21 12:22:47,079 INFO org.apache.hadoop.hive.ql.exec.Utilities: Deserializing MapWork via kryo
2014-08-21 12:22:47,341 INFO org.apache.hadoop.hive.ql.log.PerfLogger: </PERFLOG method=deserializePlan start=1408638167079 end=1408638167341 duration=262 from=org.apache.hadoop.hive.ql.exec.Utilities>
2014-08-21 12:22:47,361 WARN org.apache.hadoop.io.compress.snappy.LoadSnappy: Snappy native library is available
2014-08-21 12:22:47,361 INFO org.apache.hadoop.io.compress.snappy.LoadSnappy: Snappy native library loaded
2014-08-21 12:22:47,391 INFO org.apache.hadoop.hive.ql.io.HiveContextAwareRecordReader: Processing file maprfs:/etl/archive/data/externalsorted/txt/data_mtime_1404984445_atime_1408530322_name.txt
2014-08-21 12:22:47,569 INFO org.apache.hadoop.hive.ql.exec.mr.ExecMapper: maximum memory = 1029046272
2014-08-21 12:22:47,569 INFO org.apache.hadoop.hive.ql.exec.mr.ExecMapper: conf classpath = [file:/opt/mapr/hadoop/hadoop-0.20.2/conf/, file:/usr/lib/jvm/jdk1.7.0_25/jre/lib/tools.jar, file:/opt/mapr/hadoop/hadoop-0.20.2/, file:/opt/mapr/hadoop/hadoop-0.20.2/hadoop*core*.jar, file:/opt/mapr/hadoop/hadoop-0.20.2/lib/amazon-s3.jar, file:/opt/mapr/hadoop/hadoop-0.20.2/lib/asm-3.2.jar, file:/opt/mapr/hadoop/hadoop-0.20.2/lib/aspectjrt-1.6.5.jar, file:/opt/mapr/hadoop/hadoop-0.20.2/lib/aspectjtools-1.6.5.jar, file:/opt/mapr/hadoop/hadoop-0.20.2/lib/aws-java-sdk-1.3.26.jar, file:/opt/mapr/lib/baseutils-0.1.jar, file:/opt/mapr/hadoop/hadoop-0.20.2/lib/commons-cli-1.2.jar, file:/opt/mapr/hadoop/hadoop-0.20.2/lib/commons-codec-1.5.jar, file:/opt/mapr/lib/commons-collections-3.2.1.jar, file:/opt/mapr/hadoop/hadoop-0.20.2/lib/commons-configuration-1.8.jar, file:/opt/mapr/hadoop/hadoop-0.20.2/lib/commons-daemon-1.0.1.jar, file:/opt/mapr/hadoop/hadoop-0.20.2/lib/commons-el-1.0.jar, file:/opt/mapr/hadoop/hadoop-0.20.2/lib/commons-httpclient-3.0.1.jar, file:/opt/mapr/hadoop/hadoop-0.20.2/lib/commons-httpclient-3.1.jar, file:/opt/mapr/hadoop/hadoop-0.20.2/lib/commons-lang-2.6.jar, file:/opt/mapr/hadoop/hadoop-0.20.2/lib/commons-logging-1.0.4.jar, file:/opt/mapr/hadoop/hadoop-0.20.2/lib/commons-logging-1.1.1.jar, file:/opt/mapr/hadoop/hadoop-0.20.2/lib/commons-logging-api-1.0.4.jar, file:/opt/mapr/hadoop/hadoop-0.20.2/lib/commons-math-2.1.jar, file:/opt/mapr/hadoop/hadoop-0.20.2/lib/commons-net-1.4.1.jar, file:/opt/mapr/hadoop/hadoop-0.20.2/lib/commons-net-3.1.jar, file:/opt/mapr/hadoop/hadoop-0.20.2/lib/core-3.1.1.jar, file:/opt/mapr/hadoop/hadoop-0.20.2/lib/emr-metrics-1.0.jar, file:/opt/mapr/hadoop/hadoop-0.20.2/lib/eval-0.5.jar, file:/opt/mapr/hadoop/hadoop-0.20.2/lib/gson-1.4.jar, file:/opt/mapr/hadoop/hadoop-0.20.2/lib/guava-13.0.1.jar, file:/opt/mapr/hadoop/hadoop-0.20.2/lib/guava-r09-jarjar.jar, file:/opt/mapr/hadoop/hadoop-0.20.2/lib/hadoop-0.20.2-auth.jar, file:/opt/mapr/hadoop/hadoop-0.20.2/lib/hadoop-0.20.2-dev-capacity-scheduler.jar, file:/opt/mapr/hadoop/hadoop-0.20.2/lib/hadoop-0.20.2-dev-core.jar, file:/opt/mapr/hadoop/hadoop-0.20.2/lib/hadoop-0.20.2-dev-fairscheduler.jar, file:/opt/mapr/hadoop/hadoop-0.20.2/lib/hadoop-metrics-0.20.2-dev.jar, file:/opt/mapr/hadoop/hadoop-0.20.2/lib/hadoop-metrics2-0.20.2-dev.jar, file:/opt/mapr/hadoop/hadoop-0.20.2/lib/hsqldb-1.8.0.10.jar, file:/opt/mapr/hadoop/hadoop-0.20.2/lib/httpclient-4.1.1.jar, file:/opt/mapr/hadoop/hadoop-0.20.2/lib/httpcore-4.1.jar, file:/opt/mapr/hadoop/hadoop-0.20.2/lib/jackson-core-asl-1.5.2.jar, file:/opt/mapr/hadoop/hadoop-0.20.2/lib/jackson-mapper-asl-1.5.2.jar, file:/opt/mapr/hadoop/hadoop-0.20.2/lib/jasper-compiler-5.5.12.jar, file:/opt/mapr/hadoop/hadoop-0.20.2/lib/jasper-runtime-5.5.12.jar, file:/opt/mapr/hadoop/hadoop-0.20.2/lib/jersey-core-1.8.jar, file:/opt/mapr/hadoop/hadoop-0.20.2/lib/jersey-json-1.8.jar, file:/opt/mapr/hadoop/hadoop-0.20.2/lib/jersey-server-1.8.jar, file:/opt/mapr/hadoop/hadoop-0.20.2/lib/jets3t-0.6.1.jar, file:/opt/mapr/hadoop/hadoop-0.20.2/lib/jetty-6.1.26.jar, file:/opt/mapr/hadoop/hadoop-0.20.2/lib/jetty-plus-6.1.26.jar, file:/opt/mapr/hadoop/hadoop-0.20.2/lib/jetty-servlet-tester-6.1.26.jar, file:/opt/mapr/hadoop/hadoop-0.20.2/lib/jetty-util-6.1.26.jar, file:/opt/mapr/hadoop/hadoop-0.20.2/lib/junit-4.5.jar, file:/opt/mapr/hadoop/hadoop-0.20.2/lib/kfs-0.2.2.jar, file:/opt/mapr/hadoop/hadoop-0.20.2/lib/log4j-1.2.15.jar, file:/opt/mapr/hadoop/hadoop-0.20.2/lib/logging-0.1.jar, file:/opt/mapr/hadoop/hadoop-0.20.2/lib/mapr-hbase-1.0.3-mapr-3.1.0-tests.jar, file:/opt/mapr/hadoop/hadoop-0.20.2/lib/mapr-hbase-1.0.3-mapr-3.1.0.jar, file:/opt/mapr/lib/maprfs-1.0.3-mapr-3.1.0.jar, file:/opt/mapr/lib/maprfs-core-1.0.3-mapr-3.1.0-tests.jar, file:/opt/mapr/lib/maprfs-core-1.0.3-mapr-3.1.0.jar, file:/opt/mapr/lib/maprfs-diagnostic-tools-1.0.3-mapr-3.1.0.jar, file:/opt/mapr/lib/maprfs-jni-1.0.3-mapr-3.1.0.jar, file:/opt/mapr/hadoop/hadoop-0.20.2/lib/mockito-all-1.8.2.jar, file:/opt/mapr/hadoop/hadoop-0.20.2/lib/mockito-all-1.8.5.jar, file:/opt/mapr/hadoop/hadoop-0.20.2/lib/mysql-connector-java-5.1.25-bin.jar, file:/opt/mapr/hadoop/hadoop-0.20.2/lib/oro-2.0.8.jar, file:/opt/mapr/hadoop/hadoop-0.20.2/lib/protobuf-java-2.4.1.jar, file:/opt/mapr/hadoop/hadoop-0.20.2/lib/servlet-api-2.5-20081211.jar, file:/opt/mapr/hadoop/hadoop-0.20.2/lib/servlet-api-2.5-6.1.14.jar, file:/opt/mapr/lib/slf4j-api-1.6.1.jar, file:/opt/mapr/lib/slf4j-log4j12-1.6.1.jar, file:/opt/mapr/hadoop/hadoop-0.20.2/lib/xmlenc-0.52.jar, file:/opt/mapr/hadoop/hadoop-0.20.2/lib/zookeeper-3.4.5-mapr-1401.jar, file:/opt/mapr/hadoop/hadoop-0.20.2/lib/jsp-2.1/jsp-2.1.jar, file:/opt/mapr/hadoop/hadoop-0.20.2/lib/jsp-2.1/jsp-api-2.1.jar, file:/opt/mapr/lib/kvstore-0.1.jar, file:/opt/mapr/lib/protobuf-java-2.4.1-lite.jar, file:/opt/mapr/lib/libprotodefs.jar, file:/opt/mapr/lib/baseutils-0.1.jar, file:/opt/mapr/lib/json-20080701.jar, file:/opt/mapr/lib/flexjson-2.1.jar, file:/opt/mapr/hadoop/hadoop-0.20.2/lib/hadoop-0.20.2-auth.jar, file:/opt/mapr/lib/JPam-1.1.jar, file:/tmp/mapr-hadoop/mapred/local/taskTracker/mapr/jobcache/job_201408081313_0194/jars/classes, file:/tmp/mapr-hadoop/mapred/local/taskTracker/mapr/jobcache/job_201408081313_0194/jars/job.jar, file:/tmp/mapr-hadoop/mapred/local/taskTracker/mapr/jobcache/job_201408081313_0194/attempt_201408081313_0194_m_000361_1/work/]
2014-08-21 12:22:47,570 INFO org.apache.hadoop.hive.ql.exec.mr.ExecMapper: thread classpath = [file:/opt/mapr/hadoop/hadoop-0.20.2/conf/, file:/usr/lib/jvm/jdk1.7.0_25/jre/lib/tools.jar, file:/opt/mapr/hadoop/hadoop-0.20.2/, file:/opt/mapr/hadoop/hadoop-0.20.2/hadoop*core*.jar, file:/opt/mapr/hadoop/hadoop-0.20.2/lib/amazon-s3.jar, file:/opt/mapr/hadoop/hadoop-0.20.2/lib/asm-3.2.jar, file:/opt/mapr/hadoop/hadoop-0.20.2/lib/aspectjrt-1.6.5.jar, file:/opt/mapr/hadoop/hadoop-0.20.2/lib/aspectjtools-1.6.5.jar, file:/opt/mapr/hadoop/hadoop-0.20.2/lib/aws-java-sdk-1.3.26.jar, file:/opt/mapr/lib/baseutils-0.1.jar, file:/opt/mapr/hadoop/hadoop-0.20.2/lib/commons-cli-1.2.jar, file:/opt/mapr/hadoop/hadoop-0.20.2/lib/commons-codec-1.5.jar, file:/opt/mapr/lib/commons-collections-3.2.1.jar, file:/opt/mapr/hadoop/hadoop-0.20.2/lib/commons-configuration-1.8.jar, file:/opt/mapr/hadoop/hadoop-0.20.2/lib/commons-daemon-1.0.1.jar, file:/opt/mapr/hadoop/hadoop-0.20.2/lib/commons-el-1.0.jar, file:/opt/mapr/hadoop/hadoop-0.20.2/lib/commons-httpclient-3.0.1.jar, file:/opt/mapr/hadoop/hadoop-0.20.2/lib/commons-httpclient-3.1.jar, file:/opt/mapr/hadoop/hadoop-0.20.2/lib/commons-lang-2.6.jar, file:/opt/mapr/hadoop/hadoop-0.20.2/lib/commons-logging-1.0.4.jar, file:/opt/mapr/hadoop/hadoop-0.20.2/lib/commons-logging-1.1.1.jar, file:/opt/mapr/hadoop/hadoop-0.20.2/lib/commons-logging-api-1.0.4.jar, file:/opt/mapr/hadoop/hadoop-0.20.2/lib/commons-math-2.1.jar, file:/opt/mapr/hadoop/hadoop-0.20.2/lib/commons-net-1.4.1.jar, file:/opt/mapr/hadoop/hadoop-0.20.2/lib/commons-net-3.1.jar, file:/opt/mapr/hadoop/hadoop-0.20.2/lib/core-3.1.1.jar, file:/opt/mapr/hadoop/hadoop-0.20.2/lib/emr-metrics-1.0.jar, file:/opt/mapr/hadoop/hadoop-0.20.2/lib/eval-0.5.jar, file:/opt/mapr/hadoop/hadoop-0.20.2/lib/gson-1.4.jar, file:/opt/mapr/hadoop/hadoop-0.20.2/lib/guava-13.0.1.jar, file:/opt/mapr/hadoop/hadoop-0.20.2/lib/guava-r09-jarjar.jar, file:/opt/mapr/hadoop/hadoop-0.20.2/lib/hadoop-0.20.2-auth.jar, file:/opt/mapr/hadoop/hadoop-0.20.2/lib/hadoop-0.20.2-dev-capacity-scheduler.jar, file:/opt/mapr/hadoop/hadoop-0.20.2/lib/hadoop-0.20.2-dev-core.jar, file:/opt/mapr/hadoop/hadoop-0.20.2/lib/hadoop-0.20.2-dev-fairscheduler.jar, file:/opt/mapr/hadoop/hadoop-0.20.2/lib/hadoop-metrics-0.20.2-dev.jar, file:/opt/mapr/hadoop/hadoop-0.20.2/lib/hadoop-metrics2-0.20.2-dev.jar, file:/opt/mapr/hadoop/hadoop-0.20.2/lib/hsqldb-1.8.0.10.jar, file:/opt/mapr/hadoop/hadoop-0.20.2/lib/httpclient-4.1.1.jar, file:/opt/mapr/hadoop/hadoop-0.20.2/lib/httpcore-4.1.jar, file:/opt/mapr/hadoop/hadoop-0.20.2/lib/jackson-core-asl-1.5.2.jar, file:/opt/mapr/hadoop/hadoop-0.20.2/lib/jackson-mapper-asl-1.5.2.jar, file:/opt/mapr/hadoop/hadoop-0.20.2/lib/jasper-compiler-5.5.12.jar, file:/opt/mapr/hadoop/hadoop-0.20.2/lib/jasper-runtime-5.5.12.jar, file:/opt/mapr/hadoop/hadoop-0.20.2/lib/jersey-core-1.8.jar, file:/opt/mapr/hadoop/hadoop-0.20.2/lib/jersey-json-1.8.jar, file:/opt/mapr/hadoop/hadoop-0.20.2/lib/jersey-server-1.8.jar, file:/opt/mapr/hadoop/hadoop-0.20.2/lib/jets3t-0.6.1.jar, file:/opt/mapr/hadoop/hadoop-0.20.2/lib/jetty-6.1.26.jar, file:/opt/mapr/hadoop/hadoop-0.20.2/lib/jetty-plus-6.1.26.jar, file:/opt/mapr/hadoop/hadoop-0.20.2/lib/jetty-servlet-tester-6.1.26.jar, file:/opt/mapr/hadoop/hadoop-0.20.2/lib/jetty-util-6.1.26.jar, file:/opt/mapr/hadoop/hadoop-0.20.2/lib/junit-4.5.jar, file:/opt/mapr/hadoop/hadoop-0.20.2/lib/kfs-0.2.2.jar, file:/opt/mapr/hadoop/hadoop-0.20.2/lib/log4j-1.2.15.jar, file:/opt/mapr/hadoop/hadoop-0.20.2/lib/logging-0.1.jar, file:/opt/mapr/hadoop/hadoop-0.20.2/lib/mapr-hbase-1.0.3-mapr-3.1.0-tests.jar, file:/opt/mapr/hadoop/hadoop-0.20.2/lib/mapr-hbase-1.0.3-mapr-3.1.0.jar, file:/opt/mapr/lib/maprfs-1.0.3-mapr-3.1.0.jar, file:/opt/mapr/lib/maprfs-core-1.0.3-mapr-3.1.0-tests.jar, file:/opt/mapr/lib/maprfs-core-1.0.3-mapr-3.1.0.jar, file:/opt/mapr/lib/maprfs-diagnostic-tools-1.0.3-mapr-3.1.0.jar, file:/opt/mapr/lib/maprfs-jni-1.0.3-mapr-3.1.0.jar, file:/opt/mapr/hadoop/hadoop-0.20.2/lib/mockito-all-1.8.2.jar, file:/opt/mapr/hadoop/hadoop-0.20.2/lib/mockito-all-1.8.5.jar, file:/opt/mapr/hadoop/hadoop-0.20.2/lib/mysql-connector-java-5.1.25-bin.jar, file:/opt/mapr/hadoop/hadoop-0.20.2/lib/oro-2.0.8.jar, file:/opt/mapr/hadoop/hadoop-0.20.2/lib/protobuf-java-2.4.1.jar, file:/opt/mapr/hadoop/hadoop-0.20.2/lib/servlet-api-2.5-20081211.jar, file:/opt/mapr/hadoop/hadoop-0.20.2/lib/servlet-api-2.5-6.1.14.jar, file:/opt/mapr/lib/slf4j-api-1.6.1.jar, file:/opt/mapr/lib/slf4j-log4j12-1.6.1.jar, file:/opt/mapr/hadoop/hadoop-0.20.2/lib/xmlenc-0.52.jar, file:/opt/mapr/hadoop/hadoop-0.20.2/lib/zookeeper-3.4.5-mapr-1401.jar, file:/opt/mapr/hadoop/hadoop-0.20.2/lib/jsp-2.1/jsp-2.1.jar, file:/opt/mapr/hadoop/hadoop-0.20.2/lib/jsp-2.1/jsp-api-2.1.jar, file:/opt/mapr/lib/kvstore-0.1.jar, file:/opt/mapr/lib/protobuf-java-2.4.1-lite.jar, file:/opt/mapr/lib/libprotodefs.jar, file:/opt/mapr/lib/baseutils-0.1.jar, file:/opt/mapr/lib/json-20080701.jar, file:/opt/mapr/lib/flexjson-2.1.jar, file:/opt/mapr/hadoop/hadoop-0.20.2/lib/hadoop-0.20.2-auth.jar, file:/opt/mapr/lib/JPam-1.1.jar, file:/tmp/mapr-hadoop/mapred/local/taskTracker/mapr/jobcache/job_201408081313_0194/jars/classes, file:/tmp/mapr-hadoop/mapred/local/taskTracker/mapr/jobcache/job_201408081313_0194/jars/job.jar, file:/tmp/mapr-hadoop/mapred/local/taskTracker/mapr/jobcache/job_201408081313_0194/attempt_201408081313_0194_m_000361_1/work/]
2014-08-21 12:22:47,574 INFO org.apache.hadoop.hive.ql.exec.mr.ObjectCache: Ignoring retrieval request: __MAP_PLAN__
2014-08-21 12:22:47,575 INFO org.apache.hadoop.hive.ql.exec.mr.ObjectCache: Ignoring cache key: __MAP_PLAN__
2014-08-21 12:22:47,811 INFO org.apache.hadoop.hive.ql.exec.MapOperator: dump TS struct<line:string,extension:string>
2014-08-21 12:22:47,812 INFO org.apache.hadoop.hive.ql.exec.mr.ExecMapper:
<MAP>Id =4
  <Children>
    <TS>Id =0
      <Children>
        <SEL>Id =1
          <Children>
            <GBY>Id =2
              <Children>
                <RS>Id =3
                  <Children>
                  <\Children>
                  <Parent>Id = 2 null<\Parent>
                <\RS>
              <\Children>
              <Parent>Id = 1 null<\Parent>
            <\GBY>
          <\Children>
          <Parent>Id = 0 null<\Parent>
        <\SEL>
      <\Children>
      <Parent>Id = 4 null<\Parent>
    <\TS>
  <\Children>
  <Parent><\Parent>
<\MAP>
2014-08-21 12:22:47,815 INFO org.apache.hadoop.hive.ql.exec.MapOperator: Initializing Self 4 MAP
2014-08-21 12:22:47,816 INFO org.apache.hadoop.hive.ql.exec.TableScanOperator: Initializing Self 0 TS
2014-08-21 12:22:47,817 INFO org.apache.hadoop.hive.ql.exec.TableScanOperator: Operator 0 TS initialized
2014-08-21 12:22:47,817 INFO org.apache.hadoop.hive.ql.exec.TableScanOperator: Initializing children of 0 TS
2014-08-21 12:22:47,817 INFO org.apache.hadoop.hive.ql.exec.SelectOperator: Initializing child 1 SEL
2014-08-21 12:22:47,817 INFO org.apache.hadoop.hive.ql.exec.SelectOperator: Initializing Self 1 SEL
2014-08-21 12:22:47,817 INFO org.apache.hadoop.hive.ql.exec.SelectOperator: SELECT struct<line:string,extension:string>
2014-08-21 12:22:47,817 INFO org.apache.hadoop.hive.ql.exec.SelectOperator: Operator 1 SEL initialized
2014-08-21 12:22:47,817 INFO org.apache.hadoop.hive.ql.exec.SelectOperator: Initializing children of 1 SEL
2014-08-21 12:22:47,817 INFO org.apache.hadoop.hive.ql.exec.GroupByOperator: Initializing child 2 GBY
2014-08-21 12:22:47,817 INFO org.apache.hadoop.hive.ql.exec.GroupByOperator: Initializing Self 2 GBY
2014-08-21 12:22:47,844 INFO org.apache.hadoop.hive.ql.exec.GroupByOperator: Operator 2 GBY initialized
2014-08-21 12:22:47,844 INFO org.apache.hadoop.hive.ql.exec.GroupByOperator: Initializing children of 2 GBY
2014-08-21 12:22:47,844 INFO org.apache.hadoop.hive.ql.exec.ReduceSinkOperator: Initializing child 3 RS
2014-08-21 12:22:47,844 INFO org.apache.hadoop.hive.ql.exec.ReduceSinkOperator: Initializing Self 3 RS
2014-08-21 12:22:47,844 INFO org.apache.hadoop.hive.ql.exec.ReduceSinkOperator: Using tag = -1
2014-08-21 12:22:47,902 INFO org.apache.hadoop.hive.ql.exec.ReduceSinkOperator: Operator 3 RS initialized
2014-08-21 12:22:47,902 INFO org.apache.hadoop.hive.ql.exec.ReduceSinkOperator: Initialization Done 3 RS
2014-08-21 12:22:47,902 INFO org.apache.hadoop.hive.ql.exec.GroupByOperator: Initialization Done 2 GBY
2014-08-21 12:22:47,902 INFO org.apache.hadoop.hive.ql.exec.SelectOperator: Initialization Done 1 SEL
2014-08-21 12:22:47,902 INFO org.apache.hadoop.hive.ql.exec.TableScanOperator: Initialization Done 0 TS
2014-08-21 12:22:47,902 INFO org.apache.hadoop.hive.ql.exec.MapOperator: Initialization Done 4 MAP
2014-08-21 12:22:47,915 INFO org.apache.hadoop.hive.ql.exec.MapOperator: Processing alias externalsorted for file maprfs:/etl/archive/data/externalsorted/txt
2014-08-21 12:22:47,917 INFO org.apache.hadoop.hive.ql.exec.mr.ExecMapper: ExecMapper: processing 1 rows: used memory = 520298024
2014-08-21 12:22:47,918 INFO org.apache.hadoop.hive.ql.exec.mr.ExecMapper: ExecMapper: processing 10 rows: used memory = 520298024
2014-08-21 12:22:47,921 INFO org.apache.hadoop.hive.ql.exec.mr.ExecMapper: ExecMapper: processing 100 rows: used memory = 520298024
2014-08-21 12:22:47,950 INFO org.apache.hadoop.hive.ql.exec.mr.ExecMapper: ExecMapper: processing 1000 rows: used memory = 520298024
2014-08-21 12:22:48,245 INFO org.apache.hadoop.hive.ql.exec.mr.ExecMapper: ExecMapper: processing 10000 rows: used memory = 520298024
2014-08-21 12:22:48,556 INFO org.apache.hadoop.hive.ql.exec.mr.ExecMapper: ExecMapper: processing 100000 rows: used memory = 525668064
2014-08-21 12:22:49,251 INFO org.apache.hadoop.hive.ql.exec.mr.ExecMapper: ExecMapper: processing 1000000 rows: used memory = 547148352
2014-08-21 12:22:49,834 INFO org.apache.hadoop.hive.ql.exec.mr.ExecMapper: ExecMapper: processing 2000000 rows: used memory = 573998552
2014-08-21 12:32:56,608 INFO org.apache.hadoop.mapred.Task: Communication exception: org.apache.hadoop.ipc.RemoteException: java.io.IOException: JvmValidate Failed. Ignoring request from task: attempt_201408081313_0194_m_000361_1, with JvmId: jvm_201408081313_0194_m_1422366458
        at org.apache.hadoop.mapred.TaskTracker.validateJVM(TaskTracker.java:4794)
        at org.apache.hadoop.mapred.TaskTracker.ping(TaskTracker.java:4945)
        at sun.reflect.GeneratedMethodAccessor5.invoke(Unknown Source)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.lang.reflect.Method.invoke(Method.java:606)
        at org.apache.hadoop.ipc.RPC$Server.call(RPC.java:998)
        at org.apache.hadoop.ipc.Server$Handler$1.run(Server.java:1324)
        at org.apache.hadoop.ipc.Server$Handler$1.run(Server.java:1320)
        at java.security.AccessController.doPrivileged(Native Method)
        at javax.security.auth.Subject.doAs(Subject.java:415)
        at org.apache.hadoop.security.UserGroupInformation.doAs(UserGroupInformation.java:1117)
        at org.apache.hadoop.ipc.Server$Handler.run(Server.java:1318)

        at org.apache.hadoop.ipc.Client.call(Client.java:1142)
        at org.apache.hadoop.ipc.RPC$Invoker.invoke(RPC.java:275)
        at com.sun.proxy.$Proxy0.ping(Unknown Source)
        at org.apache.hadoop.mapred.Task$TaskReporter.run(Task.java:688)
        at java.lang.Thread.run(Thread.java:724)


profile.out logs




debugout logs

Outcomes