You are viewing a plain text version of this content. The canonical link for it is here.
Posted to user@hbase.apache.org by ma qiang <ma...@gmail.com> on 2008/09/07 14:25:20 UTC
why failed to report status in my program?
hi all,
In my mapreduce program using hbase table as input and ouput, the
console print as below:
08/09/07 19:55:51 INFO mapred.JobClient: Running job: job_200809071951_0001
08/09/07 19:55:52 INFO mapred.JobClient: map 0% reduce 0%
08/09/07 19:55:57 INFO mapred.JobClient: map 100% reduce 0%
08/09/07 19:56:02 INFO mapred.JobClient: map 100% reduce 66%
08/09/07 20:06:07 INFO mapred.JobClient: map 100% reduce 0%
08/09/07 20:06:07 INFO mapred.JobClient: Task Id :
task_200809071951_0001_r_000000_0, Status : FAILED
Task task_200809071951_0001_r_000000_0 failed to report status for 600
seconds. Killing!
08/09/07 20:06:15 INFO mapred.JobClient: map 100% reduce 66%
08/09/07 20:16:17 INFO mapred.JobClient: map 100% reduce 0%
08/09/07 20:16:17 INFO mapred.JobClient: Task Id :
task_200809071951_0001_r_000000_1, Status : FAILED
Task task_200809071951_0001_r_000000_1 failed to report status for 602
seconds. Killing!
08/09/07 20:16:26 INFO mapred.JobClient: map 100% reduce 66%
………………
………………
to be noted, I can put some values into hbase using hql in hbase shell.
who can tell why and how to solve this ?
thanks very much !
qiang
Re: why failed to report status in my program?
Posted by ma qiang <ma...@gmail.com>.
Ok.
I'll try. Thank you very much !
On Mon, Sep 8, 2008 at 10:18 AM, Jonathan Gray <jl...@streamy.com> wrote:
> You might need to turn DEBUG on to see more useful output from the logs.
> Instructions are in the wiki, simplest to just change log4j.properties by
> uncommenting the appropriate line.
>
> -----Original Message-----
> From: ma qiang [mailto:maqiang1984@gmail.com]
> Sent: Sunday, September 07, 2008 7:12 PM
> To: hbase-user@hadoop.apache.org
> Subject: Re: why failed to report status in my program?
>
> Thanks for your reply.
> I used Hadoop 0.17.2 and Hbase 0.2.0.
> In my job, the input talbe is different from output table. I don't
> understand mapping and reducing the the same table that you mentioned.
> In the process of map function, I used output.collect(Text,
> MapWritable) as the intermediate temprories, and in the process of
> reduce function I used output.collect(ImmutableBytesWritable,
> BatchUpdate) as the final output.
> l found the job halt at output.collect(ImmutableBytesWritable, BatchUpdate).
> the syslog in task_200809071951_0001_r000000_0 logs print as belows:
> 2008-09-08 10:05:56,879 INFO org.apache.hadoop.metrics.jvm.JvmMetrics:
> Initializing JVM Metrics with processName=SHUFFLE, sessionId=
> 2008-09-08 10:05:56,986 INFO org.apache.hadoop.fs.FileSystem:
> Initialized InMemoryFileSystem: ramfs://mapoutput24562387 of size (in
> bytes): 78643200
> 2008-09-08 10:05:56,986 INFO org.apache.hadoop.mapred.ReduceTask:
> task_200809080938_0001_r_000000_0 Created an InMemoryFileSystem, uri:
> ramfs://mapoutput24562387
> 2008-09-08 10:05:56,995 INFO org.apache.hadoop.mapred.ReduceTask:
> task_200809080938_0001_r_000000_0 Need 1 map output(s)
> 2008-09-08 10:05:56,998 INFO org.apache.hadoop.mapred.ReduceTask:
> task_200809080938_0001_r_000000_0: Got 0 new map-outputs & 0 obsolete
> map-outputs from tasktracker and 0 map-outputs from previous failures
> 2008-09-08 10:05:56,998 INFO org.apache.hadoop.mapred.ReduceTask:
> task_200809080938_0001_r_000000_0 Got 0 known map output location(s);
> scheduling...
> 2008-09-08 10:05:56,998 INFO org.apache.hadoop.mapred.ReduceTask:
> task_200809080938_0001_r_000000_0 Scheduled 0 of 0 known outputs (0
> slow hosts and 0 dup hosts)
> 2008-09-08 10:06:01,998 INFO org.apache.hadoop.mapred.ReduceTask:
> task_200809080938_0001_r_000000_0 Need 1 map output(s)
> 2008-09-08 10:06:02,045 INFO org.apache.hadoop.mapred.ReduceTask:
> task_200809080938_0001_r_000000_0: Got 1 new map-outputs & 0 obsolete
> map-outputs from tasktracker and 0 map-outputs from previous failures
> 2008-09-08 10:06:02,046 INFO org.apache.hadoop.mapred.ReduceTask:
> task_200809080938_0001_r_000000_0 Got 1 known map output location(s);
> scheduling...
> 2008-09-08 10:06:02,046 INFO org.apache.hadoop.mapred.ReduceTask:
> task_200809080938_0001_r_000000_0 Scheduled 1 of 1 known outputs (0
> slow hosts and 0 dup hosts)
> 2008-09-08 10:06:02,046 INFO org.apache.hadoop.mapred.ReduceTask:
> task_200809080938_0001_r_000000_0 Copying
> task_200809080938_0001_m_000000_0 output from maqiang-ubuntu.
> 2008-09-08 10:06:02,321 INFO org.apache.hadoop.mapred.ReduceTask:
> task_200809080938_0001_r_000000_0 done copying
> task_200809080938_0001_m_000000_0 output from maqiang-ubuntu.
> 2008-09-08 10:06:02,332 INFO org.apache.hadoop.mapred.ReduceTask:
> task_200809080938_0001_r_000000_0 Copying of all map outputs complete.
> Initiating the last merge on the remaining files in
> ramfs://mapoutput24562387
> 2008-09-08 10:06:02,433 INFO org.apache.hadoop.mapred.ReduceTask:
> task_200809080938_0001_r_000000_0 Merge of the 1 files in
> InMemoryFileSystem complete. Local file is
> /home/maqiang/Desktop/newhh/hadoop-0.17.2.1/hadoop_hdfs/mapred/local/taskTra
> cker/jobcache/job_200809080938_0001/task_200809080938_0001_r_000000_0/output
> /map_0.out
>
> and the logs of region server print as belows:
> Mon Sep 8 09:38:55 CST 2008 Starting regionserver on maqiang-ubuntu
> java version "1.6.0_07"
> Java(TM) SE Runtime Environment (build 1.6.0_07-b06)
> Java HotSpot(TM) Server VM (build 10.0-b23, mixed mode)
> ulimit -n 1024
> 2008-09-08 09:38:56,374 INFO org.apache.hadoop.ipc.metrics.RpcMetrics:
> Initializing RPC Metrics with hostName=HRegionServer, port=60020
> 2008-09-08 09:38:57,535 INFO
> org.apache.hadoop.hbase.regionserver.HLog: New log writer created at
> /hbase/log_10.11.8.100_1220837936420_60020/hlog.dat.1220837937464
> 2008-09-08 09:38:57,603 INFO org.mortbay.util.Credential: Checking
> Resource aliases
> 2008-09-08 09:38:57,645 INFO org.mortbay.http.HttpServer: Version
> Jetty/5.1.4
> 2008-09-08 09:38:57,646 INFO org.mortbay.util.Container: Started
> HttpContext[/static,/static]
> 2008-09-08 09:38:57,646 INFO org.mortbay.util.Container: Started
> HttpContext[/logs,/logs]
> 2008-09-08 09:38:57,938 INFO org.mortbay.util.Container: Started
> org.mortbay.jetty.servlet.WebApplicationHandler@1236cd5
> 2008-09-08 09:38:57,971 INFO org.mortbay.util.Container: Started
> WebApplicationContext[/,/]
> 2008-09-08 09:38:58,031 INFO org.mortbay.http.SocketListener: Started
> SocketListener on 0.0.0.0:60030
> 2008-09-08 09:38:58,031 INFO org.mortbay.util.Container: Started
> org.mortbay.jetty.Server@d56b37
> 2008-09-08 09:38:58,032 INFO org.apache.hadoop.ipc.Server: IPC Server
> Responder: starting
> 2008-09-08 09:38:58,044 INFO org.apache.hadoop.ipc.Server: IPC Server
> listener on 60020: starting
> 2008-09-08 09:38:58,049 INFO org.apache.hadoop.ipc.Server: IPC Server
> handler 1 on 60020: starting
> 2008-09-08 09:38:58,049 INFO org.apache.hadoop.ipc.Server: IPC Server
> handler 2 on 60020: starting
> 2008-09-08 09:38:58,050 INFO org.apache.hadoop.ipc.Server: IPC Server
> handler 3 on 60020: starting
> 2008-09-08 09:38:58,050 INFO org.apache.hadoop.ipc.Server: IPC Server
> handler 4 on 60020: starting
> 2008-09-08 09:38:58,050 INFO org.apache.hadoop.ipc.Server: IPC Server
> handler 5 on 60020: starting
> 2008-09-08 09:38:58,051 INFO org.apache.hadoop.ipc.Server: IPC Server
> handler 6 on 60020: starting
> 2008-09-08 09:38:58,051 INFO org.apache.hadoop.ipc.Server: IPC Server
> handler 7 on 60020: starting
> 2008-09-08 09:38:58,052 INFO org.apache.hadoop.ipc.Server: IPC Server
> handler 8 on 60020: starting
> 2008-09-08 09:38:58,052 INFO
> org.apache.hadoop.hbase.regionserver.HRegionServer: HRegionServer
> started at: 10.11.8.100:60020
> 2008-09-08 09:38:58,053 INFO org.apache.hadoop.ipc.Server: IPC Server
> handler 0 on 60020: starting
> 2008-09-08 09:38:58,053 INFO org.apache.hadoop.ipc.Server: IPC Server
> handler 9 on 60020: starting
> 2008-09-08 09:38:58,121 INFO
> org.apache.hadoop.hbase.regionserver.HRegionServer: MSG_REGION_OPEN:
> -ROOT-,,0
> 2008-09-08 09:38:58,122 INFO
> org.apache.hadoop.hbase.regionserver.HRegionServer: MSG_REGION_OPEN:
> -ROOT-,,0
> 2008-09-08 09:38:58,211 INFO org.apache.hadoop.util.NativeCodeLoader:
> Loaded the native-hadoop library
> 2008-09-08 09:38:58,212 INFO
> org.apache.hadoop.io.compress.zlib.ZlibFactory: Successfully loaded &
> initialized native-zlib library
> 2008-09-08 09:38:58,220 INFO
> org.apache.hadoop.hbase.regionserver.HRegion: region
> -ROOT-,,0/70236052 available
> 2008-09-08 09:38:58,221 INFO
> org.apache.hadoop.hbase.regionserver.HRegion: starting compaction on
> region -ROOT-,,0
> 2008-09-08 09:38:58,222 INFO
> org.apache.hadoop.hbase.regionserver.HRegion: compaction completed on
> region -ROOT-,,0 in 0sec
> 2008-09-08 09:39:04,135 INFO
> org.apache.hadoop.hbase.regionserver.HRegionServer: MSG_REGION_OPEN:
> .META.,,1
> 2008-09-08 09:39:04,135 INFO
> org.apache.hadoop.hbase.regionserver.HRegionServer: MSG_REGION_OPEN:
> .META.,,1
> 2008-09-08 09:39:04,154 INFO
> org.apache.hadoop.hbase.regionserver.HRegion: region
> .META.,,1/1028785192 available
> 2008-09-08 09:39:04,154 INFO
> org.apache.hadoop.hbase.regionserver.HRegion: starting compaction on
> region .META.,,1
> 2008-09-08 09:39:04,155 INFO
> org.apache.hadoop.hbase.regionserver.HRegion: compaction completed on
> region .META.,,1 in 0sec
> 2008-09-08 09:53:20,695 INFO
> org.apache.hadoop.hbase.regionserver.HRegionServer: MSG_REGION_OPEN:
> yxtest,,1220838797735
> 2008-09-08 09:53:20,696 INFO
> org.apache.hadoop.hbase.regionserver.HRegionServer: MSG_REGION_OPEN:
> yxtest,,1220838797735
> 2008-09-08 09:53:20,758 INFO
> org.apache.hadoop.hbase.regionserver.HRegion: region
> yxtest,,1220838797735/289800998 available
> 2008-09-08 09:53:20,758 INFO
> org.apache.hadoop.hbase.regionserver.HRegion: starting compaction on
> region yxtest,,1220838797735
> 2008-09-08 09:53:20,759 INFO
> org.apache.hadoop.hbase.regionserver.HRegion: compaction completed on
> region yxtest,,1220838797735 in 0sec
> 2008-09-08 09:54:05,773 INFO
> org.apache.hadoop.hbase.regionserver.HRegionServer: MSG_REGION_OPEN:
> outputyxtest,,1220838842737
> 2008-09-08 09:54:05,773 INFO
> org.apache.hadoop.hbase.regionserver.HRegionServer: MSG_REGION_OPEN:
> outputyxtest,,1220838842737
> 2008-09-08 09:54:05,787 INFO
> org.apache.hadoop.hbase.regionserver.HRegion: region
> outputyxtest,,1220838842737/631470504 available
> 2008-09-08 09:54:05,787 INFO
> org.apache.hadoop.hbase.regionserver.HRegion: starting compaction on
> region outputyxtest,,1220838842737
> 2008-09-08 09:54:05,788 INFO
> org.apache.hadoop.hbase.regionserver.HRegion: compaction completed on
> region outputyxtest,,1220838842737 in 0sec
> 2008-09-08 10:08:57,550 INFO
> org.apache.hadoop.hbase.regionserver.LogRoller: Rolling hlog. Number
> of entries: 17
> 2008-09-08 10:08:57,591 INFO
> org.apache.hadoop.hbase.regionserver.HLog: New log writer created at
> /hbase/log_10.11.8.100_1220837936420_60020/hlog.dat.1220839737574
>
>
> I haven't found anything abnormal.
>
>
>
> On Sun, Sep 7, 2008 at 10:10 PM, Jean-Daniel Cryans <jd...@apache.org>
> wrote:
>> qiang,
>>
>> Which version of Hadoop/HBase?
>> Is your job mapping and reducing to the same table?
>> Have you turned on DEBUG? (see the FAQ to know how to do it)
>> Do you see anything unusual in task_200809071951_0001_r000000_0 logs from
>> the jobtracker web UI?
>> Have you checked in the logs of the region servers?
>>
>> Thanks,
>>
>> J-D
>>
>> On Sun, Sep 7, 2008 at 8:25 AM, ma qiang <ma...@gmail.com> wrote:
>>
>>> hi all,
>>> In my mapreduce program using hbase table as input and ouput, the
>>> console print as below:
>>>
>>> 08/09/07 19:55:51 INFO mapred.JobClient: Running job:
> job_200809071951_0001
>>> 08/09/07 19:55:52 INFO mapred.JobClient: map 0% reduce 0%
>>> 08/09/07 19:55:57 INFO mapred.JobClient: map 100% reduce 0%
>>> 08/09/07 19:56:02 INFO mapred.JobClient: map 100% reduce 66%
>>> 08/09/07 20:06:07 INFO mapred.JobClient: map 100% reduce 0%
>>> 08/09/07 20:06:07 INFO mapred.JobClient: Task Id :
>>> task_200809071951_0001_r_000000_0, Status : FAILED
>>> Task task_200809071951_0001_r_000000_0 failed to report status for 600
>>> seconds. Killing!
>>> 08/09/07 20:06:15 INFO mapred.JobClient: map 100% reduce 66%
>>> 08/09/07 20:16:17 INFO mapred.JobClient: map 100% reduce 0%
>>> 08/09/07 20:16:17 INFO mapred.JobClient: Task Id :
>>> task_200809071951_0001_r_000000_1, Status : FAILED
>>> Task task_200809071951_0001_r_000000_1 failed to report status for 602
>>> seconds. Killing!
>>> 08/09/07 20:16:26 INFO mapred.JobClient: map 100% reduce 66%
>>> ......
>>> ......
>>>
>>> to be noted, I can put some values into hbase using hql in hbase shell.
>>>
>>> who can tell why and how to solve this ?
>>> thanks very much !
>>>
>>> qiang
>>>
>>
>
>
RE: why failed to report status in my program?
Posted by Jonathan Gray <jl...@streamy.com>.
You might need to turn DEBUG on to see more useful output from the logs.
Instructions are in the wiki, simplest to just change log4j.properties by
uncommenting the appropriate line.
-----Original Message-----
From: ma qiang [mailto:maqiang1984@gmail.com]
Sent: Sunday, September 07, 2008 7:12 PM
To: hbase-user@hadoop.apache.org
Subject: Re: why failed to report status in my program?
Thanks for your reply.
I used Hadoop 0.17.2 and Hbase 0.2.0.
In my job, the input talbe is different from output table. I don't
understand mapping and reducing the the same table that you mentioned.
In the process of map function, I used output.collect(Text,
MapWritable) as the intermediate temprories, and in the process of
reduce function I used output.collect(ImmutableBytesWritable,
BatchUpdate) as the final output.
l found the job halt at output.collect(ImmutableBytesWritable, BatchUpdate).
the syslog in task_200809071951_0001_r000000_0 logs print as belows:
2008-09-08 10:05:56,879 INFO org.apache.hadoop.metrics.jvm.JvmMetrics:
Initializing JVM Metrics with processName=SHUFFLE, sessionId=
2008-09-08 10:05:56,986 INFO org.apache.hadoop.fs.FileSystem:
Initialized InMemoryFileSystem: ramfs://mapoutput24562387 of size (in
bytes): 78643200
2008-09-08 10:05:56,986 INFO org.apache.hadoop.mapred.ReduceTask:
task_200809080938_0001_r_000000_0 Created an InMemoryFileSystem, uri:
ramfs://mapoutput24562387
2008-09-08 10:05:56,995 INFO org.apache.hadoop.mapred.ReduceTask:
task_200809080938_0001_r_000000_0 Need 1 map output(s)
2008-09-08 10:05:56,998 INFO org.apache.hadoop.mapred.ReduceTask:
task_200809080938_0001_r_000000_0: Got 0 new map-outputs & 0 obsolete
map-outputs from tasktracker and 0 map-outputs from previous failures
2008-09-08 10:05:56,998 INFO org.apache.hadoop.mapred.ReduceTask:
task_200809080938_0001_r_000000_0 Got 0 known map output location(s);
scheduling...
2008-09-08 10:05:56,998 INFO org.apache.hadoop.mapred.ReduceTask:
task_200809080938_0001_r_000000_0 Scheduled 0 of 0 known outputs (0
slow hosts and 0 dup hosts)
2008-09-08 10:06:01,998 INFO org.apache.hadoop.mapred.ReduceTask:
task_200809080938_0001_r_000000_0 Need 1 map output(s)
2008-09-08 10:06:02,045 INFO org.apache.hadoop.mapred.ReduceTask:
task_200809080938_0001_r_000000_0: Got 1 new map-outputs & 0 obsolete
map-outputs from tasktracker and 0 map-outputs from previous failures
2008-09-08 10:06:02,046 INFO org.apache.hadoop.mapred.ReduceTask:
task_200809080938_0001_r_000000_0 Got 1 known map output location(s);
scheduling...
2008-09-08 10:06:02,046 INFO org.apache.hadoop.mapred.ReduceTask:
task_200809080938_0001_r_000000_0 Scheduled 1 of 1 known outputs (0
slow hosts and 0 dup hosts)
2008-09-08 10:06:02,046 INFO org.apache.hadoop.mapred.ReduceTask:
task_200809080938_0001_r_000000_0 Copying
task_200809080938_0001_m_000000_0 output from maqiang-ubuntu.
2008-09-08 10:06:02,321 INFO org.apache.hadoop.mapred.ReduceTask:
task_200809080938_0001_r_000000_0 done copying
task_200809080938_0001_m_000000_0 output from maqiang-ubuntu.
2008-09-08 10:06:02,332 INFO org.apache.hadoop.mapred.ReduceTask:
task_200809080938_0001_r_000000_0 Copying of all map outputs complete.
Initiating the last merge on the remaining files in
ramfs://mapoutput24562387
2008-09-08 10:06:02,433 INFO org.apache.hadoop.mapred.ReduceTask:
task_200809080938_0001_r_000000_0 Merge of the 1 files in
InMemoryFileSystem complete. Local file is
/home/maqiang/Desktop/newhh/hadoop-0.17.2.1/hadoop_hdfs/mapred/local/taskTra
cker/jobcache/job_200809080938_0001/task_200809080938_0001_r_000000_0/output
/map_0.out
and the logs of region server print as belows:
Mon Sep 8 09:38:55 CST 2008 Starting regionserver on maqiang-ubuntu
java version "1.6.0_07"
Java(TM) SE Runtime Environment (build 1.6.0_07-b06)
Java HotSpot(TM) Server VM (build 10.0-b23, mixed mode)
ulimit -n 1024
2008-09-08 09:38:56,374 INFO org.apache.hadoop.ipc.metrics.RpcMetrics:
Initializing RPC Metrics with hostName=HRegionServer, port=60020
2008-09-08 09:38:57,535 INFO
org.apache.hadoop.hbase.regionserver.HLog: New log writer created at
/hbase/log_10.11.8.100_1220837936420_60020/hlog.dat.1220837937464
2008-09-08 09:38:57,603 INFO org.mortbay.util.Credential: Checking
Resource aliases
2008-09-08 09:38:57,645 INFO org.mortbay.http.HttpServer: Version
Jetty/5.1.4
2008-09-08 09:38:57,646 INFO org.mortbay.util.Container: Started
HttpContext[/static,/static]
2008-09-08 09:38:57,646 INFO org.mortbay.util.Container: Started
HttpContext[/logs,/logs]
2008-09-08 09:38:57,938 INFO org.mortbay.util.Container: Started
org.mortbay.jetty.servlet.WebApplicationHandler@1236cd5
2008-09-08 09:38:57,971 INFO org.mortbay.util.Container: Started
WebApplicationContext[/,/]
2008-09-08 09:38:58,031 INFO org.mortbay.http.SocketListener: Started
SocketListener on 0.0.0.0:60030
2008-09-08 09:38:58,031 INFO org.mortbay.util.Container: Started
org.mortbay.jetty.Server@d56b37
2008-09-08 09:38:58,032 INFO org.apache.hadoop.ipc.Server: IPC Server
Responder: starting
2008-09-08 09:38:58,044 INFO org.apache.hadoop.ipc.Server: IPC Server
listener on 60020: starting
2008-09-08 09:38:58,049 INFO org.apache.hadoop.ipc.Server: IPC Server
handler 1 on 60020: starting
2008-09-08 09:38:58,049 INFO org.apache.hadoop.ipc.Server: IPC Server
handler 2 on 60020: starting
2008-09-08 09:38:58,050 INFO org.apache.hadoop.ipc.Server: IPC Server
handler 3 on 60020: starting
2008-09-08 09:38:58,050 INFO org.apache.hadoop.ipc.Server: IPC Server
handler 4 on 60020: starting
2008-09-08 09:38:58,050 INFO org.apache.hadoop.ipc.Server: IPC Server
handler 5 on 60020: starting
2008-09-08 09:38:58,051 INFO org.apache.hadoop.ipc.Server: IPC Server
handler 6 on 60020: starting
2008-09-08 09:38:58,051 INFO org.apache.hadoop.ipc.Server: IPC Server
handler 7 on 60020: starting
2008-09-08 09:38:58,052 INFO org.apache.hadoop.ipc.Server: IPC Server
handler 8 on 60020: starting
2008-09-08 09:38:58,052 INFO
org.apache.hadoop.hbase.regionserver.HRegionServer: HRegionServer
started at: 10.11.8.100:60020
2008-09-08 09:38:58,053 INFO org.apache.hadoop.ipc.Server: IPC Server
handler 0 on 60020: starting
2008-09-08 09:38:58,053 INFO org.apache.hadoop.ipc.Server: IPC Server
handler 9 on 60020: starting
2008-09-08 09:38:58,121 INFO
org.apache.hadoop.hbase.regionserver.HRegionServer: MSG_REGION_OPEN:
-ROOT-,,0
2008-09-08 09:38:58,122 INFO
org.apache.hadoop.hbase.regionserver.HRegionServer: MSG_REGION_OPEN:
-ROOT-,,0
2008-09-08 09:38:58,211 INFO org.apache.hadoop.util.NativeCodeLoader:
Loaded the native-hadoop library
2008-09-08 09:38:58,212 INFO
org.apache.hadoop.io.compress.zlib.ZlibFactory: Successfully loaded &
initialized native-zlib library
2008-09-08 09:38:58,220 INFO
org.apache.hadoop.hbase.regionserver.HRegion: region
-ROOT-,,0/70236052 available
2008-09-08 09:38:58,221 INFO
org.apache.hadoop.hbase.regionserver.HRegion: starting compaction on
region -ROOT-,,0
2008-09-08 09:38:58,222 INFO
org.apache.hadoop.hbase.regionserver.HRegion: compaction completed on
region -ROOT-,,0 in 0sec
2008-09-08 09:39:04,135 INFO
org.apache.hadoop.hbase.regionserver.HRegionServer: MSG_REGION_OPEN:
.META.,,1
2008-09-08 09:39:04,135 INFO
org.apache.hadoop.hbase.regionserver.HRegionServer: MSG_REGION_OPEN:
.META.,,1
2008-09-08 09:39:04,154 INFO
org.apache.hadoop.hbase.regionserver.HRegion: region
.META.,,1/1028785192 available
2008-09-08 09:39:04,154 INFO
org.apache.hadoop.hbase.regionserver.HRegion: starting compaction on
region .META.,,1
2008-09-08 09:39:04,155 INFO
org.apache.hadoop.hbase.regionserver.HRegion: compaction completed on
region .META.,,1 in 0sec
2008-09-08 09:53:20,695 INFO
org.apache.hadoop.hbase.regionserver.HRegionServer: MSG_REGION_OPEN:
yxtest,,1220838797735
2008-09-08 09:53:20,696 INFO
org.apache.hadoop.hbase.regionserver.HRegionServer: MSG_REGION_OPEN:
yxtest,,1220838797735
2008-09-08 09:53:20,758 INFO
org.apache.hadoop.hbase.regionserver.HRegion: region
yxtest,,1220838797735/289800998 available
2008-09-08 09:53:20,758 INFO
org.apache.hadoop.hbase.regionserver.HRegion: starting compaction on
region yxtest,,1220838797735
2008-09-08 09:53:20,759 INFO
org.apache.hadoop.hbase.regionserver.HRegion: compaction completed on
region yxtest,,1220838797735 in 0sec
2008-09-08 09:54:05,773 INFO
org.apache.hadoop.hbase.regionserver.HRegionServer: MSG_REGION_OPEN:
outputyxtest,,1220838842737
2008-09-08 09:54:05,773 INFO
org.apache.hadoop.hbase.regionserver.HRegionServer: MSG_REGION_OPEN:
outputyxtest,,1220838842737
2008-09-08 09:54:05,787 INFO
org.apache.hadoop.hbase.regionserver.HRegion: region
outputyxtest,,1220838842737/631470504 available
2008-09-08 09:54:05,787 INFO
org.apache.hadoop.hbase.regionserver.HRegion: starting compaction on
region outputyxtest,,1220838842737
2008-09-08 09:54:05,788 INFO
org.apache.hadoop.hbase.regionserver.HRegion: compaction completed on
region outputyxtest,,1220838842737 in 0sec
2008-09-08 10:08:57,550 INFO
org.apache.hadoop.hbase.regionserver.LogRoller: Rolling hlog. Number
of entries: 17
2008-09-08 10:08:57,591 INFO
org.apache.hadoop.hbase.regionserver.HLog: New log writer created at
/hbase/log_10.11.8.100_1220837936420_60020/hlog.dat.1220839737574
I haven't found anything abnormal.
On Sun, Sep 7, 2008 at 10:10 PM, Jean-Daniel Cryans <jd...@apache.org>
wrote:
> qiang,
>
> Which version of Hadoop/HBase?
> Is your job mapping and reducing to the same table?
> Have you turned on DEBUG? (see the FAQ to know how to do it)
> Do you see anything unusual in task_200809071951_0001_r000000_0 logs from
> the jobtracker web UI?
> Have you checked in the logs of the region servers?
>
> Thanks,
>
> J-D
>
> On Sun, Sep 7, 2008 at 8:25 AM, ma qiang <ma...@gmail.com> wrote:
>
>> hi all,
>> In my mapreduce program using hbase table as input and ouput, the
>> console print as below:
>>
>> 08/09/07 19:55:51 INFO mapred.JobClient: Running job:
job_200809071951_0001
>> 08/09/07 19:55:52 INFO mapred.JobClient: map 0% reduce 0%
>> 08/09/07 19:55:57 INFO mapred.JobClient: map 100% reduce 0%
>> 08/09/07 19:56:02 INFO mapred.JobClient: map 100% reduce 66%
>> 08/09/07 20:06:07 INFO mapred.JobClient: map 100% reduce 0%
>> 08/09/07 20:06:07 INFO mapred.JobClient: Task Id :
>> task_200809071951_0001_r_000000_0, Status : FAILED
>> Task task_200809071951_0001_r_000000_0 failed to report status for 600
>> seconds. Killing!
>> 08/09/07 20:06:15 INFO mapred.JobClient: map 100% reduce 66%
>> 08/09/07 20:16:17 INFO mapred.JobClient: map 100% reduce 0%
>> 08/09/07 20:16:17 INFO mapred.JobClient: Task Id :
>> task_200809071951_0001_r_000000_1, Status : FAILED
>> Task task_200809071951_0001_r_000000_1 failed to report status for 602
>> seconds. Killing!
>> 08/09/07 20:16:26 INFO mapred.JobClient: map 100% reduce 66%
>> ......
>> ......
>>
>> to be noted, I can put some values into hbase using hql in hbase shell.
>>
>> who can tell why and how to solve this ?
>> thanks very much !
>>
>> qiang
>>
>
Re: why failed to report status in my program?
Posted by ma qiang <ma...@gmail.com>.
Thanks for your reply.
I used Hadoop 0.17.2 and Hbase 0.2.0.
In my job, the input talbe is different from output table. I don't
understand mapping and reducing the the same table that you mentioned.
In the process of map function, I used output.collect(Text,
MapWritable) as the intermediate temprories, and in the process of
reduce function I used output.collect(ImmutableBytesWritable,
BatchUpdate) as the final output.
l found the job halt at output.collect(ImmutableBytesWritable, BatchUpdate).
the syslog in task_200809071951_0001_r000000_0 logs print as belows:
2008-09-08 10:05:56,879 INFO org.apache.hadoop.metrics.jvm.JvmMetrics:
Initializing JVM Metrics with processName=SHUFFLE, sessionId=
2008-09-08 10:05:56,986 INFO org.apache.hadoop.fs.FileSystem:
Initialized InMemoryFileSystem: ramfs://mapoutput24562387 of size (in
bytes): 78643200
2008-09-08 10:05:56,986 INFO org.apache.hadoop.mapred.ReduceTask:
task_200809080938_0001_r_000000_0 Created an InMemoryFileSystem, uri:
ramfs://mapoutput24562387
2008-09-08 10:05:56,995 INFO org.apache.hadoop.mapred.ReduceTask:
task_200809080938_0001_r_000000_0 Need 1 map output(s)
2008-09-08 10:05:56,998 INFO org.apache.hadoop.mapred.ReduceTask:
task_200809080938_0001_r_000000_0: Got 0 new map-outputs & 0 obsolete
map-outputs from tasktracker and 0 map-outputs from previous failures
2008-09-08 10:05:56,998 INFO org.apache.hadoop.mapred.ReduceTask:
task_200809080938_0001_r_000000_0 Got 0 known map output location(s);
scheduling...
2008-09-08 10:05:56,998 INFO org.apache.hadoop.mapred.ReduceTask:
task_200809080938_0001_r_000000_0 Scheduled 0 of 0 known outputs (0
slow hosts and 0 dup hosts)
2008-09-08 10:06:01,998 INFO org.apache.hadoop.mapred.ReduceTask:
task_200809080938_0001_r_000000_0 Need 1 map output(s)
2008-09-08 10:06:02,045 INFO org.apache.hadoop.mapred.ReduceTask:
task_200809080938_0001_r_000000_0: Got 1 new map-outputs & 0 obsolete
map-outputs from tasktracker and 0 map-outputs from previous failures
2008-09-08 10:06:02,046 INFO org.apache.hadoop.mapred.ReduceTask:
task_200809080938_0001_r_000000_0 Got 1 known map output location(s);
scheduling...
2008-09-08 10:06:02,046 INFO org.apache.hadoop.mapred.ReduceTask:
task_200809080938_0001_r_000000_0 Scheduled 1 of 1 known outputs (0
slow hosts and 0 dup hosts)
2008-09-08 10:06:02,046 INFO org.apache.hadoop.mapred.ReduceTask:
task_200809080938_0001_r_000000_0 Copying
task_200809080938_0001_m_000000_0 output from maqiang-ubuntu.
2008-09-08 10:06:02,321 INFO org.apache.hadoop.mapred.ReduceTask:
task_200809080938_0001_r_000000_0 done copying
task_200809080938_0001_m_000000_0 output from maqiang-ubuntu.
2008-09-08 10:06:02,332 INFO org.apache.hadoop.mapred.ReduceTask:
task_200809080938_0001_r_000000_0 Copying of all map outputs complete.
Initiating the last merge on the remaining files in
ramfs://mapoutput24562387
2008-09-08 10:06:02,433 INFO org.apache.hadoop.mapred.ReduceTask:
task_200809080938_0001_r_000000_0 Merge of the 1 files in
InMemoryFileSystem complete. Local file is
/home/maqiang/Desktop/newhh/hadoop-0.17.2.1/hadoop_hdfs/mapred/local/taskTracker/jobcache/job_200809080938_0001/task_200809080938_0001_r_000000_0/output/map_0.out
and the logs of region server print as belows:
Mon Sep 8 09:38:55 CST 2008 Starting regionserver on maqiang-ubuntu
java version "1.6.0_07"
Java(TM) SE Runtime Environment (build 1.6.0_07-b06)
Java HotSpot(TM) Server VM (build 10.0-b23, mixed mode)
ulimit -n 1024
2008-09-08 09:38:56,374 INFO org.apache.hadoop.ipc.metrics.RpcMetrics:
Initializing RPC Metrics with hostName=HRegionServer, port=60020
2008-09-08 09:38:57,535 INFO
org.apache.hadoop.hbase.regionserver.HLog: New log writer created at
/hbase/log_10.11.8.100_1220837936420_60020/hlog.dat.1220837937464
2008-09-08 09:38:57,603 INFO org.mortbay.util.Credential: Checking
Resource aliases
2008-09-08 09:38:57,645 INFO org.mortbay.http.HttpServer: Version Jetty/5.1.4
2008-09-08 09:38:57,646 INFO org.mortbay.util.Container: Started
HttpContext[/static,/static]
2008-09-08 09:38:57,646 INFO org.mortbay.util.Container: Started
HttpContext[/logs,/logs]
2008-09-08 09:38:57,938 INFO org.mortbay.util.Container: Started
org.mortbay.jetty.servlet.WebApplicationHandler@1236cd5
2008-09-08 09:38:57,971 INFO org.mortbay.util.Container: Started
WebApplicationContext[/,/]
2008-09-08 09:38:58,031 INFO org.mortbay.http.SocketListener: Started
SocketListener on 0.0.0.0:60030
2008-09-08 09:38:58,031 INFO org.mortbay.util.Container: Started
org.mortbay.jetty.Server@d56b37
2008-09-08 09:38:58,032 INFO org.apache.hadoop.ipc.Server: IPC Server
Responder: starting
2008-09-08 09:38:58,044 INFO org.apache.hadoop.ipc.Server: IPC Server
listener on 60020: starting
2008-09-08 09:38:58,049 INFO org.apache.hadoop.ipc.Server: IPC Server
handler 1 on 60020: starting
2008-09-08 09:38:58,049 INFO org.apache.hadoop.ipc.Server: IPC Server
handler 2 on 60020: starting
2008-09-08 09:38:58,050 INFO org.apache.hadoop.ipc.Server: IPC Server
handler 3 on 60020: starting
2008-09-08 09:38:58,050 INFO org.apache.hadoop.ipc.Server: IPC Server
handler 4 on 60020: starting
2008-09-08 09:38:58,050 INFO org.apache.hadoop.ipc.Server: IPC Server
handler 5 on 60020: starting
2008-09-08 09:38:58,051 INFO org.apache.hadoop.ipc.Server: IPC Server
handler 6 on 60020: starting
2008-09-08 09:38:58,051 INFO org.apache.hadoop.ipc.Server: IPC Server
handler 7 on 60020: starting
2008-09-08 09:38:58,052 INFO org.apache.hadoop.ipc.Server: IPC Server
handler 8 on 60020: starting
2008-09-08 09:38:58,052 INFO
org.apache.hadoop.hbase.regionserver.HRegionServer: HRegionServer
started at: 10.11.8.100:60020
2008-09-08 09:38:58,053 INFO org.apache.hadoop.ipc.Server: IPC Server
handler 0 on 60020: starting
2008-09-08 09:38:58,053 INFO org.apache.hadoop.ipc.Server: IPC Server
handler 9 on 60020: starting
2008-09-08 09:38:58,121 INFO
org.apache.hadoop.hbase.regionserver.HRegionServer: MSG_REGION_OPEN:
-ROOT-,,0
2008-09-08 09:38:58,122 INFO
org.apache.hadoop.hbase.regionserver.HRegionServer: MSG_REGION_OPEN:
-ROOT-,,0
2008-09-08 09:38:58,211 INFO org.apache.hadoop.util.NativeCodeLoader:
Loaded the native-hadoop library
2008-09-08 09:38:58,212 INFO
org.apache.hadoop.io.compress.zlib.ZlibFactory: Successfully loaded &
initialized native-zlib library
2008-09-08 09:38:58,220 INFO
org.apache.hadoop.hbase.regionserver.HRegion: region
-ROOT-,,0/70236052 available
2008-09-08 09:38:58,221 INFO
org.apache.hadoop.hbase.regionserver.HRegion: starting compaction on
region -ROOT-,,0
2008-09-08 09:38:58,222 INFO
org.apache.hadoop.hbase.regionserver.HRegion: compaction completed on
region -ROOT-,,0 in 0sec
2008-09-08 09:39:04,135 INFO
org.apache.hadoop.hbase.regionserver.HRegionServer: MSG_REGION_OPEN:
.META.,,1
2008-09-08 09:39:04,135 INFO
org.apache.hadoop.hbase.regionserver.HRegionServer: MSG_REGION_OPEN:
.META.,,1
2008-09-08 09:39:04,154 INFO
org.apache.hadoop.hbase.regionserver.HRegion: region
.META.,,1/1028785192 available
2008-09-08 09:39:04,154 INFO
org.apache.hadoop.hbase.regionserver.HRegion: starting compaction on
region .META.,,1
2008-09-08 09:39:04,155 INFO
org.apache.hadoop.hbase.regionserver.HRegion: compaction completed on
region .META.,,1 in 0sec
2008-09-08 09:53:20,695 INFO
org.apache.hadoop.hbase.regionserver.HRegionServer: MSG_REGION_OPEN:
yxtest,,1220838797735
2008-09-08 09:53:20,696 INFO
org.apache.hadoop.hbase.regionserver.HRegionServer: MSG_REGION_OPEN:
yxtest,,1220838797735
2008-09-08 09:53:20,758 INFO
org.apache.hadoop.hbase.regionserver.HRegion: region
yxtest,,1220838797735/289800998 available
2008-09-08 09:53:20,758 INFO
org.apache.hadoop.hbase.regionserver.HRegion: starting compaction on
region yxtest,,1220838797735
2008-09-08 09:53:20,759 INFO
org.apache.hadoop.hbase.regionserver.HRegion: compaction completed on
region yxtest,,1220838797735 in 0sec
2008-09-08 09:54:05,773 INFO
org.apache.hadoop.hbase.regionserver.HRegionServer: MSG_REGION_OPEN:
outputyxtest,,1220838842737
2008-09-08 09:54:05,773 INFO
org.apache.hadoop.hbase.regionserver.HRegionServer: MSG_REGION_OPEN:
outputyxtest,,1220838842737
2008-09-08 09:54:05,787 INFO
org.apache.hadoop.hbase.regionserver.HRegion: region
outputyxtest,,1220838842737/631470504 available
2008-09-08 09:54:05,787 INFO
org.apache.hadoop.hbase.regionserver.HRegion: starting compaction on
region outputyxtest,,1220838842737
2008-09-08 09:54:05,788 INFO
org.apache.hadoop.hbase.regionserver.HRegion: compaction completed on
region outputyxtest,,1220838842737 in 0sec
2008-09-08 10:08:57,550 INFO
org.apache.hadoop.hbase.regionserver.LogRoller: Rolling hlog. Number
of entries: 17
2008-09-08 10:08:57,591 INFO
org.apache.hadoop.hbase.regionserver.HLog: New log writer created at
/hbase/log_10.11.8.100_1220837936420_60020/hlog.dat.1220839737574
I haven't found anything abnormal.
On Sun, Sep 7, 2008 at 10:10 PM, Jean-Daniel Cryans <jd...@apache.org> wrote:
> qiang,
>
> Which version of Hadoop/HBase?
> Is your job mapping and reducing to the same table?
> Have you turned on DEBUG? (see the FAQ to know how to do it)
> Do you see anything unusual in task_200809071951_0001_r000000_0 logs from
> the jobtracker web UI?
> Have you checked in the logs of the region servers?
>
> Thanks,
>
> J-D
>
> On Sun, Sep 7, 2008 at 8:25 AM, ma qiang <ma...@gmail.com> wrote:
>
>> hi all,
>> In my mapreduce program using hbase table as input and ouput, the
>> console print as below:
>>
>> 08/09/07 19:55:51 INFO mapred.JobClient: Running job: job_200809071951_0001
>> 08/09/07 19:55:52 INFO mapred.JobClient: map 0% reduce 0%
>> 08/09/07 19:55:57 INFO mapred.JobClient: map 100% reduce 0%
>> 08/09/07 19:56:02 INFO mapred.JobClient: map 100% reduce 66%
>> 08/09/07 20:06:07 INFO mapred.JobClient: map 100% reduce 0%
>> 08/09/07 20:06:07 INFO mapred.JobClient: Task Id :
>> task_200809071951_0001_r_000000_0, Status : FAILED
>> Task task_200809071951_0001_r_000000_0 failed to report status for 600
>> seconds. Killing!
>> 08/09/07 20:06:15 INFO mapred.JobClient: map 100% reduce 66%
>> 08/09/07 20:16:17 INFO mapred.JobClient: map 100% reduce 0%
>> 08/09/07 20:16:17 INFO mapred.JobClient: Task Id :
>> task_200809071951_0001_r_000000_1, Status : FAILED
>> Task task_200809071951_0001_r_000000_1 failed to report status for 602
>> seconds. Killing!
>> 08/09/07 20:16:26 INFO mapred.JobClient: map 100% reduce 66%
>> ………………
>> ………………
>>
>> to be noted, I can put some values into hbase using hql in hbase shell.
>>
>> who can tell why and how to solve this ?
>> thanks very much !
>>
>> qiang
>>
>
Re: why failed to report status in my program?
Posted by Jean-Daniel Cryans <jd...@apache.org>.
qiang,
Which version of Hadoop/HBase?
Is your job mapping and reducing to the same table?
Have you turned on DEBUG? (see the FAQ to know how to do it)
Do you see anything unusual in task_200809071951_0001_r000000_0 logs from
the jobtracker web UI?
Have you checked in the logs of the region servers?
Thanks,
J-D
On Sun, Sep 7, 2008 at 8:25 AM, ma qiang <ma...@gmail.com> wrote:
> hi all,
> In my mapreduce program using hbase table as input and ouput, the
> console print as below:
>
> 08/09/07 19:55:51 INFO mapred.JobClient: Running job: job_200809071951_0001
> 08/09/07 19:55:52 INFO mapred.JobClient: map 0% reduce 0%
> 08/09/07 19:55:57 INFO mapred.JobClient: map 100% reduce 0%
> 08/09/07 19:56:02 INFO mapred.JobClient: map 100% reduce 66%
> 08/09/07 20:06:07 INFO mapred.JobClient: map 100% reduce 0%
> 08/09/07 20:06:07 INFO mapred.JobClient: Task Id :
> task_200809071951_0001_r_000000_0, Status : FAILED
> Task task_200809071951_0001_r_000000_0 failed to report status for 600
> seconds. Killing!
> 08/09/07 20:06:15 INFO mapred.JobClient: map 100% reduce 66%
> 08/09/07 20:16:17 INFO mapred.JobClient: map 100% reduce 0%
> 08/09/07 20:16:17 INFO mapred.JobClient: Task Id :
> task_200809071951_0001_r_000000_1, Status : FAILED
> Task task_200809071951_0001_r_000000_1 failed to report status for 602
> seconds. Killing!
> 08/09/07 20:16:26 INFO mapred.JobClient: map 100% reduce 66%
> ………………
> ………………
>
> to be noted, I can put some values into hbase using hql in hbase shell.
>
> who can tell why and how to solve this ?
> thanks very much !
>
> qiang
>