hadoop-user mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Stone <stones....@gmail.com>
Subject Re: Hadoop in Pseudo-Distributed mode on Mac OS X 10.8
Date Thu, 30 Aug 2012 17:56:27 GMT
FYI : the jstack output for the hanged job:

Full thread dump Java HotSpot(TM) 64-Bit Server VM (20.8-b03-424 mixed
mode):

"RMI TCP Accept-0" daemon prio=9 tid=7f833f1ba800 nid=0x109b90000 runnable
[109b8f000]
   java.lang.Thread.State: RUNNABLE
at java.net.PlainSocketImpl.socketAccept(Native Method)
at java.net.PlainSocketImpl.accept(PlainSocketImpl.java:408)
- locked <7bd6a00a8> (a java.net.SocksSocketImpl)
at java.net.ServerSocket.implAccept(ServerSocket.java:462)
at java.net.ServerSocket.accept(ServerSocket.java:430)
at
sun.management.jmxremote.LocalRMIServerSocketFactory$1.accept(LocalRMIServerSocketFactory.java:34)
at
sun.rmi.transport.tcp.TCPTransport$AcceptLoop.executeAcceptLoop(TCPTransport.java:369)
at sun.rmi.transport.tcp.TCPTransport$AcceptLoop.run(TCPTransport.java:341)
at java.lang.Thread.run(Thread.java:680)

"Attach Listener" daemon prio=9 tid=7f833d000800 nid=0x108b72000 waiting on
condition [00000000]
   java.lang.Thread.State: RUNNABLE

"LeaseChecker" daemon prio=5 tid=7f833f30d000 nid=0x10a000000 waiting on
condition [109fff000]
   java.lang.Thread.State: TIMED_WAITING (sleeping)
at java.lang.Thread.sleep(Native Method)
at org.apache.hadoop.hdfs.DFSClient$LeaseChecker.run(DFSClient.java:1302)
at java.lang.Thread.run(Thread.java:680)

"IPC Client (47) connection to localhost/127.0.0.1:9001 from stone" daemon
prio=5 tid=7f833d0de000 nid=0x109dfa000 in Object.wait() [109df9000]
   java.lang.Thread.State: TIMED_WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
- waiting on <7bd6a02e0> (a org.apache.hadoop.ipc.Client$Connection)
at org.apache.hadoop.ipc.Client$Connection.waitForWork(Client.java:680)
- locked <7bd6a02e0> (a org.apache.hadoop.ipc.Client$Connection)
at org.apache.hadoop.ipc.Client$Connection.run(Client.java:723)

"sendParams-0" daemon prio=5 tid=7f833e1cb000 nid=0x109cf7000 waiting on
condition [109cf6000]
   java.lang.Thread.State: TIMED_WAITING (parking)
at sun.misc.Unsafe.park(Native Method)
- parking to wait for  <7c1950890> (a
java.util.concurrent.SynchronousQueue$TransferStack)
at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:196)
at
java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:424)
at
java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:323)
at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:874)
at
java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:945)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:907)
at java.lang.Thread.run(Thread.java:680)

"Low Memory Detector" daemon prio=5 tid=7f833e021800 nid=0x109084000
runnable [00000000]
   java.lang.Thread.State: RUNNABLE

"C2 CompilerThread1" daemon prio=9 tid=7f833e021000 nid=0x108f81000 waiting
on condition [00000000]
   java.lang.Thread.State: RUNNABLE

"C2 CompilerThread0" daemon prio=9 tid=7f833e020000 nid=0x108e7e000 waiting
on condition [00000000]
   java.lang.Thread.State: RUNNABLE

"Signal Dispatcher" daemon prio=9 tid=7f833e01f800 nid=0x108d7b000 runnable
[00000000]
   java.lang.Thread.State: RUNNABLE

"Surrogate Locker Thread (Concurrent GC)" daemon prio=5 tid=7f833e01e800
nid=0x108c78000 waiting on condition [00000000]
   java.lang.Thread.State: RUNNABLE

"Finalizer" daemon prio=8 tid=7f833e00f000 nid=0x108a6f000 in Object.wait()
[108a6e000]
   java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
- waiting on <7c19c1550> (a java.lang.ref.ReferenceQueue$Lock)
at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:118)
- locked <7c19c1550> (a java.lang.ref.ReferenceQueue$Lock)
at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:134)
at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:159)

"Reference Handler" daemon prio=10 tid=7f833e00e000 nid=0x10896c000 in
Object.wait() [10896b000]
   java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
- waiting on <7c1950860> (a java.lang.ref.Reference$Lock)
at java.lang.Object.wait(Object.java:485)
at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:116)
- locked <7c1950860> (a java.lang.ref.Reference$Lock)

"main" prio=5 tid=7f833f000800 nid=0x1008eb000 waiting on condition
[1008e9000]
   java.lang.Thread.State: TIMED_WAITING (sleeping)
at java.lang.Thread.sleep(Native Method)
at
org.apache.hadoop.mapred.JobClient.monitorAndPrintJob(JobClient.java:1316)
at org.apache.hadoop.mapreduce.Job.waitForCompletion(Job.java:509)
at org.apache.hadoop.examples.WordCount.main(WordCount.java:67)
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:597)
at
org.apache.hadoop.util.ProgramDriver$ProgramDescription.invoke(ProgramDriver.java:68)
at org.apache.hadoop.util.ProgramDriver.driver(ProgramDriver.java:139)
at org.apache.hadoop.examples.ExampleDriver.main(ExampleDriver.java:64)
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:597)
at org.apache.hadoop.util.RunJar.main(RunJar.java:197)

"VM Thread" prio=9 tid=7f833e009800 nid=0x108869000 runnable

"Gang worker#0 (Parallel GC Threads)" prio=9 tid=7f833f002000
nid=0x103ced000 runnable

"Gang worker#1 (Parallel GC Threads)" prio=9 tid=7f833f002800
nid=0x103df0000 runnable

"Gang worker#2 (Parallel GC Threads)" prio=9 tid=7f833f003000
nid=0x103ef3000 runnable

"Gang worker#3 (Parallel GC Threads)" prio=9 tid=7f833f004000
nid=0x103ff6000 runnable

"Concurrent Mark-Sweep GC Thread" prio=9 tid=7f833f07f000 nid=0x1084e7000
runnable
"VM Periodic Task Thread" prio=10 tid=7f833e033800 nid=0x109187000 waiting
on condition

"Exception Catcher Thread" prio=10 tid=7f833f001800 nid=0x100b16000
runnable
JNI global references: 1457



Best Regards,
Stone



On Fri, Aug 31, 2012 at 1:24 AM, Stone <stones.gao@gmail.com> wrote:

> I got the same issue today. map tasks finished quickly but reduce is
> always 0%. I am also running Mac OS X 10.8. (cdh3u4)
>
> 12/08/31 01:13:03 INFO mapred.JobClient:  map 0% reduce 0%
> 12/08/31 01:13:07 INFO mapred.JobClient:  map 100% reduce 0%
> 12/08/31 01:23:14 INFO mapred.JobClient: Task Id :
> attempt_201208310112_0001_r_000000_0, Status : FAILED
> Task attempt_201208310112_0001_r_000000_0 failed to report status for 600
> seconds. Killing!
>
>
>
> logs for the reducer :
>
> Task Logs: 'attempt_201208310112_0001_r_000000_0'
>
>
>
> stdout logs
>
>
> stderr logs
> 2012-08-31 01:13:06.316 java[46834:1203] Unable to load realm info from
> SCDynamicStore
>
>
> syslog logs
> 2012-08-31 01:13:06,421 INFO
> org.apache.hadoop.security.UserGroupInformation: JAAS Configuration already
> set up for Hadoop, not re-installing.
> 2012-08-31 01:13:06,674 WARN org.apache.hadoop.util.NativeCodeLoader:
> Unable to load native-hadoop library for your platform... using
> builtin-java classes where applicable
> 2012-08-31 01:13:06,848 INFO org.apache.hadoop.metrics.jvm.JvmMetrics:
> Initializing JVM Metrics with processName=SHUFFLE, sessionId=
> 2012-08-31 01:13:06,945 INFO org.apache.hadoop.mapred.Task:  Using
> ResourceCalculatorPlugin : null
> 2012-08-31 01:13:06,957 INFO org.apache.hadoop.mapred.ReduceTask:
> ShuffleRamManager: MemoryLimit=144965632, MaxSingleShuffleLimit=36241408
> 2012-08-31 01:13:06,962 INFO org.apache.hadoop.mapred.ReduceTask:
> attempt_201208310112_0001_r_000000_0 Thread started: Thread for merging
> on-disk files
> 2012-08-31 01:13:06,963 INFO org.apache.hadoop.mapred.ReduceTask:
> attempt_201208310112_0001_r_000000_0 Thread waiting: Thread for merging
> on-disk files
> 2012-08-31 01:13:06,963 INFO org.apache.hadoop.mapred.ReduceTask:
> attempt_201208310112_0001_r_000000_0 Thread started: Thread for merging in
> memory files
> 2012-08-31 01:13:06,964 INFO org.apache.hadoop.mapred.ReduceTask:
> attempt_201208310112_0001_r_000000_0 Thread started: Thread for polling Map
> Completion Events
> 2012-08-31 01:13:06,964 INFO org.apache.hadoop.mapred.ReduceTask:
> attempt_201208310112_0001_r_000000_0 Need another 1 map output(s) where 0
> is already in progress
> 2012-08-31 01:13:06,965 INFO org.apache.hadoop.mapred.ReduceTask:
> attempt_201208310112_0001_r_000000_0 Scheduled 0 outputs (0 slow hosts and0
> dup hosts)
> 2012-08-31 01:13:11,966 INFO org.apache.hadoop.mapred.ReduceTask:
> attempt_201208310112_0001_r_000000_0 Scheduled 1 outputs (0 slow hosts and0
> dup hosts)
> 2012-08-31 01:14:07,996 INFO org.apache.hadoop.mapred.ReduceTask:
> attempt_201208310112_0001_r_000000_0 Need another 1 map output(s) where 1
> is already in progress
> 2012-08-31 01:14:07,996 INFO org.apache.hadoop.mapred.ReduceTask:
> attempt_201208310112_0001_r_000000_0 Scheduled 0 outputs (0 slow hosts and0
> dup hosts)
> 2012-08-31 01:15:08,033 INFO org.apache.hadoop.mapred.ReduceTask:
> attempt_201208310112_0001_r_000000_0 Need another 1 map output(s) where 1
> is already in progress
> 2012-08-31 01:15:08,033 INFO org.apache.hadoop.mapred.ReduceTask:
> attempt_201208310112_0001_r_000000_0 Scheduled 0 outputs (0 slow hosts and0
> dup hosts)
> 2012-08-31 01:16:08,069 INFO org.apache.hadoop.mapred.ReduceTask:
> attempt_201208310112_0001_r_000000_0 Need another 1 map output(s) where 1
> is already in progress
> 2012-08-31 01:16:08,070 INFO org.apache.hadoop.mapred.ReduceTask:
> attempt_201208310112_0001_r_000000_0 Scheduled 0 outputs (0 slow hosts and0
> dup hosts)
> 2012-08-31 01:17:08,106 INFO org.apache.hadoop.mapred.ReduceTask:
> attempt_201208310112_0001_r_000000_0 Need another 1 map output(s) where 1
> is already in progress
> 2012-08-31 01:17:08,107 INFO org.apache.hadoop.mapred.ReduceTask:
> attempt_201208310112_0001_r_000000_0 Scheduled 0 outputs (0 slow hosts and0
> dup hosts)
> 2012-08-31 01:18:08,147 INFO org.apache.hadoop.mapred.ReduceTask:
> attempt_201208310112_0001_r_000000_0 Need another 1 map output(s) where 1
> is already in progress
> 2012-08-31 01:18:08,147 INFO org.apache.hadoop.mapred.ReduceTask:
> attempt_201208310112_0001_r_000000_0 Scheduled 0 outputs (0 slow hosts and0
> dup hosts)
>
> I can successfully run the wordcount example on my old macbook (os x 10.6)
> previously.
>
> Any suggestions ?
>
> Best Regards,
> Stone
>
>
>
>
> On Mon, Aug 13, 2012 at 12:21 PM, Subho Banerjee <subs.zero@gmail.com>wrote:
>
>> Hello,
>>
>> I am running hadoop v1.0.3 in Mac OS X 10.8 with Java_1.6.0_33-b03-424
>>
>>
>> When running hadoop on pseudo-distributed mode, the map seems to work,
>> but it cannot compute the reduce.
>>
>> 12/08/13 08:58:12 INFO mapred.JobClient: Running job:
>> job_201208130857_0001
>> 12/08/13 08:58:13 INFO mapred.JobClient: map 0% reduce 0%
>> 12/08/13 08:58:27 INFO mapred.JobClient: map 20% reduce 0%
>> 12/08/13 08:58:33 INFO mapred.JobClient: map 30% reduce 0%
>> 12/08/13 08:58:36 INFO mapred.JobClient: map 40% reduce 0%
>> 12/08/13 08:58:39 INFO mapred.JobClient: map 50% reduce 0%
>> 12/08/13 08:58:42 INFO mapred.JobClient: map 60% reduce 0%
>> 12/08/13 08:58:45 INFO mapred.JobClient: map 70% reduce 0%
>> 12/08/13 08:58:48 INFO mapred.JobClient: map 80% reduce 0%
>> 12/08/13 08:58:51 INFO mapred.JobClient: map 90% reduce 0%
>> 12/08/13 08:58:54 INFO mapred.JobClient: map 100% reduce 0%
>> 12/08/13 08:59:14 INFO mapred.JobClient: Task Id :
>> attempt_201208130857_0001_m_000000_0, Status : FAILED
>> Too many fetch-failures
>> 12/08/13 08:59:14 WARN mapred.JobClient: Error reading task outputServer
>> returned HTTP response code: 403 for URL:
>> http://10.1.66.17:50060/tasklog?plaintext=true&attemptid=attempt_201208130857_0001_m_000000_0&filter=stdout
>> 12/08/13 08:59:14 WARN mapred.JobClient: Error reading task outputServer
>> returned HTTP response code: 403 for URL:
>> http://10.1.66.17:50060/tasklog?plaintext=true&attemptid=attempt_201208130857_0001_m_000000_0&filter=stderr
>> 12/08/13 08:59:18 INFO mapred.JobClient: map 89% reduce 0%
>> 12/08/13 08:59:21 INFO mapred.JobClient: map 100% reduce 0%
>> 12/08/13 09:00:14 INFO mapred.JobClient: Task Id :
>> attempt_201208130857_0001_m_000001_0, Status : FAILED
>> Too many fetch-failures
>>
>> Here is what I get when I try to see the tasklog using the links given in
>> the output
>>
>>
>> http://10.1.66.17:50060/tasklog?plaintext=true&attemptid=attempt_201208130857_0001_m_000000_0&filter=stderr
>>  --->
>> 2012-08-13 08:58:39.189 java[74092:1203] Unable to load realm info from
>> SCDynamicStore
>>
>>
>> http://10.1.66.17:50060/tasklog?plaintext=true&attemptid=attempt_201208130857_0001_m_000000_0&filter=stdout
>>  --->
>>
>> I have changed my hadoop-env.sh acoording to Mathew Buckett in
>> https://issues.apache.org/jira/browse/HADOOP-7489
>>
>> Also this error of Unable to load realm info from SCDynamicStore does not
>> show up when I do 'hadoop namenode -format' or 'start-all.sh'
>>
>> I am also attaching a zipped copy of my logs
>>
>>
>> Cheers,
>>
>> Subho.
>>
>
>

Mime
View raw message