linux控制台输出:
15/01/28 09:05:07 INFO input.FileInputFormat: Total input paths to process : 1
15/01/28 09:05:07 INFO util.NativeCodeLoader: Loaded the native-hadoop library
15/01/28 09:05:07 WARN snappy.LoadSnappy: Snappy native library not loaded
15/01/28 09:05:08 INFO mapred.JobClient: Running job: job_201501280903_0001
15/01/28 09:05:09 INFO mapred.JobClient: map 0% reduce 0%
15/01/28 09:06:39 INFO mapred.JobClient: map 62% reduce 0%
15/01/28 09:06:42 INFO mapred.JobClient: map 100% reduce 0%
15/01/28 09:07:46 INFO mapred.JobClient: map 0% reduce 0%
15/01/28 09:08:17 INFO mapred.JobClient: Task Id : attempt_201501280903_0001_m_000000_0, Status : FAILED
Task attempt_201501280903_0001_m_000000_0 failed to report status for 1800 seconds. Killing!
15/01/28 09:09:05 INFO mapred.JobClient: map 62% reduce 0%
15/01/28 09:09:08 INFO mapred.JobClient: map 100% reduce 0%
15/01/28 09:10:11 INFO mapred.JobClient: map 0% reduce 0%
15/01/28 09:10:43 INFO mapred.JobClient: Task Id : attempt_201501280903_0001_m_000000_1, Status : FAILED
Task attempt_201501280903_0001_m_000000_1 failed to report status for 1800 seconds. Killing!
15/01/28 09:11:10 INFO mapred.JobClient: map 100% reduce 0%
15/01/28 09:12:16 INFO mapred.JobClient: map 0% reduce 0%
15/01/28 09:12:33 INFO mapred.JobClient: Task Id : attempt_201501280903_0001_m_000000_2, Status : FAILED
Task attempt_201501280903_0001_m_000000_2 failed to report status for 1800 seconds. Killing!
15/01/28 09:12:51 INFO mapred.JobClient: map 100% reduce 0%
15/01/28 09:13:57 INFO mapred.JobClient: map 0% reduce 0%
15/01/28 09:14:38 INFO mapred.JobClient: Job complete: job_201501280903_0001
15/01/28 09:14:38 INFO mapred.JobClient: Counters: 7
15/01/28 09:14:38 INFO mapred.JobClient: Job Counters
15/01/28 09:14:38 INFO mapred.JobClient: SLOTS_MILLIS_MAPS=171776
15/01/28 09:14:38 INFO mapred.JobClient: Total time spent by all reduces waiting after reserving slots (ms)=0
15/01/28 09:14:38 INFO mapred.JobClient: Total time spent by all maps waiting after reserving slots (ms)=0
15/01/28 09:14:38 INFO mapred.JobClient: Launched map tasks=4
15/01/28 09:14:38 INFO mapred.JobClient: Data-local map tasks=4
15/01/28 09:14:38 INFO mapred.JobClient: SLOTS_MILLIS_REDUCES=0
15/01/28 09:14:38 INFO mapred.JobClient: Failed map tasks=1
================下面是某个jobtracker的syslog日志信息============
2015-01-26 17:05:35,574 INFO org.apache.hadoop.util.NativeCodeLoader: Loaded the native-hadoop library
2015-01-26 17:05:35,965 WARN org.apache.hadoop.metrics2.impl.MetricsSystemImpl: Source name ugi already exists!
2015-01-26 17:05:36,143 INFO org.apache.hadoop.util.ProcessTree: setsid exited with exit code 0
2015-01-26 17:05:36,154 INFO org.apache.hadoop.mapred.Task: Using ResourceCalculatorPlugin : org.apache.hadoop.util.LinuxResourceCalculatorPlugin@14d1cbd
2015-01-26 17:05:36,238 INFO org.apache.hadoop.mapred.MapTask: Processing split: hdfs://rocky-virtual-machine:9000/user/grid/cyyytest/555:0+44874380
2015-01-26 17:05:36,252 INFO org.apache.hadoop.mapred.MapTask: io.sort.mb = 100
2015-01-26 17:05:37,002 INFO org.apache.hadoop.mapred.MapTask: data buffer = 79691776/99614720
2015-01-26 17:05:37,002 INFO org.apache.hadoop.mapred.MapTask: record buffer = 262144/327680
2015-01-26 17:05:37,020 WARN org.apache.hadoop.io.compress.snappy.LoadSnappy: Snappy native library not loaded
2015-01-26 17:05:38,910 INFO org.apache.hadoop.mapred.MapTask: Spilling map output: record full = true
2015-01-26 17:05:38,910 INFO org.apache.hadoop.mapred.MapTask: bufstart = 0; bufend = 12481493; bufvoid = 99614720
2015-01-26 17:05:38,910 INFO org.apache.hadoop.mapred.MapTask: kvstart = 0; kvend = 262144; length = 327680
2015-01-26 17:05:40,771 INFO org.apache.hadoop.mapred.MapTask: Finished spill 0
2015-01-26 17:05:41,692 INFO org.apache.hadoop.mapred.MapTask: Spilling map output: record full = true
2015-01-26 17:05:41,693 INFO org.apache.hadoop.mapred.MapTask: bufstart = 12481493; bufend = 24951394; bufvoid = 99614720
2015-01-26 17:05:41,693 INFO org.apache.hadoop.mapred.MapTask: kvstart = 262144; kvend = 196607; length = 327680
2015-01-26 17:05:41,700 INFO org.apache.hadoop.mapred.MapTask: Starting flush of map output
2015-01-26 17:05:43,159 INFO org.apache.hadoop.mapred.MapTask: Finished spill 1
2015-01-26 17:05:43,161 INFO org.apache.hadoop.mapred.MapTask: Finished spill 2
2015-01-26 17:05:43,167 INFO org.apache.hadoop.mapred.Merger: Merging 3 sorted segments
2015-01-26 17:05:43,175 INFO org.apache.hadoop.mapred.Merger: Down to the last merge-pass, with 3 segments left of total size: 15673220 bytes
2015-01-26 17:05:43,175 INFO org.apache.hadoop.mapred.MapTask: Starting flush of map output
2015-01-26 17:35:49,409 INFO org.apache.hadoop.mapred.Task: Communication exception: org.apache.hadoop.ipc.RemoteException: java.io.IOException: JvmValidate Failed. Ignoring request from task: attempt_201501261630_0001_m_000000_1, with JvmId: jvm_201501261630_0001_m_-1033103475
at org.apache.hadoop.mapred.TaskTracker.validateJVM(TaskTracker.java:3465)
at org.apache.hadoop.mapred.TaskTracker.ping(TaskTracker.java:3598)
at sun.reflect.GeneratedMethodAccessor2.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:587)
at org.apache.hadoop.ipc.Server$Handler$1.run(Server.java:1432)
at org.apache.hadoop.ipc.Server$Handler$1.run(Server.java:1428)
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:1190)
at org.apache.hadoop.ipc.Server$Handler.run(Server.java:1426)
at org.apache.hadoop.ipc.Client.call(Client.java:1113)
at org.apache.hadoop.ipc.RPC$Invoker.invoke(RPC.java:229)
at com.sun.proxy.$Proxy1.ping(Unknown Source)
at org.apache.hadoop.mapred.Task$TaskReporter.run(Task.java:685)
at java.lang.Thread.run(Thread.java:744)
2015-01-26 17:35:52,411 INFO org.apache.hadoop.mapred.Task: Communication exception: org.apache.hadoop.ipc.RemoteException: java.io.IOException: JvmValidate Failed. Ignoring request from task: attempt_201501261630_0001_m_000000_1, with JvmId: jvm_201501261630_0001_m_-1033103475
at org.apache.hadoop.mapred.TaskTracker.validateJVM(TaskTracker.java:3465)
at org.apache.hadoop.mapred.TaskTracker.ping(TaskTracker.java:3598)
at sun.reflect.GeneratedMethodAccessor2.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:587)
at org.apache.hadoop.ipc.Server$Handler$1.run(Server.java:1432)
at org.apache.hadoop.ipc.Server$Handler$1.run(Server.java:1428)
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:1190)
at org.apache.hadoop.ipc.Server$Handler.run(Server.java:1426)
at org.apache.hadoop.ipc.Client.call(Client.java:1113)
at org.apache.hadoop.ipc.RPC$Invoker.invoke(RPC.java:229)
at com.sun.proxy.$Proxy1.ping(Unknown Source)
at org.apache.hadoop.mapred.Task$TaskReporter.run(Task.java:685)
at java.lang.Thread.run(Thread.java:744)
2015-01-26 17:35:55,417 INFO org.apache.hadoop.mapred.Task: Communication exception: org.apache.hadoop.ipc.RemoteException: java.io.IOException: JvmValidate Failed. Ignoring request from task: attempt_201501261630_0001_m_000000_1, with JvmId: jvm_201501261630_0001_m_-1033103475
at org.apache.hadoop.mapred.TaskTracker.validateJVM(TaskTracker.java:3465)
at org.apache.hadoop.mapred.TaskTracker.ping(TaskTracker.java:3598)
at sun.reflect.GeneratedMethodAccessor2.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:587)
at org.apache.hadoop.ipc.Server$Handler$1.run(Server.java:1432)
at org.apache.hadoop.ipc.Server$Handler$1.run(Server.java:1428)
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:1190)
at org.apache.hadoop.ipc.Server$Handler.run(Server.java:1426)
at org.apache.hadoop.ipc.Client.call(Client.java:1113)
at org.apache.hadoop.ipc.RPC$Invoker.invoke(RPC.java:229)
at com.sun.proxy.$Proxy1.ping(Unknown Source)
at org.apache.hadoop.mapred.Task$TaskReporter.run(Task.java:685)
at java.lang.Thread.run(Thread.java:744)
2015-01-26 17:35:55,420 INFO org.apache.hadoop.mapred.Task: Process Thread Dump: Communication exception
11 active threads
Thread 22 (Readahead Thread #2):
State: WAITING
Blocked count: 0
Waited count: 1
Waiting on java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject@1487194
Stack:
sun.misc.Unsafe.park(Native Method)
java.util.concurrent.locks.LockSupport.park(LockSupport.java:186)
java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2043)
java.util.concurrent.ArrayBlockingQueue.take(ArrayBlockingQueue.java:374)
java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1068)
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130)
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
java.lang.Thread.run(Thread.java:744)
Thread 21 (Readahead Thread #1):
State: WAITING
Blocked count: 0
Waited count: 1
Waiting on java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject@1487194
Stack:
sun.misc.Unsafe.park(Native Method)
java.util.concurrent.locks.LockSupport.park(LockSupport.java:186)
java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2043)
java.util.concurrent.ArrayBlockingQueue.take(ArrayBlockingQueue.java:374)
java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1068)
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130)
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
java.lang.Thread.run(Thread.java:744)
Thread 20 (Readahead Thread #0):
State: WAITING
Blocked count: 0
Waited count: 2
Waiting on java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject@1487194
Stack:
sun.misc.Unsafe.park(Native Method)
java.util.concurrent.locks.LockSupport.park(LockSupport.java:186)
java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2043)
java.util.concurrent.ArrayBlockingQueue.take(ArrayBlockingQueue.java:374)
java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1068)
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130)
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
java.lang.Thread.run(Thread.java:744)
Thread 14 (communication thread):
State: RUNNABLE
Blocked count: 603
Waited count: 1209
Stack:
sun.management.ThreadImpl.getThreadInfo1(Native Method)
sun.management.ThreadImpl.getThreadInfo(ThreadImpl.java:174)
sun.management.ThreadImpl.getThreadInfo(ThreadImpl.java:139)
org.apache.hadoop.util.ReflectionUtils.printThreadInfo(ReflectionUtils.java:149)
org.apache.hadoop.util.ReflectionUtils.logThreadInfo(ReflectionUtils.java:203)
org.apache.hadoop.mapred.Task$TaskReporter.run(Task.java:703)
java.lang.Thread.run(Thread.java:744)
Thread 12 (Timer for 'MapTask' metrics system):
State: TIMED_WAITING
Blocked count: 0
Waited count: 182
Stack:
java.lang.Object.wait(Native Method)
java.util.TimerThread.mainLoop(Timer.java:552)
java.util.TimerThread.run(Timer.java:505)
Thread 10 (Thread for syncLogs):
State: TIMED_WAITING
Blocked count: 0
Waited count: 364
Stack:
java.lang.Thread.sleep(Native Method)
org.apache.hadoop.mapred.Child$3.run(Child.java:139)
Thread 8 (IPC Client (47) connection to /127.0.0.1:58984 from job_201501261630_0001):
State: TIMED_WAITING
Blocked count: 607
Waited count: 608
Stack:
java.lang.Object.wait(Native Method)
org.apache.hadoop.ipc.Client$Connection.waitForWork(Client.java:747)
org.apache.hadoop.ipc.Client$Connection.run(Client.java:789)
Thread 4 (Signal Dispatcher):
State: RUNNABLE
Blocked count: 0
Waited count: 0
Stack:
Thread 3 (Finalizer):
State: WAITING
Blocked count: 15
Waited count: 16
Waiting on java.lang.ref.ReferenceQueue$Lock@1628d93
Stack:
java.lang.Object.wait(Native Method)
java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:135)
java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:151)
java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:189)
Thread 2 (Reference Handler):
State: WAITING
Blocked count: 16
Waited count: 17
Waiting on java.lang.ref.Reference$Lock@13cb6cf
Stack:
java.lang.Object.wait(Native Method)
java.lang.Object.wait(Object.java:503)
java.lang.ref.Reference$ReferenceHandler.run(Reference.java:133)
Thread 1 (main):
State: WAITING
Blocked count: 8
Waited count: 12
Waiting on java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject@1c3e166
Stack:
sun.misc.Unsafe.park(Native Method)
java.util.concurrent.locks.LockSupport.park(LockSupport.java:186)
java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2043)
org.apache.hadoop.mapred.MapTask$MapOutputBuffer.flush(MapTask.java:1294)
org.apache.hadoop.mapred.MapTask$NewOutputCollector.close(MapTask.java:698)
org.apache.hadoop.mapred.MapTask.closeQuietly(MapTask.java:1793)
org.apache.hadoop.mapred.MapTask.runNewMapper(MapTask.java:779)
org.apache.hadoop.mapred.MapTask.run(MapTask.java:364)
org.apache.hadoop.mapred.Child$4.run(Child.java:255)
java.security.AccessController.doPrivileged(Native Method)
javax.security.auth.Subject.doAs(Subject.java:415)
org.apache.hadoop.security.UserGroupInformation.doAs(UserGroupInformation.java:1190)
org.apache.hadoop.mapred.Child.main(Child.java:249)
2015-01-26 17:35:55,420 WARN org.apache.hadoop.mapred.Task: Last retry, killing attempt_201501261630_0001_m_000000_1
|