Return-Path: Delivered-To: apmail-hadoop-hbase-user-archive@locus.apache.org Received: (qmail 6920 invoked from network); 9 Dec 2008 17:02:16 -0000 Received: from hermes.apache.org (HELO mail.apache.org) (140.211.11.2) by minotaur.apache.org with SMTP; 9 Dec 2008 17:02:16 -0000 Received: (qmail 39295 invoked by uid 500); 9 Dec 2008 17:02:25 -0000 Delivered-To: apmail-hadoop-hbase-user-archive@hadoop.apache.org Received: (qmail 39179 invoked by uid 500); 9 Dec 2008 17:02:24 -0000 Mailing-List: contact hbase-user-help@hadoop.apache.org; run by ezmlm Precedence: bulk List-Help: List-Unsubscribe: List-Post: List-Id: Reply-To: hbase-user@hadoop.apache.org Delivered-To: mailing list hbase-user@hadoop.apache.org Received: (qmail 39131 invoked by uid 99); 9 Dec 2008 17:02:24 -0000 Received: from nike.apache.org (HELO nike.apache.org) (192.87.106.230) by apache.org (qpsmtpd/0.29) with ESMTP; Tue, 09 Dec 2008 09:02:24 -0800 X-ASF-Spam-Status: No, hits=-4.0 required=10.0 tests=RCVD_IN_DNSWL_MED,SPF_PASS X-Spam-Check-By: apache.org Received-SPF: pass (nike.apache.org: local policy includes SPF record at spf.trusted-forwarder.org) Received: from [64.18.1.181] (HELO exprod6og101.obsmtp.com) (64.18.1.181) by apache.org (qpsmtpd/0.29) with ESMTP; Tue, 09 Dec 2008 17:02:04 +0000 Received: from source ([192.150.8.22]) by exprod6ob101.postini.com ([64.18.5.12]) with SMTP ID DSNKST6kcDw1MWMPvMlLR21SDmJlvcjaIpVf@postini.com; Tue, 09 Dec 2008 09:01:43 PST Received: from inner-relay-1.corp.adobe.com ([153.32.1.51]) by outbound-smtp-2.corp.adobe.com (8.12.10/8.12.10) with ESMTP id mB9H1XE0027741; Tue, 9 Dec 2008 09:01:34 -0800 (PST) Received: from nacas02.corp.adobe.com (nacas02.corp.adobe.com [10.8.189.100]) by inner-relay-1.corp.adobe.com (8.12.10/8.12.10) with ESMTP id mB9H1Wiq003057; Tue, 9 Dec 2008 09:01:32 -0800 (PST) Received: from nacas03.corp.adobe.com (10.8.189.121) by nacas02.corp.adobe.com (10.8.189.100) with Microsoft SMTP Server (TLS) id 8.1.291.4; Tue, 9 Dec 2008 09:01:33 -0800 Received: from eurhub01.eur.adobe.com (10.128.4.30) by nacas03.corp.adobe.com (10.8.189.121) with Microsoft SMTP Server (TLS) id 8.1.291.4; Tue, 9 Dec 2008 09:01:32 -0800 Received: from eurmbx01.eur.adobe.com ([10.128.4.32]) by eurhub01.eur.adobe.com ([10.128.4.30]) with mapi; Tue, 9 Dec 2008 17:01:30 +0000 From: Cosmin Lehene To: "hbase-user@hadoop.apache.org" CC: "hbase-dev@hadoop.apache.org" Date: Tue, 9 Dec 2008 17:01:26 +0000 Subject: Re: Loosing an entire table after restarting the region server hosting it Thread-Topic: Loosing an entire table after restarting the region server hosting it Thread-Index: AclaDfWzLuiDIhubVECpkLSSMh0FAwAEc/D0 Message-ID: In-Reply-To: Accept-Language: en-US Content-Language: en X-MS-Has-Attach: X-MS-TNEF-Correlator: acceptlanguage: en-US Content-Type: text/plain; charset="iso-8859-1" Content-Transfer-Encoding: quoted-printable MIME-Version: 1.0 X-Virus-Checked: Checked by ClamAV on apache.org This also reproduces on HBase-0.18.1 and HBase-0.18.2. Apparently its org.a= pache.hadoop.hbase.DroppedSnapshotException that is causing the cache data = loss. If between step 4 and step 5 the cache is flushed (e.g. Hbase cluster resta= rt) no data is loss. However it means that if you stop a region server with= dirty cache you will loose some data. Step 5 is hbase/bin/hbase-daemon.sh stop regionserver I raised https://issues.apache.org/jira/browse/HBASE-1052 On 12/9/08 4:53 PM, "Cosmin Lehene" wrote: Hi, It seems https://issues.apache.org/jira/browse/HBASE-1010 has some ugly eff= ects: data from entire table is missing after stopping the HRegionServer Hadoop 0.18.2 Hbase 0.18.0 Reproducing it is simple: 1. Start a Hbase cluster 2. Create a table t1: create 't1', {NAME =3D> 'f1'} 3. Put a cell in the table: put 't1', 'r1', 'f1:', 'value' 4. Scan it, see it's fine 5. Stop the HRegionSever hosting the t1 region. Watch the region being re= assigned from the original HRegionServer 6. Scan the t1 table again. It's empty now. The problem we initially found was that a few hours after restarting a HREg= ionServer we couldn't instantiate any scanners on the affected table. The p= roblem could have been solved with a HRegionServer restart. However when tr= ying to reproduce it the entire table content disappeared . Thanks, Cosmin Original HRegionServer: java version "1.6.0_06" Java(TM) SE Runtime Environment (build 1.6.0_06-b02) Java HotSpot(TM) 64-Bit Server VM (build 10.0-b22, mixed mode) ulimit -n 32768 2008-12-09 06:35:26,761 INFO org.apache.hadoop.ipc.metrics.RpcMetrics: Init= ializing RPC Metrics with hostName=3DHRegionServer, port=3D60020 2008-12-09 06:35:26,862 DEBUG org.apache.hadoop.hbase.regionserver.HRegionS= erver: Telling master at h2:60000 that we are up 2008-12-09 06:35:27,559 DEBUG org.apache.hadoop.hbase.regionserver.HRegionS= erver: Config from master: hbase.regionserver.address=3D10.131.237.51 2008-12-09 06:35:27,559 DEBUG org.apache.hadoop.hbase.regionserver.HRegionS= erver: Config from master: fs.default.name=3Dhdfs://h1:54310/hbase 2008-12-09 06:35:27,559 DEBUG org.apache.hadoop.hbase.regionserver.HRegionS= erver: Config from master: hbase.rootdir=3Dhdfs://h1:54310/hbase 2008-12-09 06:35:27,731 DEBUG org.apache.hadoop.hbase.regionserver.HRegionS= erver: Log dir hdfs://h1:54310/hbase/log_10.131.237.51_1228833326838_60020 2008-12-09 06:35:27,835 INFO org.apache.hadoop.hbase.regionserver.HLog: New= log writer created at /hbase/log_10.131.237.51_1228833326838_60020/hlog.da= t.1228833327777 2008-12-09 06:35:27,908 INFO org.mortbay.util.Credential: Checking Resource= aliases 2008-12-09 06:35:27,956 INFO org.mortbay.http.HttpServer: Version Jetty/5.1= .4 2008-12-09 06:35:27,957 INFO org.mortbay.util.Container: Started HttpContex= t[/static,/static] 2008-12-09 06:35:27,957 INFO org.mortbay.util.Container: Started HttpContex= t[/logs,/logs] 2008-12-09 06:35:28,510 INFO org.mortbay.util.Container: Started org.mortba= y.jetty.servlet.WebApplicationHandler@60ded0f0 2008-12-09 06:35:28,565 INFO org.mortbay.util.Container: Started WebApplica= tionContext[/,/] 2008-12-09 06:35:28,568 INFO org.mortbay.http.SocketListener: Started Socke= tListener on 0.0.0.0:60030 2008-12-09 06:35:28,568 INFO org.mortbay.util.Container: Started org.mortba= y.jetty.Server@6490832e 2008-12-09 06:35:28,568 INFO org.apache.hadoop.ipc.Server: IPC Server Respo= nder: starting 2008-12-09 06:35:28,570 INFO org.apache.hadoop.ipc.Server: IPC Server liste= ner on 60020: starting 2008-12-09 06:35:28,570 INFO org.apache.hadoop.ipc.Server: IPC Server handl= er 0 on 60020: starting 2008-12-09 06:35:28,577 INFO org.apache.hadoop.ipc.Server: IPC Server handl= er 1 on 60020: starting 2008-12-09 06:35:28,578 INFO org.apache.hadoop.ipc.Server: IPC Server handl= er 2 on 60020: starting 2008-12-09 06:35:28,578 INFO org.apache.hadoop.ipc.Server: IPC Server handl= er 3 on 60020: starting 2008-12-09 06:35:28,578 INFO org.apache.hadoop.ipc.Server: IPC Server handl= er 4 on 60020: starting 2008-12-09 06:35:28,578 INFO org.apache.hadoop.ipc.Server: IPC Server handl= er 5 on 60020: starting 2008-12-09 06:35:28,579 INFO org.apache.hadoop.ipc.Server: IPC Server handl= er 6 on 60020: starting 2008-12-09 06:35:28,579 INFO org.apache.hadoop.ipc.Server: IPC Server handl= er 7 on 60020: starting 2008-12-09 06:35:28,579 INFO org.apache.hadoop.ipc.Server: IPC Server handl= er 8 on 60020: starting 2008-12-09 06:35:28,579 INFO org.apache.hadoop.hbase.regionserver.HRegionSe= rver: HRegionServer started at: 10.131.237.51:60020 2008-12-09 06:35:28,580 INFO org.apache.hadoop.ipc.Server: IPC Server handl= er 9 on 60020: starting 2008-12-09 06:36:04,729 INFO org.apache.hadoop.hbase.regionserver.HRegionSe= rver: MSG_REGION_OPEN: t1,,1228833363456 2008-12-09 06:36:04,730 INFO org.apache.hadoop.hbase.regionserver.HRegionSe= rver: MSG_REGION_OPEN: t1,,1228833363456 2008-12-09 06:36:04,815 DEBUG org.apache.hadoop.hbase.client.HConnectionMan= ager$TableServers: Found ROOT REGION =3D> {NAME =3D> '-ROOT-,,0', STARTKEY = =3D> '', ENDKEY =3D> '', ENCODED =3D> 70236052, TABLE =3D> {{NAME =3D> '-RO= OT-', IS_ROOT =3D> 'true', IS_META =3D> 'true', FAMILIES =3D> [{NAME =3D> '= info', BLOOMFILTER =3D> 'false', COMPRESSION =3D> 'NONE', VERSIONS =3D> '1'= , LENGTH =3D> '2147483647', TTL =3D> '-1', IN_MEMORY =3D> 'false', BLOCKCAC= HE =3D> 'false'}]}} 2008-12-09 06:36:04,840 DEBUG org.apache.hadoop.hbase.RegionHistorian: Onli= ned 2008-12-09 06:36:04,851 DEBUG org.apache.hadoop.hbase.regionserver.HRegion:= Opening region t1,,1228833363456/2133923429 2008-12-09 06:36:04,881 DEBUG org.apache.hadoop.hbase.regionserver.HRegion:= Next sequence id for region t1,,1228833363456 is 0 2008-12-09 06:36:04,883 INFO org.apache.hadoop.hbase.regionserver.HRegion: = region t1,,1228833363456/2133923429 available 2008-12-09 06:36:04,884 DEBUG org.apache.hadoop.hbase.regionserver.CompactS= plitThread: Compaction requested for region: t1,,1228833363456 2008-12-09 06:36:04,884 INFO org.apache.hadoop.hbase.regionserver.HRegion: = starting compaction on region t1,,1228833363456 2008-12-09 06:36:04,886 INFO org.apache.hadoop.hbase.regionserver.HRegion: = compaction completed on region t1,,1228833363456 in 0sec Tue Dec 9 16:37:46 EET 2008 Stopping regionserver Tue Dec 9 16:37:46 EET 2008 Killing regionserver 2008-12-09 06:37:46,119 INFO org.apache.hadoop.hbase.regionserver.HRegionSe= rver: Starting shutdown thread. 2008-12-09 06:37:46,871 DEBUG org.apache.hadoop.hbase.RegionHistorian: Offl= ined 2008-12-09 06:37:46,871 INFO org.apache.hadoop.ipc.Server: Stopping server = on 60020 2008-12-09 06:37:46,872 INFO org.apache.hadoop.ipc.Server: Stopping IPC Ser= ver listener on 60020 2008-12-09 06:37:46,872 INFO org.apache.hadoop.ipc.Server: IPC Server handl= er 1 on 60020: exiting 2008-12-09 06:37:46,872 INFO org.apache.hadoop.ipc.Server: IPC Server handl= er 6 on 60020: exiting 2008-12-09 06:37:46,872 INFO org.apache.hadoop.ipc.Server: IPC Server handl= er 2 on 60020: exiting 2008-12-09 06:37:46,873 INFO org.apache.hadoop.ipc.Server: IPC Server handl= er 3 on 60020: exiting 2008-12-09 06:37:46,873 INFO org.apache.hadoop.ipc.Server: IPC Server handl= er 4 on 60020: exiting 2008-12-09 06:37:46,873 INFO org.apache.hadoop.ipc.Server: IPC Server handl= er 5 on 60020: exiting 2008-12-09 06:37:46,873 INFO org.apache.hadoop.ipc.Server: IPC Server handl= er 7 on 60020: exiting 2008-12-09 06:37:46,873 INFO org.apache.hadoop.ipc.Server: IPC Server handl= er 8 on 60020: exiting 2008-12-09 06:37:46,873 INFO org.apache.hadoop.ipc.Server: IPC Server handl= er 9 on 60020: exiting 2008-12-09 06:37:46,873 INFO org.apache.hadoop.ipc.Server: IPC Server handl= er 0 on 60020: exiting 2008-12-09 06:37:46,874 INFO org.apache.hadoop.hbase.regionserver.HRegionSe= rver: Stopping infoServer 2008-12-09 06:37:46,874 INFO org.apache.hadoop.ipc.Server: Stopping IPC Ser= ver Responder 2008-12-09 06:37:46,874 INFO org.mortbay.util.ThreadedServer: Stopping Acce= ptor ServerSocket[addr=3D0.0.0.0/0.0.0.0,port=3D0,localport=3D60030] 2008-12-09 06:37:46,886 INFO org.mortbay.http.SocketListener: Stopped Socke= tListener on 0.0.0.0:60030 2008-12-09 06:37:46,948 INFO org.mortbay.util.Container: Stopped HttpContex= t[/static,/static] 2008-12-09 06:37:47,007 INFO org.mortbay.util.Container: Stopped HttpContex= t[/logs,/logs] 2008-12-09 06:37:47,007 INFO org.mortbay.util.Container: Stopped org.mortba= y.jetty.servlet.WebApplicationHandler@60ded0f0 2008-12-09 06:37:47,094 INFO org.mortbay.util.Container: Stopped WebApplica= tionContext[/,/] 2008-12-09 06:37:47,094 INFO org.mortbay.util.Container: Stopped org.mortba= y.jetty.Server@6490832e 2008-12-09 06:37:47,094 DEBUG org.apache.hadoop.hbase.regionserver.HRegionS= erver: closing region t1,,1228833363456 2008-12-09 06:37:47,094 DEBUG org.apache.hadoop.hbase.regionserver.HRegion:= Compactions and cache flushes disabled for region t1,,1228833363456 2008-12-09 06:37:47,094 DEBUG org.apache.hadoop.hbase.regionserver.HRegion:= Scanners disabled for region t1,,1228833363456 2008-12-09 06:37:47,094 DEBUG org.apache.hadoop.hbase.regionserver.HRegion:= No more active scanners for region t1,,1228833363456 2008-12-09 06:37:47,095 DEBUG org.apache.hadoop.hbase.regionserver.HRegion:= Updates disabled for region t1,,1228833363456 2008-12-09 06:37:47,095 DEBUG org.apache.hadoop.hbase.regionserver.HRegion:= No more row locks outstanding on region t1,,1228833363456 2008-12-09 06:37:47,095 DEBUG org.apache.hadoop.hbase.regionserver.HRegion:= Started memcache flush for region t1,,1228833363456. Current region memcac= he size 18.0 2008-12-09 06:37:47,095 INFO org.apache.hadoop.hbase.regionserver.Flusher: = regionserver/0:0:0:0:0:0:0:0:60020.cacheFlusher exiting 2008-12-09 06:37:47,096 INFO org.apache.hadoop.hbase.regionserver.LogRoller= : LogRoller exiting. 2008-12-09 06:37:47,096 INFO org.apache.hadoop.hbase.regionserver.CompactSp= litThread: regionserver/0:0:0:0:0:0:0:0:60020.compactor exiting 2008-12-09 06:37:47,099 ERROR org.apache.hadoop.hbase.regionserver.HRegionS= erver: error closing region t1,,1228833363456 org.apache.hadoop.hbase.DroppedSnapshotException: region: t1,,1228833363456 at org.apache.hadoop.hbase.regionserver.HRegion.internalFlushcache(HReg= ion.java:1071) at org.apache.hadoop.hbase.regionserver.HRegion.close(HRegion.java:619) at org.apache.hadoop.hbase.regionserver.HRegionServer.closeAllRegions(H= RegionServer.java:951) at org.apache.hadoop.hbase.regionserver.HRegionServer.run(HRegionServer= .java:459) at java.lang.Thread.run(Thread.java:619) Caused by: java.io.IOException: Filesystem closed at org.apache.hadoop.dfs.DFSClient.checkOpen(DFSClient.java:196) at org.apache.hadoop.dfs.DFSClient.getFileInfo(DFSClient.java:564) at org.apache.hadoop.dfs.DistributedFileSystem.getFileStatus(Distribute= dFileSystem.java:390) at org.apache.hadoop.fs.FileSystem.exists(FileSystem.java:667) at org.apache.hadoop.hbase.regionserver.HStoreFile.(HStoreFile.ja= va:152) at org.apache.hadoop.hbase.regionserver.HStore.internalFlushCache(HStor= e.java:599) at org.apache.hadoop.hbase.regionserver.HStore.flushCache(HStore.java:5= 77) at org.apache.hadoop.hbase.regionserver.HRegion.internalFlushcache(HReg= ion.java:1058) ... 4 more 2008-12-09 06:37:47,100 DEBUG org.apache.hadoop.hbase.regionserver.HLog: cl= osing log writer in hdfs://h1:54310/hbase/log_10.131.237.51_1228833326838_6= 0020 2008-12-09 06:37:47,101 ERROR org.apache.hadoop.hbase.regionserver.HRegionS= erver: Close and delete failed java.io.IOException: Filesystem closed at org.apache.hadoop.dfs.DFSClient.checkOpen(DFSClient.java:196) at org.apache.hadoop.dfs.DFSClient.access$600(DFSClient.java:59) at org.apache.hadoop.dfs.DFSClient$DFSOutputStream.closeInternal(DFSCli= ent.java:2689) at org.apache.hadoop.dfs.DFSClient$DFSOutputStream.close(DFSClient.java= :2655) at org.apache.hadoop.fs.FSDataOutputStream$PositionCache.close(FSDataOu= tputStream.java:59) at org.apache.hadoop.fs.FSDataOutputStream.close(FSDataOutputStream.jav= a:79) at org.apache.hadoop.io.SequenceFile$Writer.close(SequenceFile.java:962= ) at org.apache.hadoop.hbase.regionserver.HLog.close(HLog.java:349) at org.apache.hadoop.hbase.regionserver.HLog.closeAndDelete(HLog.java:3= 33) at org.apache.hadoop.hbase.regionserver.HRegionServer.run(HRegionServer= .java:461) at java.lang.Thread.run(Thread.java:619) 2008-12-09 06:37:47,102 INFO org.apache.hadoop.hbase.regionserver.HRegionSe= rver: telling master that region server is shutting down at: 10.131.237.51:= 60020 2008-12-09 06:37:47,104 INFO org.apache.hadoop.hbase.regionserver.HRegionSe= rver: stopping server at: 10.131.237.51:60020 2008-12-09 06:37:47,882 INFO org.apache.hadoop.hbase.Leases: regionserver/0= :0:0:0:0:0:0:0:60020.leaseChecker closing leases 2008-12-09 06:37:47,882 INFO org.apache.hadoop.hbase.Leases: regionserver/0= :0:0:0:0:0:0:0:60020.leaseChecker closed leases 2008-12-09 06:37:54,919 INFO org.apache.hadoop.hbase.regionserver.HRegionSe= rver: worker thread exiting 2008-12-09 06:37:54,920 INFO org.apache.hadoop.hbase.regionserver.HRegionSe= rver: regionserver/0:0:0:0:0:0:0:0:60020 exiting 2008-12-09 06:37:54,920 INFO org.apache.hadoop.hbase.regionserver.HRegionSe= rver: Shutdown thread complete Second HRegion Server: 2008-12-09 06:35:28,710 INFO org.apache.hadoop.hbase.regionserver.HRegionSe= rver: HRegionServer started at: 10.131.237.52:60020 2008-12-09 06:35:28,711 INFO org.apache.hadoop.ipc.Server: IPC Server handl= er 9 on 60020: starting 2008-12-09 06:37:49,965 INFO org.apache.hadoop.hbase.regionserver.HRegionSe= rver: MSG_REGION_OPEN: t1,,1228833363456 2008-12-09 06:37:49,966 INFO org.apache.hadoop.hbase.regionserver.HRegionSe= rver: MSG_REGION_OPEN: t1,,1228833363456 2008-12-09 06:37:50,055 DEBUG org.apache.hadoop.hbase.client.HConnectionMan= ager$TableServers: Found ROOT REGION =3D> {NAME =3D> '-ROOT-,,0', STARTKEY = =3D> '', ENDKEY =3D> '', ENCODED =3D> 70236052, TABLE =3D> {{NAME =3D> '-RO= OT-', IS_ROOT =3D> 'true', IS_META =3D> 'true', FAMILIES =3D> [{NAME =3D> '= info', BLOOMFILTER =3D> 'false', COMPRESSION =3D> 'NONE', VERSIONS =3D> '1'= , LENGTH =3D> '2147483647', TTL =3D> '-1', IN_MEMORY =3D> 'false', BLOCKCAC= HE =3D> 'false'}]}} 2008-12-09 06:37:50,069 DEBUG org.apache.hadoop.hbase.RegionHistorian: Onli= ned 2008-12-09 06:37:50,080 DEBUG org.apache.hadoop.hbase.regionserver.HRegion:= Opening region t1,,1228833363456/2133923429 2008-12-09 06:37:50,110 DEBUG org.apache.hadoop.hbase.regionserver.HRegion:= Next sequence id for region t1,,1228833363456 is 0 2008-12-09 06:37:50,112 INFO org.apache.hadoop.hbase.regionserver.HRegion: = region t1,,1228833363456/2133923429 available 2008-12-09 06:37:50,112 DEBUG org.apache.hadoop.hbase.regionserver.CompactS= plitThread: Compaction requested for region: t1,,1228833363456 2008-12-09 06:37:50,114 INFO org.apache.hadoop.hbase.regionserver.HRegion: = starting compaction on region t1,,1228833363456 2008-12-09 06:37:50,118 INFO org.apache.hadoop.hbase.regionserver.HRegion: = compaction completed on region t1,,1228833363456 in 0sec HMaster Server: java version "1.6.0_06" Java(TM) SE Runtime Environment (build 1.6.0_06-b02) Java HotSpot(TM) 64-Bit Server VM (build 10.0-b22, mixed mode) ulimit -n 32768 2008-12-09 06:35:24,944 INFO org.apache.hadoop.hbase.master.HMaster: Root r= egion dir: hdfs://h1:54310/hbase/-ROOT-/70236052 2008-12-09 06:35:25,109 INFO org.apache.hadoop.hbase.master.HMaster: BOOTST= RAP: creating ROOT and first META regions 2008-12-09 06:35:25,156 INFO org.apache.hadoop.hbase.regionserver.HLog: New= log writer created at /hbase/-ROOT-/70236052/log/hlog.dat.1228833325121 2008-12-09 06:35:25,160 DEBUG org.apache.hadoop.hbase.regionserver.HRegion:= Opening region -ROOT-,,0/70236052 2008-12-09 06:35:25,197 DEBUG org.apache.hadoop.hbase.regionserver.HRegion:= Next sequence id for region -ROOT-,,0 is 0 2008-12-09 06:35:25,200 INFO org.apache.hadoop.hbase.regionserver.HRegion: = region -ROOT-,,0/70236052 available 2008-12-09 06:35:25,219 INFO org.apache.hadoop.hbase.regionserver.HLog: New= log writer created at /hbase/.META./1028785192/log/hlog.dat.1228833325214 2008-12-09 06:35:25,220 DEBUG org.apache.hadoop.hbase.regionserver.HRegion:= Opening region .META.,,1/1028785192 2008-12-09 06:35:25,252 DEBUG org.apache.hadoop.hbase.regionserver.HRegion:= Next sequence id for region .META.,,1 is 0 2008-12-09 06:35:25,256 INFO org.apache.hadoop.hbase.regionserver.HRegion: = region .META.,,1/1028785192 available 2008-12-09 06:35:25,260 DEBUG org.apache.hadoop.hbase.regionserver.HRegion:= Compactions and cache flushes disabled for region -ROOT-,,0 2008-12-09 06:35:25,260 DEBUG org.apache.hadoop.hbase.regionserver.HRegion:= Scanners disabled for region -ROOT-,,0 2008-12-09 06:35:25,260 DEBUG org.apache.hadoop.hbase.regionserver.HRegion:= No more active scanners for region -ROOT-,,0 2008-12-09 06:35:25,260 DEBUG org.apache.hadoop.hbase.regionserver.HRegion:= Updates disabled for region -ROOT-,,0 2008-12-09 06:35:25,260 DEBUG org.apache.hadoop.hbase.regionserver.HRegion:= No more row locks outstanding on region -ROOT-,,0 2008-12-09 06:35:25,261 DEBUG org.apache.hadoop.hbase.regionserver.HRegion:= Started memcache flush for region -ROOT-,,0. Current region memcache size = 445.0 2008-12-09 06:35:25,297 INFO org.apache.hadoop.util.NativeCodeLoader: Loade= d the native-hadoop library 2008-12-09 06:35:25,299 INFO org.apache.hadoop.io.compress.zlib.ZlibFactory= : Successfully loaded & initialized native-zlib library 2008-12-09 06:35:25,301 INFO org.apache.hadoop.io.compress.CodecPool: Got b= rand-new compressor 2008-12-09 06:35:25,555 INFO org.apache.hadoop.io.compress.CodecPool: Got b= rand-new decompressor 2008-12-09 06:35:25,556 INFO org.apache.hadoop.io.compress.CodecPool: Got b= rand-new decompressor 2008-12-09 06:35:25,556 INFO org.apache.hadoop.io.compress.CodecPool: Got b= rand-new decompressor 2008-12-09 06:35:25,556 INFO org.apache.hadoop.io.compress.CodecPool: Got b= rand-new decompressor 2008-12-09 06:35:25,570 DEBUG org.apache.hadoop.hbase.regionserver.HStore: = Added /hbase/-ROOT-/70236052/info/mapfiles/2955877428110101962 with 1 entri= es, sequence id 1, data size 445.0, file size 569.0 2008-12-09 06:35:25,570 DEBUG org.apache.hadoop.hbase.regionserver.HRegion:= Finished memcache flush for region -ROOT-,,0 in 310ms, sequence id=3D1, co= mpaction requested=3Dfalse 2008-12-09 06:35:25,570 DEBUG org.apache.hadoop.hbase.regionserver.HStore: = closed 70236052/info 2008-12-09 06:35:25,570 INFO org.apache.hadoop.hbase.regionserver.HRegion: = closed -ROOT-,,0 2008-12-09 06:35:25,570 DEBUG org.apache.hadoop.hbase.regionserver.HLog: cl= osing log writer in hdfs://h1:54310/hbase/-ROOT-/70236052/log 2008-12-09 06:35:25,590 DEBUG org.apache.hadoop.hbase.regionserver.HRegion:= Compactions and cache flushes disabled for region .META.,,1 2008-12-09 06:35:25,591 DEBUG org.apache.hadoop.hbase.regionserver.HRegion:= Scanners disabled for region .META.,,1 2008-12-09 06:35:25,591 DEBUG org.apache.hadoop.hbase.regionserver.HRegion:= No more active scanners for region .META.,,1 2008-12-09 06:35:25,591 DEBUG org.apache.hadoop.hbase.regionserver.HRegion:= Updates disabled for region .META.,,1 2008-12-09 06:35:25,591 DEBUG org.apache.hadoop.hbase.regionserver.HRegion:= No more row locks outstanding on region .META.,,1 2008-12-09 06:35:25,591 DEBUG org.apache.hadoop.hbase.regionserver.HStore: = closed 1028785192/historian 2008-12-09 06:35:25,591 DEBUG org.apache.hadoop.hbase.regionserver.HStore: = closed 1028785192/info 2008-12-09 06:35:25,591 INFO org.apache.hadoop.hbase.regionserver.HRegion: = closed .META.,,1 2008-12-09 06:35:25,591 DEBUG org.apache.hadoop.hbase.regionserver.HLog: cl= osing log writer in hdfs://h1:54310/hbase/.META./1028785192/log 2008-12-09 06:35:25,917 INFO org.apache.hadoop.ipc.metrics.RpcMetrics: Init= ializing RPC Metrics with hostName=3DHMaster, port=3D60000 2008-12-09 06:35:26,088 INFO org.apache.hadoop.hbase.master.HMaster: HMaste= r initialized on 10.131.237.52:60000 2008-12-09 06:35:26,152 INFO org.mortbay.util.Credential: Checking Resource= aliases 2008-12-09 06:35:26,208 INFO org.mortbay.http.HttpServer: Version Jetty/5.1= .4 2008-12-09 06:35:26,209 INFO org.mortbay.util.Container: Started HttpContex= t[/static,/static] 2008-12-09 06:35:26,209 INFO org.mortbay.util.Container: Started HttpContex= t[/logs,/logs] 2008-12-09 06:35:27,051 INFO org.mortbay.util.Container: Started org.mortba= y.jetty.servlet.WebApplicationHandler@741827d1 2008-12-09 06:35:27,133 INFO org.mortbay.util.Container: Started WebApplica= tionContext[/,/] 2008-12-09 06:35:27,493 INFO org.mortbay.util.Container: Started org.mortba= y.jetty.servlet.WebApplicationHandler@25e222e 2008-12-09 06:35:27,495 INFO org.mortbay.util.Container: Started WebApplica= tionContext[/api,rest] 2008-12-09 06:35:27,498 INFO org.mortbay.http.SocketListener: Started Socke= tListener on 0.0.0.0:60010 2008-12-09 06:35:27,498 INFO org.mortbay.util.Container: Started org.mortba= y.jetty.Server@6632060c 2008-12-09 06:35:27,498 INFO org.apache.hadoop.ipc.Server: IPC Server Respo= nder: starting 2008-12-09 06:35:27,499 INFO org.apache.hadoop.ipc.Server: IPC Server liste= ner on 60000: starting 2008-12-09 06:35:27,501 INFO org.apache.hadoop.ipc.Server: IPC Server handl= er 0 on 60000: starting 2008-12-09 06:35:27,501 INFO org.apache.hadoop.ipc.Server: IPC Server handl= er 1 on 60000: starting 2008-12-09 06:35:27,501 INFO org.apache.hadoop.ipc.Server: IPC Server handl= er 2 on 60000: starting 2008-12-09 06:35:27,501 INFO org.apache.hadoop.ipc.Server: IPC Server handl= er 3 on 60000: starting 2008-12-09 06:35:27,501 INFO org.apache.hadoop.ipc.Server: IPC Server handl= er 4 on 60000: starting 2008-12-09 06:35:27,502 INFO org.apache.hadoop.ipc.Server: IPC Server handl= er 5 on 60000: starting 2008-12-09 06:35:27,505 INFO org.apache.hadoop.ipc.Server: IPC Server handl= er 6 on 60000: starting 2008-12-09 06:35:27,507 INFO org.apache.hadoop.ipc.Server: IPC Server handl= er 7 on 60000: starting 2008-12-09 06:35:27,522 INFO org.apache.hadoop.ipc.Server: IPC Server handl= er 9 on 60000: starting 2008-12-09 06:35:27,522 INFO org.apache.hadoop.ipc.Server: IPC Server handl= er 8 on 60000: starting 2008-12-09 06:35:27,523 DEBUG org.apache.hadoop.hbase.master.HMaster: Start= ed service threads 2008-12-09 06:35:27,529 INFO org.apache.hadoop.hbase.master.ServerManager: = Received start message from: 10.131.237.54:60020 2008-12-09 06:35:27,535 INFO org.apache.hadoop.hbase.master.ServerManager: = Received start message from: 10.131.237.51:60020 2008-12-09 06:35:27,538 INFO org.apache.hadoop.hbase.master.ServerManager: = Received start message from: 10.131.237.53:60020 2008-12-09 06:35:27,705 INFO org.apache.hadoop.hbase.master.ServerManager: = Received start message from: 10.131.237.52:60020 2008-12-09 06:35:28,648 INFO org.apache.hadoop.hbase.master.RegionManager: = assigning region -ROOT-,,0 to server 10.131.237.54:60020 2008-12-09 06:35:28,651 DEBUG org.apache.hadoop.hbase.master.ServerManager:= Total Load: 0, Num Servers: 4, Avg Load: 0.0 2008-12-09 06:35:31,673 INFO org.apache.hadoop.hbase.master.ServerManager: = Received MSG_REPORT_OPEN: -ROOT-,,0 from 10.131.237.54:60020 2008-12-09 06:35:31,675 INFO org.apache.hadoop.hbase.master.BaseScanner: Re= gionManager.rootScanner scanning meta region {regionname: -ROOT-,,0, startK= ey: <>, server: 10.131.237.54:60020} 2008-12-09 06:35:31,769 DEBUG org.apache.hadoop.hbase.master.BaseScanner: R= egionManager.rootScanner REGION =3D> {NAME =3D> '.META.,,1', STARTKEY =3D> = '', ENDKEY =3D> '', ENCODED =3D> 1028785192, TABLE =3D> {{NAME =3D> '.META.= ', IS_ROOT =3D> 'false', IS_META =3D> 'true', FAMILIES =3D> [{NAME =3D> 'in= fo', BLOOMFILTER =3D> 'false', VERSIONS =3D> '1', COMPRESSION =3D> 'NONE', = LENGTH =3D> '2147483647', TTL =3D> '-1', IN_MEMORY =3D> 'false', BLOCKCACHE= =3D> 'false'}, {NAME =3D> 'historian', BLOOMFILTER =3D> 'false', VERSIONS = =3D> '2147483647', COMPRESSION =3D> 'NONE', LENGTH =3D> '2147483647', TTL = =3D> '-1', IN_MEMORY =3D> 'false', BLOCKCACHE =3D> 'false'}]}}}, SERVER =3D= > '', STARTCODE =3D> 0 2008-12-09 06:35:31,769 DEBUG org.apache.hadoop.hbase.master.BaseScanner: C= urrent assignment of .META.,,1 is not valid: serverInfo: null, passed start= Code: 0, storedInfo.startCode: -1, unassignedRegions: false, pendingRegions= : false 2008-12-09 06:35:31,772 INFO org.apache.hadoop.hbase.master.BaseScanner: Re= gionManager.rootScanner scan of meta region {regionname: -ROOT-,,0, startKe= y: <>, server: 10.131.237.54:60020} complete 2008-12-09 06:35:34,661 INFO org.apache.hadoop.hbase.master.RegionManager: = assigning region .META.,,1 to server 10.131.237.53:60020 2008-12-09 06:35:36,721 DEBUG org.apache.hadoop.hbase.client.HConnectionMan= ager$TableServers: Found ROOT REGION =3D> {NAME =3D> '-ROOT-,,0', STARTKEY = =3D> '', ENDKEY =3D> '', ENCODED =3D> 70236052, TABLE =3D> {{NAME =3D> '-RO= OT-', IS_ROOT =3D> 'true', IS_META =3D> 'true', FAMILIES =3D> [{NAME =3D> '= info', BLOOMFILTER =3D> 'false', COMPRESSION =3D> 'NONE', VERSIONS =3D> '1'= , LENGTH =3D> '2147483647', TTL =3D> '-1', IN_MEMORY =3D> 'false', BLOCKCAC= HE =3D> 'false'}]}} 2008-12-09 06:35:36,730 DEBUG org.apache.hadoop.hbase.client.HConnectionMan= ager$TableServers: Attempt 0 of 10 failed with . Retrying after sleep of 2000 2008-12-09 06:35:36,734 DEBUG org.apache.hadoop.hbase.client.HConnectionMan= ager$TableServers: Found ROOT REGION =3D> {NAME =3D> '-ROOT-,,0', STARTKEY = =3D> '', ENDKEY =3D> '', ENCODED =3D> 70236052, TABLE =3D> {{NAME =3D> '-RO= OT-', IS_ROOT =3D> 'true', IS_META =3D> 'true', FAMILIES =3D> [{NAME =3D> '= info', BLOOMFILTER =3D> 'false', COMPRESSION =3D> 'NONE', VERSIONS =3D> '1'= , LENGTH =3D> '2147483647', TTL =3D> '-1', IN_MEMORY =3D> 'false', BLOCKCAC= HE =3D> 'false'}]}} 2008-12-09 06:35:37,685 INFO org.apache.hadoop.hbase.master.ServerManager: = Received MSG_REPORT_PROCESS_OPEN: .META.,,1 from 10.131.237.53:60020 2008-12-09 06:35:37,685 INFO org.apache.hadoop.hbase.master.ServerManager: = Received MSG_REPORT_OPEN: .META.,,1 from 10.131.237.53:60020 2008-12-09 06:35:37,689 DEBUG org.apache.hadoop.hbase.master.HMaster: Main = processing loop: PendingOpenOperation from 10.131.237.53:60020 2008-12-09 06:35:37,691 INFO org.apache.hadoop.hbase.master.ProcessRegionOp= en$1: .META.,,1 open on 10.131.237.53:60020 2008-12-09 06:35:37,691 INFO org.apache.hadoop.hbase.master.ProcessRegionOp= en$1: updating row .META.,,1 in region -ROOT-,,0 with startcode 12288333268= 70 and server 10.131.237.53:60020 2008-12-09 06:35:38,744 DEBUG org.apache.hadoop.hbase.client.HConnectionMan= ager$TableServers: Found ROOT REGION =3D> {NAME =3D> '-ROOT-,,0', STARTKEY = =3D> '', ENDKEY =3D> '', ENCODED =3D> 70236052, TABLE =3D> {{NAME =3D> '-RO= OT-', IS_ROOT =3D> 'true', IS_META =3D> 'true', FAMILIES =3D> [{NAME =3D> '= info', BLOOMFILTER =3D> 'false', COMPRESSION =3D> 'NONE', VERSIONS =3D> '1'= , LENGTH =3D> '2147483647', TTL =3D> '-1', IN_MEMORY =3D> 'false', BLOCKCAC= HE =3D> 'false'}]}} 2008-12-09 06:35:38,754 DEBUG org.apache.hadoop.hbase.client.HConnectionMan= ager$TableServers: Cache hit in table locations for row <> and tableName .M= ETA.: location server 10.131.237.53:60020, location region name .META.,,1 2008-12-09 06:35:38,754 DEBUG org.apache.hadoop.hbase.RegionHistorian: Onli= ned 2008-12-09 06:35:38,755 DEBUG org.apache.hadoop.hbase.client.HConnectionMan= ager$TableServers: Cache hit in table locations for row <> and tableName .M= ETA.: location server 10.131.237.53:60020, location region name .META.,,1 2008-12-09 06:35:38,755 DEBUG org.apache.hadoop.hbase.master.ProcessRegionO= pen$1: Adding to onlineMetaRegions: {regionname: .META.,,1, startKey: <>, s= erver: 10.131.237.53:60020} 2008-12-09 06:35:38,758 INFO org.apache.hadoop.hbase.master.BaseScanner: Re= gionManager.metaScanner scanning meta region {regionname: .META.,,1, startK= ey: <>, server: 10.131.237.53:60020} 2008-12-09 06:35:38,831 INFO org.apache.hadoop.hbase.master.BaseScanner: Re= gionManager.metaScanner scan of meta region {regionname: .META.,,1, startKe= y: <>, server: 10.131.237.53:60020} complete 2008-12-09 06:35:38,831 INFO org.apache.hadoop.hbase.master.BaseScanner: al= l meta regions scanned 2008-12-09 06:35:38,931 DEBUG org.apache.hadoop.hbase.client.HConnectionMan= ager$TableServers: Cache hit in table locations for row <> and tableName .M= ETA.: location server 10.131.237.53:60020, location region name .META.,,1 2008-12-09 06:35:39,697 DEBUG org.apache.hadoop.hbase.client.HConnectionMan= ager$TableServers: Cache hit in table locations for row <> and tableName .M= ETA.: location server 10.131.237.53:60020, location region name .META.,,1 2008-12-09 06:35:40,435 DEBUG org.apache.hadoop.hbase.client.HConnectionMan= ager$TableServers: Cache hit in table locations for row <> and tableName .M= ETA.: location server 10.131.237.53:60020, location region name .META.,,1 2008-12-09 06:35:41,223 DEBUG org.apache.hadoop.hbase.client.HConnectionMan= ager$TableServers: Cache hit in table locations for row <> and tableName .M= ETA.: location server 10.131.237.53:60020, location region name .META.,,1 2008-12-09 06:35:43,673 DEBUG org.apache.hadoop.hbase.master.ServerManager:= Total Load: 2, Num Servers: 4, Avg Load: 1.0 2008-12-09 06:35:58,697 DEBUG org.apache.hadoop.hbase.master.ServerManager:= Total Load: 2, Num Servers: 4, Avg Load: 1.0 2008-12-09 06:36:03,477 INFO org.apache.hadoop.hbase.regionserver.HLog: New= log writer created at /hbase/t1/2133923429/log/hlog.dat.1228833363473 2008-12-09 06:36:03,478 DEBUG org.apache.hadoop.hbase.regionserver.HRegion:= Opening region t1,,1228833363456/2133923429 2008-12-09 06:36:03,489 DEBUG org.apache.hadoop.hbase.regionserver.HRegion:= Next sequence id for region t1,,1228833363456 is 0 2008-12-09 06:36:03,491 INFO org.apache.hadoop.hbase.regionserver.HRegion: = region t1,,1228833363456/2133923429 available 2008-12-09 06:36:03,494 DEBUG org.apache.hadoop.hbase.regionserver.HRegion:= Compactions and cache flushes disabled for region t1,,1228833363456 2008-12-09 06:36:03,494 DEBUG org.apache.hadoop.hbase.regionserver.HRegion:= Scanners disabled for region t1,,1228833363456 2008-12-09 06:36:03,494 DEBUG org.apache.hadoop.hbase.regionserver.HRegion:= No more active scanners for region t1,,1228833363456 2008-12-09 06:36:03,494 DEBUG org.apache.hadoop.hbase.regionserver.HRegion:= Updates disabled for region t1,,1228833363456 2008-12-09 06:36:03,494 DEBUG org.apache.hadoop.hbase.regionserver.HRegion:= No more row locks outstanding on region t1,,1228833363456 2008-12-09 06:36:03,494 DEBUG org.apache.hadoop.hbase.regionserver.HStore: = closed 2133923429/f1 2008-12-09 06:36:03,495 INFO org.apache.hadoop.hbase.regionserver.HRegion: = closed t1,,1228833363456 2008-12-09 06:36:03,495 DEBUG org.apache.hadoop.hbase.regionserver.HLog: cl= osing log writer in hdfs://h1:54310/hbase/t1/2133923429/log 2008-12-09 06:36:03,521 INFO org.apache.hadoop.hbase.master.HMaster: create= d table t1 2008-12-09 06:36:04,705 INFO org.apache.hadoop.hbase.master.RegionManager: = assigning region t1,,1228833363456 to server 10.131.237.51:60020 2008-12-09 06:36:07,726 INFO org.apache.hadoop.hbase.master.ServerManager: = Received MSG_REPORT_OPEN: t1,,1228833363456 from 10.131.237.51:60020 2008-12-09 06:36:07,727 DEBUG org.apache.hadoop.hbase.master.HMaster: Main = processing loop: PendingOpenOperation from 10.131.237.51:60020 2008-12-09 06:36:07,727 INFO org.apache.hadoop.hbase.master.ProcessRegionOp= en$1: t1,,1228833363456 open on 10.131.237.51:60020 2008-12-09 06:36:07,727 DEBUG org.apache.hadoop.hbase.master.RegionServerOp= eration: numberOfMetaRegions: 1, onlineMetaRegions.size(): 1 2008-12-09 06:36:07,727 INFO org.apache.hadoop.hbase.master.ProcessRegionOp= en$1: updating row t1,,1228833363456 in region .META.,,1 with startcode 122= 8833326838 and server 10.131.237.51:60020 2008-12-09 06:36:11,335 DEBUG org.apache.hadoop.hbase.client.HConnectionMan= ager$TableServers: Cache hit in table locations for row <> and tableName .M= ETA.: location server 10.131.237.53:60020, location region name .META.,,1 2008-12-09 06:36:13,735 DEBUG org.apache.hadoop.hbase.master.ServerManager:= Total Load: 3, Num Servers: 4, Avg Load: 1.0 2008-12-09 06:36:24,695 DEBUG org.apache.hadoop.hbase.client.HConnectionMan= ager$TableServers: Cache hit in table locations for row <> and tableName .M= ETA.: location server 10.131.237.53:60020, location region name .META.,,1 2008-12-09 06:36:28,756 DEBUG org.apache.hadoop.hbase.master.ServerManager:= Total Load: 3, Num Servers: 4, Avg Load: 1.0 2008-12-09 06:36:31,782 INFO org.apache.hadoop.hbase.master.BaseScanner: Re= gionManager.rootScanner scanning meta region {regionname: -ROOT-,,0, startK= ey: <>, server: 10.131.237.54:60020} 2008-12-09 06:36:31,815 DEBUG org.apache.hadoop.hbase.master.BaseScanner: R= egionManager.rootScanner REGION =3D> {NAME =3D> '.META.,,1', STARTKEY =3D> = '', ENDKEY =3D> '', ENCODED =3D> 1028785192, TABLE =3D> {{NAME =3D> '.META.= ', IS_ROOT =3D> 'false', IS_META =3D> 'true', FAMILIES =3D> [{NAME =3D> 'in= fo', BLOOMFILTER =3D> 'false', VERSIONS =3D> '1', COMPRESSION =3D> 'NONE', = LENGTH =3D> '2147483647', TTL =3D> '-1', IN_MEMORY =3D> 'false', BLOCKCACHE= =3D> 'false'}, {NAME =3D> 'historian', BLOOMFILTER =3D> 'false', VERSIONS = =3D> '2147483647', COMPRESSION =3D> 'NONE', LENGTH =3D> '2147483647', TTL = =3D> '-1', IN_MEMORY =3D> 'false', BLOCKCACHE =3D> 'false'}]}}}, SERVER =3D= > '10.131.237.53:60020', STARTCODE =3D> 1228833326870 2008-12-09 06:36:31,817 INFO org.apache.hadoop.hbase.master.BaseScanner: Re= gionManager.rootScanner scan of meta region {regionname: -ROOT-,,0, startKe= y: <>, server: 10.131.237.54:60020} complete 2008-12-09 06:36:38,766 INFO org.apache.hadoop.hbase.master.BaseScanner: Re= gionManager.metaScanner scanning meta region {regionname: .META.,,1, startK= ey: <>, server: 10.131.237.53:60020} 2008-12-09 06:36:38,773 DEBUG org.apache.hadoop.hbase.master.BaseScanner: R= egionManager.metaScanner REGION =3D> {NAME =3D> 't1,,1228833363456', STARTK= EY =3D> '', ENDKEY =3D> '', ENCODED =3D> 2133923429, TABLE =3D> {{NAME =3D>= 't1', IS_ROOT =3D> 'false', IS_META =3D> 'false', FAMILIES =3D> [{NAME =3D= > 'f1', BLOOMFILTER =3D> 'false', COMPRESSION =3D> 'NONE', VERSIONS =3D> '3= ', LENGTH =3D> '2147483647', TTL =3D> '-1', IN_MEMORY =3D> 'false', BLOCKCA= CHE =3D> 'false'}]}}}, SERVER =3D> '10.131.237.51:60020', STARTCODE =3D> 12= 28833326838 2008-12-09 06:36:38,775 INFO org.apache.hadoop.hbase.master.BaseScanner: Re= gionManager.metaScanner scan of meta region {regionname: .META.,,1, startKe= y: <>, server: 10.131.237.53:60020} complete 2008-12-09 06:36:38,775 INFO org.apache.hadoop.hbase.master.BaseScanner: al= l meta regions scanned 2008-12-09 06:36:43,777 DEBUG org.apache.hadoop.hbase.master.ServerManager:= Total Load: 3, Num Servers: 4, Avg Load: 1.0 2008-12-09 06:36:56,635 DEBUG org.apache.hadoop.hbase.client.HConnectionMan= ager$TableServers: Cache hit in table locations for row <> and tableName t1= : location server 10.131.237.51:60020, location region name t1,,12288333634= 56 2008-12-09 06:36:58,801 DEBUG org.apache.hadoop.hbase.master.ServerManager:= Total Load: 3, Num Servers: 4, Avg Load: 1.0 2008-12-09 06:37:13,820 DEBUG org.apache.hadoop.hbase.master.ServerManager:= Total Load: 3, Num Servers: 4, Avg Load: 1.0 2008-12-09 06:37:26,769 DEBUG org.apache.hadoop.hbase.client.HConnectionMan= ager$TableServers: Cache hit in table locations for row <> and tableName t1= : location server 10.131.237.51:60020, location region name t1,,12288333634= 56 2008-12-09 06:37:28,841 DEBUG org.apache.hadoop.hbase.master.ServerManager:= Total Load: 3, Num Servers: 4, Avg Load: 1.0 2008-12-09 06:37:31,792 INFO org.apache.hadoop.hbase.master.BaseScanner: Re= gionManager.rootScanner scanning meta region {regionname: -ROOT-,,0, startK= ey: <>, server: 10.131.237.54:60020} 2008-12-09 06:37:31,835 DEBUG org.apache.hadoop.hbase.master.BaseScanner: R= egionManager.rootScanner REGION =3D> {NAME =3D> '.META.,,1', STARTKEY =3D> = '', ENDKEY =3D> '', ENCODED =3D> 1028785192, TABLE =3D> {{NAME =3D> '.META.= ', IS_ROOT =3D> 'false', IS_META =3D> 'true', FAMILIES =3D> [{NAME =3D> 'in= fo', BLOOMFILTER =3D> 'false', VERSIONS =3D> '1', COMPRESSION =3D> 'NONE', = LENGTH =3D> '2147483647', TTL =3D> '-1', IN_MEMORY =3D> 'false', BLOCKCACHE= =3D> 'false'}, {NAME =3D> 'historian', BLOOMFILTER =3D> 'false', VERSIONS = =3D> '2147483647', COMPRESSION =3D> 'NONE', LENGTH =3D> '2147483647', TTL = =3D> '-1', IN_MEMORY =3D> 'false', BLOCKCACHE =3D> 'false'}]}}}, SERVER =3D= > '10.131.237.53:60020', STARTCODE =3D> 1228833326870 2008-12-09 06:37:31,837 INFO org.apache.hadoop.hbase.master.BaseScanner: Re= gionManager.rootScanner scan of meta region {regionname: -ROOT-,,0, startKe= y: <>, server: 10.131.237.54:60020} complete 2008-12-09 06:37:38,776 INFO org.apache.hadoop.hbase.master.BaseScanner: Re= gionManager.metaScanner scanning meta region {regionname: .META.,,1, startK= ey: <>, server: 10.131.237.53:60020} 2008-12-09 06:37:38,786 DEBUG org.apache.hadoop.hbase.master.BaseScanner: R= egionManager.metaScanner REGION =3D> {NAME =3D> 't1,,1228833363456', STARTK= EY =3D> '', ENDKEY =3D> '', ENCODED =3D> 2133923429, TABLE =3D> {{NAME =3D>= 't1', IS_ROOT =3D> 'false', IS_META =3D> 'false', FAMILIES =3D> [{NAME =3D= > 'f1', BLOOMFILTER =3D> 'false', COMPRESSION =3D> 'NONE', VERSIONS =3D> '3= ', LENGTH =3D> '2147483647', TTL =3D> '-1', IN_MEMORY =3D> 'false', BLOCKCA= CHE =3D> 'false'}]}}}, SERVER =3D> '10.131.237.51:60020', STARTCODE =3D> 12= 28833326838 2008-12-09 06:37:38,789 INFO org.apache.hadoop.hbase.master.BaseScanner: Re= gionManager.metaScanner scan of meta region {regionname: .META.,,1, startKe= y: <>, server: 10.131.237.53:60020} complete 2008-12-09 06:37:38,789 INFO org.apache.hadoop.hbase.master.BaseScanner: al= l meta regions scanned 2008-12-09 06:37:43,860 DEBUG org.apache.hadoop.hbase.master.ServerManager:= Total Load: 3, Num Servers: 4, Avg Load: 1.0 2008-12-09 06:37:47,095 INFO org.apache.hadoop.hbase.master.ServerManager: = Cancelling lease for 10.131.237.51:60020 2008-12-09 06:37:47,095 INFO org.apache.hadoop.hbase.master.ServerManager: = Region server 10.131.237.51:60020: MSG_REPORT_EXITING -- lease cancelled 2008-12-09 06:37:47,096 INFO org.apache.hadoop.hbase.master.ServerManager: = Processing MSG_REPORT_CLOSE: t1,,1228833363456 from 10.131.237.51:60020 2008-12-09 06:37:49,949 INFO org.apache.hadoop.hbase.master.RegionManager: = assigning region t1,,1228833363456 to server 10.131.237.52:60020 2008-12-09 06:37:52,974 INFO org.apache.hadoop.hbase.master.ServerManager: = Received MSG_REPORT_PROCESS_OPEN: t1,,1228833363456 from 10.131.237.52:6002= 0 2008-12-09 06:37:52,974 INFO org.apache.hadoop.hbase.master.ServerManager: = Received MSG_REPORT_OPEN: t1,,1228833363456 from 10.131.237.52:60020 2008-12-09 06:37:52,975 DEBUG org.apache.hadoop.hbase.master.HMaster: Main = processing loop: PendingOpenOperation from 10.131.237.52:60020 2008-12-09 06:37:52,975 INFO org.apache.hadoop.hbase.master.ProcessRegionOp= en$1: t1,,1228833363456 open on 10.131.237.52:60020 2008-12-09 06:37:52,975 DEBUG org.apache.hadoop.hbase.master.RegionServerOp= eration: numberOfMetaRegions: 1, onlineMetaRegions.size(): 1 2008-12-09 06:37:52,975 INFO org.apache.hadoop.hbase.master.ProcessRegionOp= en$1: updating row t1,,1228833363456 in region .META.,,1 with startcode 122= 8833327601 and server 10.131.237.52:60020 2008-12-09 06:37:56,912 DEBUG org.apache.hadoop.hbase.client.HConnectionMan= ager$TableServers: Cache hit in table locations for row <> and tableName t1= : location server 10.131.237.51:60020, location region name t1,,12288333634= 56 2008-12-09 06:37:58,877 DEBUG org.apache.hadoop.hbase.master.ServerManager:= Total Load: 3, Num Servers: 3, Avg Load: 1.0 2008-12-09 06:38:13,894 DEBUG org.apache.hadoop.hbase.master.ServerManager:= Total Load: 3, Num Servers: 3, Avg Load: 1.0 2008-12-09 06:38:27,035 DEBUG org.apache.hadoop.hbase.client.HConnectionMan= ager$TableServers: Cache hit in table locations for row <> and tableName t1= : location server 10.131.237.51:60020, location region name t1,,12288333634= 56 2008-12-09 06:38:28,914 DEBUG org.apache.hadoop.hbase.master.ServerManager:= Total Load: 3, Num Servers: 3, Avg Load: 1.0 2008-12-09 06:38:31,802 INFO org.apache.hadoop.hbase.master.BaseScanner: Re= gionManager.rootScanner scanning meta region {regionname: -ROOT-,,0, startK= ey: <>, server: 10.131.237.54:60020} 2008-12-09 06:38:31,833 DEBUG org.apache.hadoop.hbase.master.BaseScanner: R= egionManager.rootScanner REGION =3D> {NAME =3D> '.META.,,1', STARTKEY =3D> = '', ENDKEY =3D> '', ENCODED =3D> 1028785192, TABLE =3D> {{NAME =3D> '.META.= ', IS_ROOT =3D> 'false', IS_META =3D> 'true', FAMILIES =3D> [{NAME =3D> 'in= fo', BLOOMFILTER =3D> 'false', VERSIONS =3D> '1', COMPRESSION =3D> 'NONE', = LENGTH =3D> '2147483647', TTL =3D> '-1', IN_MEMORY =3D> 'false', BLOCKCACHE= =3D> 'false'}, {NAME =3D> 'historian', BLOOMFILTER =3D> 'false', VERSIONS = =3D> '2147483647', COMPRESSION =3D> 'NONE', LENGTH =3D> '2147483647', TTL = =3D> '-1', IN_MEMORY =3D> 'false', BLOCKCACHE =3D> 'false'}]}}}, SERVER =3D= > '10.131.237.53:60020', STARTCODE =3D> 1228833326870 2008-12-09 06:38:31,835 INFO org.apache.hadoop.hbase.master.BaseScanner: Re= gionManager.rootScanner scan of meta region {regionname: -ROOT-,,0, startKe= y: <>, server: 10.131.237.54:60020} complete 2008-12-09 06:38:38,787 INFO org.apache.hadoop.hbase.master.BaseScanner: Re= gionManager.metaScanner scanning meta region {regionname: .META.,,1, startK= ey: <>, server: 10.131.237.53:60020} 2008-12-09 06:38:38,792 DEBUG org.apache.hadoop.hbase.master.BaseScanner: R= egionManager.metaScanner REGION =3D> {NAME =3D> 't1,,1228833363456', STARTK= EY =3D> '', ENDKEY =3D> '', ENCODED =3D> 2133923429, TABLE =3D> {{NAME =3D>= 't1', IS_ROOT =3D> 'false', IS_META =3D> 'false', FAMILIES =3D> [{NAME =3D= > 'f1', BLOOMFILTER =3D> 'false', COMPRESSION =3D> 'NONE', VERSIONS =3D> '3= ', LENGTH =3D> '2147483647', TTL =3D> '-1', IN_MEMORY =3D> 'false', BLOCKCA= CHE =3D> 'false'}]}}}, SERVER =3D> '10.131.237.52:60020', STARTCODE =3D> 12= 28833327601 2008-12-09 06:38:38,794 INFO org.apache.hadoop.hbase.master.BaseScanner: Re= gionManager.metaScanner scan of meta region {regionname: .META.,,1, startKe= y: <>, server: 10.131.237.53:60020} complete 2008-12-09 06:38:38,794 INFO org.apache.hadoop.hbase.master.BaseScanner: al= l meta regions scanned 2008-12-09 06:38:43,930 DEBUG org.apache.hadoop.hbase.master.ServerManager:= Total Load: 3, Num Servers: 3, Avg Load: 1.0 2008-12-09 06:38:57,168 DEBUG org.apache.hadoop.hbase.client.HConnectionMan= ager$TableServers: Cache hit in table locations for row <> and tableName t1= : location server 10.131.237.51:60020, location region name t1,,12288333634= 56 2008-12-09 06:38:58,950 DEBUG org.apache.hadoop.hbase.master.ServerManager:= Total Load: 3, Num Servers: 3, Avg Load: 1.0 2008-12-09 06:39:13,970 DEBUG org.apache.hadoop.hbase.master.ServerManager:= Total Load: 3, Num Servers: 3, Avg Load: 1.0 2008-12-09 06:39:27,310 DEBUG org.apache.hadoop.hbase.client.HConnectionMan= ager$TableServers: Cache hit in table locations for row <> and tableName t1= : location server 10.131.237.51:60020, location region name t1,,12288333634= 56 2008-12-09 06:39:28,996 DEBUG org.apache.hadoop.hbase.master.ServerManager:= Total Load: 3, Num Servers: 3, Avg Load: 1.0 2008-12-09 06:39:31,813 INFO org.apache.hadoop.hbase.master.BaseScanner: Re= gionManager.rootScanner scanning meta region {regionname: -ROOT-,,0, startK= ey: <>, server: 10.131.237.54:60020} 2008-12-09 06:39:31,844 DEBUG org.apache.hadoop.hbase.master.BaseScanner: R= egionManager.rootScanner REGION =3D> {NAME =3D> '.META.,,1', STARTKEY =3D> = '', ENDKEY =3D> '', ENCODED =3D> 1028785192, TABLE =3D> {{NAME =3D> '.META.= ', IS_ROOT =3D> 'false', IS_META =3D> 'true', FAMILIES =3D> [{NAME =3D> 'in= fo', BLOOMFILTER =3D> 'false', VERSIONS =3D> '1', COMPRESSION =3D> 'NONE', = LENGTH =3D> '2147483647', TTL =3D> '-1', IN_MEMORY =3D> 'false', BLOCKCACHE= =3D> 'false'}, {NAME =3D> 'historian', BLOOMFILTER =3D> 'false', VERSIONS = =3D> '2147483647', COMPRESSION =3D> 'NONE', LENGTH =3D> '2147483647', TTL = =3D> '-1', IN_MEMORY =3D> 'false', BLOCKCACHE =3D> 'false'}]}}}, SERVER =3D= > '10.131.237.53:60020', STARTCODE =3D> 1228833326870 2008-12-09 06:39:31,846 INFO org.apache.hadoop.hbase.master.BaseScanner: Re= gionManager.rootScanner scan of meta region {regionname: -ROOT-,,0, startKe= y: <>, server: 10.131.237.54:60020} complete 2008-12-09 06:39:38,797 INFO org.apache.hadoop.hbase.master.BaseScanner: Re= gionManager.metaScanner scanning meta region {regionname: .META.,,1, startK= ey: <>, server: 10.131.237.53:60020} 2008-12-09 06:39:38,806 DEBUG org.apache.hadoop.hbase.master.BaseScanner: R= egionManager.metaScanner REGION =3D> {NAME =3D> 't1,,1228833363456', STARTK= EY =3D> '', ENDKEY =3D> '', ENCODED =3D> 2133923429, TABLE =3D> {{NAME =3D>= 't1', IS_ROOT =3D> 'false', IS_META =3D> 'false', FAMILIES =3D> [{NAME =3D= > 'f1', BLOOMFILTER =3D> 'false', COMPRESSION =3D> 'NONE', VERSIONS =3D> '3= ', LENGTH =3D> '2147483647', TTL =3D> '-1', IN_MEMORY =3D> 'false', BLOCKCA= CHE =3D> 'false'}]}}}, SERVER =3D> '10.131.237.52:60020', STARTCODE =3D> 12= 28833327601 2008-12-09 06:39:38,808 INFO org.apache.hadoop.hbase.master.BaseScanner: Re= gionManager.metaScanner scan of meta region {regionname: .META.,,1, startKe= y: <>, server: 10.131.237.53:60020} complete 2008-12-09 06:39:38,808 INFO org.apache.hadoop.hbase.master.BaseScanner: al= l meta regions scanned 2008-12-09 06:39:44,016 DEBUG org.apache.hadoop.hbase.master.ServerManager:= Total Load: 3, Num Servers: 3, Avg Load: 1.0 2008-12-09 06:39:57,462 DEBUG org.apache.hadoop.hbase.client.HConnectionMan= ager$TableServers: Cache hit in table locations for row <> and tableName t1= : location server 10.131.237.51:60020, location region name t1,,12288333634= 56 2008-12-09 06:39:58,440 DEBUG org.apache.hadoop.hbase.client.HConnectionMan= ager$TableServers: Cache hit in table locations for row <> and tableName t1= : location server 10.131.237.51:60020, location region name t1,,12288333634= 56 2008-12-09 06:39:59,036 DEBUG org.apache.hadoop.hbase.master.ServerManager:= Total Load: 3, Num Servers: 3, Avg Load: 1.0 2008-12-09 06:40:14,056 DEBUG org.apache.hadoop.hbase.master.ServerManager:= Total Load: 3, Num Servers: 3, Avg Load: 1.0 2008-12-09 06:40:28,547 DEBUG org.apache.hadoop.hbase.client.HConnectionMan= ager$TableServers: Cache hit in table locations for row <> and tableName t1= : location server 10.131.237.51:60020, location region name t1,,12288333634= 56 2008-12-09 06:40:29,075 DEBUG org.apache.hadoop.hbase.master.ServerManager:= Total Load: 3, Num Servers: 3, Avg Load: 1.0 2008-12-09 06:40:31,823 INFO org.apache.hadoop.hbase.master.BaseScanner: Re= gionManager.rootScanner scanning meta region {regionname: -ROOT-,,0, startK= ey: <>, server: 10.131.237.54:60020} 2008-12-09 06:40:31,849 DEBUG org.apache.hadoop.hbase.master.BaseScanner: R= egionManager.rootScanner REGION =3D> {NAME =3D> '.META.,,1', STARTKEY =3D> = '', ENDKEY =3D> '', ENCODED =3D> 1028785192, TABLE =3D> {{NAME =3D> '.META.= ', IS_ROOT =3D> 'false', IS_META =3D> 'true', FAMILIES =3D> [{NAME =3D> 'in= fo', BLOOMFILTER =3D> 'false', VERSIONS =3D> '1', COMPRESSION =3D> 'NONE', = LENGTH =3D> '2147483647', TTL =3D> '-1', IN_MEMORY =3D> 'false', BLOCKCACHE= =3D> 'false'}, {NAME =3D> 'historian', BLOOMFILTER =3D> 'false', VERSIONS = =3D> '2147483647', COMPRESSION =3D> 'NONE', LENGTH =3D> '2147483647', TTL = =3D> '-1', IN_MEMORY =3D> 'false', BLOCKCACHE =3D> 'false'}]}}}, SERVER =3D= > '10.131.237.53:60020', STARTCODE =3D> 1228833326870 2008-12-09 06:40:31,851 INFO org.apache.hadoop.hbase.master.BaseScanner: Re= gionManager.rootScanner scan of meta region {regionname: -ROOT-,,0, startKe= y: <>, server: 10.131.237.54:60020} complete 2008-12-09 06:40:38,808 INFO org.apache.hadoop.hbase.master.BaseScanner: Re= gionManager.metaScanner scanning meta region {regionname: .META.,,1, startK= ey: <>, server: 10.131.237.53:60020} 2008-12-09 06:40:38,812 DEBUG org.apache.hadoop.hbase.master.BaseScanner: R= egionManager.metaScanner REGION =3D> {NAME =3D> 't1,,1228833363456', STARTK= EY =3D> '', ENDKEY =3D> '', ENCODED =3D> 2133923429, TABLE =3D> {{NAME =3D>= 't1', IS_ROOT =3D> 'false', IS_META =3D> 'false', FAMILIES =3D> [{NAME =3D= > 'f1', BLOOMFILTER =3D> 'false', COMPRESSION =3D> 'NONE', VERSIONS =3D> '3= ', LENGTH =3D> '2147483647', TTL =3D> '-1', IN_MEMORY =3D> 'false', BLOCKCA= CHE =3D> 'false'}]}}}, SERVER =3D> '10.131.237.52:60020', STARTCODE =3D> 12= 28833327601 2008-12-09 06:40:38,814 INFO org.apache.hadoop.hbase.master.BaseScanner: Re= gionManager.metaScanner scan of meta region {regionname: .META.,,1, startKe= y: <>, server: 10.131.237.53:60020} complete 2008-12-09 06:40:38,814 INFO org.apache.hadoop.hbase.master.BaseScanner: al= l meta regions scanned 2008-12-09 06:40:44,096 DEBUG org.apache.hadoop.hbase.master.ServerManager:= Total Load: 3, Num Servers: 3, Avg Load: 1.0 2008-12-09 06:40:58,661 DEBUG org.apache.hadoop.hbase.client.HConnectionMan= ager$TableServers: Cache hit in table locations for row <> and tableName t1= : location server 10.131.237.51:60020, location region name t1,,12288333634= 56 2008-12-09 06:40:59,115 DEBUG org.apache.hadoop.hbase.master.ServerManager:= Total Load: 3, Num Servers: 3, Avg Load: 1.0