Mailing-List: contact hbase-user-help@hadoop.apache.org; run by ezmlm
Precedence: bulk
Reply-To: hbase-user@hadoop.apache.org
Received-SPF: pass (athena.apache.org: domain of maqiang1984@gmail.com
 designates 209.85.198.237 as permitted sender)
DomainKey-Signature: a=rsa-sha1; c=nofws;
        d=gmail.com; s=gamma;
        h=message-id:date:from:to:subject:in-reply-to:mime-version
         :content-type:content-transfer-encoding:content-disposition
         :references;
        b=j08+HhDJ2SYY75TTtTteglSD8LkVPNMTqHD/g7JU5yp8C1Y8b+2rQwtLoiAJ5irSWW
         LfWMADMpxRe08VHaofCOi/lpPuNAG0vfZjQRbwC9NJ1i8/cFB0Y+PIs4tfo8w8gd4/JM
         UWGoxmcShrH5p71SgqmgyRSp0OVY+PUUO2rvw=
Message-ID: <2af70f430809071921gf246ac0v74cc1d29107f3ac9@mail.gmail.com>
Date: Mon, 8 Sep 2008 10:21:49 +0800
From: "ma qiang" <maqiang1984@gmail.com>
To: hbase-user@hadoop.apache.org
Subject: Re: why failed to report status in my program?
In-Reply-To: <010601c91159$258d7980$70a86c80$@com>
MIME-Version: 1.0
Content-Type: text/plain; charset=ISO-8859-1
Content-Transfer-Encoding: 7bit
Content-Disposition: inline
References: <2af70f430809070525l23864081y6ffd263efebad871@mail.gmail.com>
	 <31a243e70809070710i3335bc39gc3a2dc93e573df27@mail.gmail.com>
	 <2af70f430809071912gbd0400bh1350c27564cf24f8@mail.gmail.com>
	 <010601c91159$258d7980$70a86c80$@com>

Ok.
I'll try.   Thank you very much !

On Mon, Sep 8, 2008 at 10:18 AM, Jonathan Gray <jlist@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 <jdcryans@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 <maqiang1984@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
>>>
>>
>
>