You are viewing a plain text version of this content. The canonical link for it is here.
Posted to user@hbase.apache.org by Ronen Itkin <ro...@taykey.com> on 2011/10/16 14:32:00 UTC
HBase Rest & Zookeeper issue
Hey all!
At first it my seem like a Zookeeper issue, but the thing is that it is very
HBase related so I figured to send it to this mailing list as well.
I am currently using Zookeeper 3.3.3-cdh3u1, installed as a distributed
cluster with 3 nodes.
Though I have installed Zookeeper separately, its only purpose right now is
to serve HBase clients (hbase-0.90.3-cdh3u1).
Seems like everything is working great for a day or two and then out the
blue, Zookeeper refuses to serve clients requests,
alerting for the wide known issue of exceeding the defined maximum
connections allowed for a client.
I changed this value to 500 and it seems that it just held on for more time
and finally reached the threshold of 500 and then stopped working.
So, I set it to 1000 and right now I am waiting to see what will happen.
Meanwhile, by auditing the Zookeeper connections manually it seems like they
keep growing in a slow - promising pace towards the threshold of 1000
connections.
I have tried to analyze the connections and it looks like almost all of the
connections were established from the HBase Rest service towards zookeeper.
Can someone think of a reason why it keep growing? Does someone has any
other suggestions regarding this issue?
Are there any known issues regarding this situation, combining Rest and
Zookeeper?
If it helps, this is my environment design:
- Server 1 - Hadoop NameNode, JobTracker, *Hbase Master (Including Rest)*,
*Zookeeper01*
- Server 2 - Hadoop SecondaryMaster, HBase *Backup Master (Including
Rest)*, *Zookeeper02*
- Server 3 - *Zookeeper03*
- Servers 4-6 - Hadoop DataNode,TaskTracker, *HBase Region Server.*
The type of operations I am committing on HBase using Zookeeper are:
- Simple read/writes/updates using SCAN / MapReduce / Cascading ..
- Queries of the *Rest* service.
Thanks a lot !!!
* *Ronen Itkin
Re: HMaster issues
Posted by Jean-Daniel Cryans <jd...@apache.org>.
The client will pick it up like any other HBase process ran with bin/
scripts, so this would point to a configuration error. Make sure your client
is really picking up the config file you think it is, that there's no typo
in the file, that sort of stuff.
J-D
On Thu, Oct 20, 2011 at 11:15 AM, Ben West <bw...@yahoo.com> wrote:
> You're right:
>
> 11/10/18 15:39:54 INFO zookeeper.ZooKeeper: Initiating client connection,
> connectString=localhost:2181 sessionTimeout=180000
> watcher=hconnection
>
>
> How can I configure the port? It's set in my hbase-site.xml file correctly.
>
>
>
> ----- Original Message -----
> From: Jean-Daniel Cryans <jd...@apache.org>
> To: user@hbase.apache.org; Ben West <bw...@yahoo.com>
> Cc:
> Sent: Tuesday, October 18, 2011 1:23 PM
> Subject: Re: HMaster issues
>
> This line:
>
> java.lang.NoSuchMethodException:
>
> org.apache.hadoop.fs.ChecksumFileSystem$ChecksumFSInputChecker.getFileLength()
>
> Is because it's using the local filesystem and not HDFS (so it's expected).
>
> As far as I can tell the master starts ok, maybe the client is trying to
> use
> the ZK port 2181? Start the shell with -d and it should show you where it's
> connecting.
>
> J-D
>
> On Tue, Oct 18, 2011 at 7:19 AM, Ben West <bw...@yahoo.com> wrote:
>
> > Hey All,
> >
> > I'm having an issue I can't debug. The shell gives me a
> > MasterNotRunningException, but I can connect to the master via the web
> > interface. I'm using the Cloudera demo VM, which has a standalone
> instance
> > of HBase.
> >
> > I'm attaching the HBase-master log file. The only thing I can see is a
> > warning that getting a checksum failed, but from the warning that doesn't
> > sound very serious.
> >
> > The only thing in my config file is to change the Zookeeper port since
> > there seemed to be a conflict with the default.
> >
> > Any help would be appreciated,
> > -Ben
> >
>
Re: HMaster issues
Posted by Ben West <bw...@yahoo.com>.
You're right:
11/10/18 15:39:54 INFO zookeeper.ZooKeeper: Initiating client connection, connectString=localhost:2181 sessionTimeout=180000
watcher=hconnection
How can I configure the port? It's set in my hbase-site.xml file correctly.
----- Original Message -----
From: Jean-Daniel Cryans <jd...@apache.org>
To: user@hbase.apache.org; Ben West <bw...@yahoo.com>
Cc:
Sent: Tuesday, October 18, 2011 1:23 PM
Subject: Re: HMaster issues
This line:
java.lang.NoSuchMethodException:
org.apache.hadoop.fs.ChecksumFileSystem$ChecksumFSInputChecker.getFileLength()
Is because it's using the local filesystem and not HDFS (so it's expected).
As far as I can tell the master starts ok, maybe the client is trying to use
the ZK port 2181? Start the shell with -d and it should show you where it's
connecting.
J-D
On Tue, Oct 18, 2011 at 7:19 AM, Ben West <bw...@yahoo.com> wrote:
> Hey All,
>
> I'm having an issue I can't debug. The shell gives me a
> MasterNotRunningException, but I can connect to the master via the web
> interface. I'm using the Cloudera demo VM, which has a standalone instance
> of HBase.
>
> I'm attaching the HBase-master log file. The only thing I can see is a
> warning that getting a checksum failed, but from the warning that doesn't
> sound very serious.
>
> The only thing in my config file is to change the Zookeeper port since
> there seemed to be a conflict with the default.
>
> Any help would be appreciated,
> -Ben
>
>
> Tue Oct 18 08:27:17 EDT 2011 Starting master on localhost.localdomain
> ulimit -n 1024
> 2011-10-18 08:27:20,631 INFO org.apache.zookeeper.server.ZooKeeperServer:
> Server environment:zookeeper.version=3.3.3-cdh3u1--1, built on 07/30/2011
> 01:29 GMT
> 2011-10-18 08:27:20,631 INFO org.apache.zookeeper.server.ZooKeeperServer:
> Server environment:host.name=localhost.localdomain
> 2011-10-18 08:27:20,631 INFO org.apache.zookeeper.server.ZooKeeperServer:
> Server environment:java.version=1.6.0_21
> 2011-10-18 08:27:20,631 INFO org.apache.zookeeper.server.ZooKeeperServer:
> Server environment:java.vendor=Sun Microsystems Inc.
> 2011-10-18 08:27:20,631 INFO org.apache.zookeeper.server.ZooKeeperServer:
> Server environment:java.home=/usr/java/jdk1.6.0_21/jre
> 2011-10-18 08:27:20,631 INFO org.apache.zookeeper.server.ZooKeeperServer:
> Server
>
>
environment:java.class.path=/usr/lib/hbase/bin/../conf:/usr/java/jdk1.6.0_21/lib/tools.jar:/usr/lib/hbase/bin/..:/usr/lib/hbase/bin/../hbase-0.90.3-cdh3u1.jar:/usr/lib/hbase/bin/../hbase-0.90.3-cdh3u1-tests.jar:/usr/lib/hbase/bin/../lib/activation-1.1.jar:/usr/lib/hbase/bin/../lib/asm-3.1.jar:/usr/lib/hbase/bin/../lib/avro-1.3.3.jar:/usr/lib/hbase/bin/../lib/commons-cli-1.2.jar:/usr/lib/hbase/bin/../lib/commons-codec-1.4.jar:/usr/lib/hbase/bin/../lib/commons-el-1.0.jar:/usr/lib/hbase/bin/../lib/commons-httpclient-3.1.jar:/usr/lib/hbase/bin/../lib/commons-lang-2.5.jar:/usr/lib/hbase/bin/../lib/commons-logging-1.1.1.jar:/usr/lib/hbase/bin/../lib/commons-net-1.4.1.jar:/usr/lib/hbase/bin/../lib/core-3.1.1.jar:/usr/lib/hbase/bin/../lib/guava-r06.jar:/usr/lib/hbase/bin/../lib/hadoop-core.jar:/usr/lib/hbase/bin/../lib/jackson-core-asl-1.5.2.jar:/usr/lib/hbase/bin/../lib/jackson-jaxrs-1.5.5.jar:/usr/lib/hbase/bin/../lib/jackson-mapper-asl-1.5.2.jar:/usr/lib/hb
>
> ase/bin/../lib/jackson-xc-1.5.5.jar:/usr/lib/hbase/bin/../lib/jasper-compiler-5.5.23.jar:/usr/lib/hbase/bin/../lib/jasper-runtime-5.5.23.jar:/usr/lib/hbase/bin/../lib/jaxb-api-2.1.jar:/usr/lib/hbase/bin/../lib/jaxb-impl-2.1.12.jar:/usr/lib/hbase/bin/../lib/jersey-core-1.4.jar:/usr/lib/hbase/bin/../lib/jersey-json-1.4.jar:/usr/lib/hbase/bin/../lib/jersey-server-1.4.jar:/usr/lib/hbase/bin/../lib/jettison-1.1.jar:/usr/lib/hbase/bin/../lib/jetty-6.1.26.jar:/usr/lib/hbase/bin/../lib/jetty-util-6.1.26.jar:/usr/lib/hbase/bin/../lib/jruby-complete-1.6.0.jar:/usr/lib/hbase/bin/../lib/jsp-2.1-6.1.14.jar:/usr/lib/hbase/bin/../lib/jsp-api-2.1-6.1.14.jar:/usr/lib/hbase/bin/../lib/jsp-api-2.1.jar:/usr/lib/hbase/bin/../lib/jsr311-api-1.1.1.jar:/usr/lib/hbase/bin/../lib/log4j-1.2.16.jar:/usr/lib/hbase/bin/../lib/protobuf-java-2.3.0.jar:/usr/lib/hbase/bin/../lib/servlet-api-2.5-6.1.14.jar:/usr/lib/hbase/bin/../lib/servlet-api-2.5.jar:/usr/lib/hbase/bin/../lib/slf4j-api-
>
> 1.5.8.jar:/usr/lib/hbase/bin/../lib/slf4j-log4j12-1.5.8.jar:/usr/lib/hbase/bin/../lib/stax-api-1.0.1.jar:/usr/lib/hbase/bin/../lib/thrift-0.2.0.jar:/usr/lib/hbase/bin/../lib/xmlenc-0.52.jar:/usr/lib/hbase/bin/../lib/zookeeper.jar
> 2011-10-18 08:27:20,631 INFO org.apache.zookeeper.server.ZooKeeperServer:
> Server
> environment:java.library.path=/usr/lib/hbase/bin/../lib/native/Linux-amd64-64
> 2011-10-18 08:27:20,631 INFO org.apache.zookeeper.server.ZooKeeperServer:
> Server environment:java.io.tmpdir=/tmp
> 2011-10-18 08:27:20,631 INFO org.apache.zookeeper.server.ZooKeeperServer:
> Server environment:java.compiler=<NA>
> 2011-10-18 08:27:20,631 INFO org.apache.zookeeper.server.ZooKeeperServer:
> Server environment:os.name=Linux
> 2011-10-18 08:27:20,631 INFO org.apache.zookeeper.server.ZooKeeperServer:
> Server environment:os.arch=amd64
> 2011-10-18 08:27:20,631 INFO org.apache.zookeeper.server.ZooKeeperServer:
> Server environment:os.version=2.6.18-238.19.1.el5
> 2011-10-18 08:27:20,631 INFO org.apache.zookeeper.server.ZooKeeperServer:
> Server environment:user.name=hbase
> 2011-10-18 08:27:20,631 INFO org.apache.zookeeper.server.ZooKeeperServer:
> Server environment:user.home=/var/run/hbase
> 2011-10-18 08:27:20,631 INFO org.apache.zookeeper.server.ZooKeeperServer:
> Server environment:user.dir=/
> 2011-10-18 08:27:20,837 INFO org.apache.zookeeper.server.ZooKeeperServer:
> Created server with tickTime 2000 minSessionTimeout 4000 maxSessionTimeout
> 40000 datadir /tmp/hbase-hbase/zookeeper/zookeeper/version-2 snapdir
> /tmp/hbase-hbase/zookeeper/zookeeper/version-2
> 2011-10-18 08:27:21,189 INFO org.apache.zookeeper.server.NIOServerCnxn:
> binding to port 0.0.0.0/0.0.0.0:2182
> 2011-10-18 08:27:21,220 INFO
> org.apache.zookeeper.server.persistence.FileTxnSnapLog: Snapshotting: 0
> 2011-10-18 08:27:21,463 INFO org.apache.zookeeper.server.NIOServerCnxn:
> Accepted socket connection from /127.0.0.1:48821
> 2011-10-18 08:27:21,485 INFO org.apache.zookeeper.server.NIOServerCnxn:
> Processing stat command from /127.0.0.1:48821
> 2011-10-18 08:27:21,488 INFO org.apache.zookeeper.server.NIOServerCnxn:
> Stat command output
> 2011-10-18 08:27:21,488 INFO org.apache.zookeeper.server.NIOServerCnxn:
> Closed socket connection for client /127.0.0.1:48821 (no session
> established for client)
> 2011-10-18 08:27:21,489 INFO
> org.apache.hadoop.hbase.zookeeper.MiniZooKeeperCluster: Started MiniZK
> Server on client port: 2182
> 2011-10-18 08:27:21,939 INFO org.apache.hadoop.hbase.ipc.HBaseRpcMetrics:
> Initializing RPC Metrics with hostName=HMasterCommandLine$LocalHMaster,
> port=49977
> 2011-10-18 08:27:23,849 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server
> Responder: starting
> 2011-10-18 08:27:23,870 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server
> listener on 49977: starting
> 2011-10-18 08:27:23,884 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server
> handler 0 on 49977: starting
> 2011-10-18 08:27:23,885 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server
> handler 1 on 49977: starting
> 2011-10-18 08:27:23,909 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server
> handler 3 on 49977: starting
> 2011-10-18 08:27:23,909 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server
> handler 2 on 49977: starting
> 2011-10-18 08:27:23,910 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server
> handler 4 on 49977: starting
> 2011-10-18 08:27:23,910 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server
> handler 5 on 49977: starting
> 2011-10-18 08:27:23,910 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server
> handler 6 on 49977: starting
> 2011-10-18 08:27:23,911 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server
> handler 7 on 49977: starting
> 2011-10-18 08:27:23,911 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server
> handler 8 on 49977: starting
> 2011-10-18 08:27:23,911 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server
> handler 9 on 49977: starting
> 2011-10-18 08:27:23,951 INFO org.apache.zookeeper.ZooKeeper: Client
> environment:zookeeper.version=3.3.3-cdh3u1--1, built on 07/30/2011 01:29 GMT
> 2011-10-18 08:27:23,951 INFO org.apache.zookeeper.ZooKeeper: Client
> environment:host.name=localhost.localdomain
> 2011-10-18 08:27:23,951 INFO org.apache.zookeeper.ZooKeeper: Client
> environment:java.version=1.6.0_21
> 2011-10-18 08:27:23,951 INFO org.apache.zookeeper.ZooKeeper: Client
> environment:java.vendor=Sun Microsystems Inc.
> 2011-10-18 08:27:23,951 INFO org.apache.zookeeper.ZooKeeper: Client
> environment:java.home=/usr/java/jdk1.6.0_21/jre
> 2011-10-18 08:27:23,951 INFO org.apache.zookeeper.ZooKeeper: Client
>
>
environment:java.class.path=/usr/lib/hbase/bin/../conf:/usr/java/jdk1.6.0_21/lib/tools.jar:/usr/lib/hbase/bin/..:/usr/lib/hbase/bin/../hbase-0.90.3-cdh3u1.jar:/usr/lib/hbase/bin/../hbase-0.90.3-cdh3u1-tests.jar:/usr/lib/hbase/bin/../lib/activation-1.1.jar:/usr/lib/hbase/bin/../lib/asm-3.1.jar:/usr/lib/hbase/bin/../lib/avro-1.3.3.jar:/usr/lib/hbase/bin/../lib/commons-cli-1.2.jar:/usr/lib/hbase/bin/../lib/commons-codec-1.4.jar:/usr/lib/hbase/bin/../lib/commons-el-1.0.jar:/usr/lib/hbase/bin/../lib/commons-httpclient-3.1.jar:/usr/lib/hbase/bin/../lib/commons-lang-2.5.jar:/usr/lib/hbase/bin/../lib/commons-logging-1.1.1.jar:/usr/lib/hbase/bin/../lib/commons-net-1.4.1.jar:/usr/lib/hbase/bin/../lib/core-3.1.1.jar:/usr/lib/hbase/bin/../lib/guava-r06.jar:/usr/lib/hbase/bin/../lib/hadoop-core.jar:/usr/lib/hbase/bin/../lib/jackson-core-asl-1.5.2.jar:/usr/lib/hbase/bin/../lib/jackson-jaxrs-1.5.5.jar:/usr/lib/hbase/bin/../lib/jackson-mapper-asl-1.5.2.jar:/usr/lib/hb
>
> ase/bin/../lib/jackson-xc-1.5.5.jar:/usr/lib/hbase/bin/../lib/jasper-compiler-5.5.23.jar:/usr/lib/hbase/bin/../lib/jasper-runtime-5.5.23.jar:/usr/lib/hbase/bin/../lib/jaxb-api-2.1.jar:/usr/lib/hbase/bin/../lib/jaxb-impl-2.1.12.jar:/usr/lib/hbase/bin/../lib/jersey-core-1.4.jar:/usr/lib/hbase/bin/../lib/jersey-json-1.4.jar:/usr/lib/hbase/bin/../lib/jersey-server-1.4.jar:/usr/lib/hbase/bin/../lib/jettison-1.1.jar:/usr/lib/hbase/bin/../lib/jetty-6.1.26.jar:/usr/lib/hbase/bin/../lib/jetty-util-6.1.26.jar:/usr/lib/hbase/bin/../lib/jruby-complete-1.6.0.jar:/usr/lib/hbase/bin/../lib/jsp-2.1-6.1.14.jar:/usr/lib/hbase/bin/../lib/jsp-api-2.1-6.1.14.jar:/usr/lib/hbase/bin/../lib/jsp-api-2.1.jar:/usr/lib/hbase/bin/../lib/jsr311-api-1.1.1.jar:/usr/lib/hbase/bin/../lib/log4j-1.2.16.jar:/usr/lib/hbase/bin/../lib/protobuf-java-2.3.0.jar:/usr/lib/hbase/bin/../lib/servlet-api-2.5-6.1.14.jar:/usr/lib/hbase/bin/../lib/servlet-api-2.5.jar:/usr/lib/hbase/bin/../lib/slf4j-api-
>
> 1.5.8.jar:/usr/lib/hbase/bin/../lib/slf4j-log4j12-1.5.8.jar:/usr/lib/hbase/bin/../lib/stax-api-1.0.1.jar:/usr/lib/hbase/bin/../lib/thrift-0.2.0.jar:/usr/lib/hbase/bin/../lib/xmlenc-0.52.jar:/usr/lib/hbase/bin/../lib/zookeeper.jar
> 2011-10-18 08:27:23,951 INFO org.apache.zookeeper.ZooKeeper: Client
> environment:java.library.path=/usr/lib/hbase/bin/../lib/native/Linux-amd64-64
> 2011-10-18 08:27:23,951 INFO org.apache.zookeeper.ZooKeeper: Client
> environment:java.io.tmpdir=/tmp
> 2011-10-18 08:27:23,951 INFO org.apache.zookeeper.ZooKeeper: Client
> environment:java.compiler=<NA>
> 2011-10-18 08:27:23,951 INFO org.apache.zookeeper.ZooKeeper: Client
> environment:os.name=Linux
> 2011-10-18 08:27:23,951 INFO org.apache.zookeeper.ZooKeeper: Client
> environment:os.arch=amd64
> 2011-10-18 08:27:23,951 INFO org.apache.zookeeper.ZooKeeper: Client
> environment:os.version=2.6.18-238.19.1.el5
> 2011-10-18 08:27:23,951 INFO org.apache.zookeeper.ZooKeeper: Client
> environment:user.name=hbase
> 2011-10-18 08:27:23,951 INFO org.apache.zookeeper.ZooKeeper: Client
> environment:user.home=/var/run/hbase
> 2011-10-18 08:27:23,951 INFO org.apache.zookeeper.ZooKeeper: Client
> environment:user.dir=/
> 2011-10-18 08:27:23,952 INFO org.apache.zookeeper.ZooKeeper: Initiating
> client connection, connectString=localhost:2182 sessionTimeout=180000
> watcher=master:49977
> 2011-10-18 08:27:24,009 INFO org.apache.zookeeper.ClientCnxn: Opening
> socket connection to server localhost/127.0.0.1:2182
> 2011-10-18 08:27:24,047 INFO org.apache.zookeeper.server.NIOServerCnxn:
> Accepted socket connection from /127.0.0.1:48824
> 2011-10-18 08:27:24,047 INFO org.apache.zookeeper.ClientCnxn: Socket
> connection established to localhost/127.0.0.1:2182, initiating session
> 2011-10-18 08:27:24,064 INFO org.apache.zookeeper.server.NIOServerCnxn:
> Client attempting to establish new session at /127.0.0.1:48824
> 2011-10-18 08:27:24,066 INFO
> org.apache.zookeeper.server.persistence.FileTxnLog: Creating new log file:
> log.1
> 2011-10-18 08:27:24,092 INFO org.apache.zookeeper.server.NIOServerCnxn:
> Established session 0x1331700150e0000 with negotiated timeout 40000 for
> client /127.0.0.1:48824
> 2011-10-18 08:27:24,097 INFO org.apache.zookeeper.ClientCnxn: Session
> establishment complete on server localhost/127.0.0.1:2182, sessionid =
> 0x1331700150e0000, negotiated timeout = 40000
> 2011-10-18 08:27:24,111 INFO org.apache.hadoop.metrics.jvm.JvmMetrics:
> Initializing JVM Metrics with processName=Master,
> sessionId=localhost.localdomain:49977
> 2011-10-18 08:27:24,131 INFO org.apache.hadoop.hbase.metrics: MetricsString
> added: revision
> 2011-10-18 08:27:24,131 INFO org.apache.hadoop.hbase.metrics: MetricsString
> added: hdfsUser
> 2011-10-18 08:27:24,131 INFO org.apache.hadoop.hbase.metrics: MetricsString
> added: hdfsDate
> 2011-10-18 08:27:24,131 INFO org.apache.hadoop.hbase.metrics: MetricsString
> added: hdfsUrl
> 2011-10-18 08:27:24,131 INFO org.apache.hadoop.hbase.metrics: MetricsString
> added: date
> 2011-10-18 08:27:24,131 INFO org.apache.hadoop.hbase.metrics: MetricsString
> added: hdfsRevision
> 2011-10-18 08:27:24,131 INFO org.apache.hadoop.hbase.metrics: MetricsString
> added: user
> 2011-10-18 08:27:24,131 INFO org.apache.hadoop.hbase.metrics: MetricsString
> added: hdfsVersion
> 2011-10-18 08:27:24,131 INFO org.apache.hadoop.hbase.metrics: MetricsString
> added: url
> 2011-10-18 08:27:24,131 INFO org.apache.hadoop.hbase.metrics: MetricsString
> added: version
> 2011-10-18 08:27:24,131 INFO org.apache.hadoop.hbase.metrics: new MBeanInfo
> 2011-10-18 08:27:24,131 INFO org.apache.hadoop.hbase.metrics: new MBeanInfo
> 2011-10-18 08:27:24,132 INFO
> org.apache.hadoop.hbase.master.metrics.MasterMetrics: Initialized
> 2011-10-18 08:27:24,508 INFO org.apache.zookeeper.ZooKeeper: Initiating
> client connection, connectString=localhost:2182 sessionTimeout=180000
> watcher=hconnection
> 2011-10-18 08:27:24,508 INFO org.apache.zookeeper.ClientCnxn: Opening
> socket connection to server localhost/127.0.0.1:2182
> 2011-10-18 08:27:24,527 INFO org.apache.zookeeper.server.NIOServerCnxn:
> Accepted socket connection from /127.0.0.1:48825
> 2011-10-18 08:27:24,528 INFO org.apache.zookeeper.ClientCnxn: Socket
> connection established to localhost/127.0.0.1:2182, initiating session
> 2011-10-18 08:27:24,528 INFO org.apache.zookeeper.server.NIOServerCnxn:
> Client attempting to establish new session at /127.0.0.1:48825
> 2011-10-18 08:27:24,537 INFO org.apache.zookeeper.server.NIOServerCnxn:
> Established session 0x1331700150e0001 with negotiated timeout 40000 for
> client /127.0.0.1:48825
> 2011-10-18 08:27:24,539 INFO org.apache.zookeeper.ClientCnxn: Session
> establishment complete on server localhost/127.0.0.1:2182, sessionid =
> 0x1331700150e0001, negotiated timeout = 40000
> 2011-10-18 08:27:24,727 INFO org.apache.hadoop.hbase.ipc.HBaseRpcMetrics:
> Initializing RPC Metrics with hostName=HRegionServer, port=57754
> 2011-10-18 08:27:25,093 INFO org.apache.zookeeper.ZooKeeper: Initiating
> client connection, connectString=localhost:2182 sessionTimeout=180000
> watcher=regionserver:57754
> 2011-10-18 08:27:25,093 INFO
> org.apache.hadoop.hbase.master.ActiveMasterManager:
> Master=localhost.localdomain:49977
> 2011-10-18 08:27:25,107 INFO org.apache.zookeeper.ClientCnxn: Opening
> socket connection to server localhost/127.0.0.1:2182
> 2011-10-18 08:27:25,107 INFO org.apache.zookeeper.server.NIOServerCnxn:
> Accepted socket connection from /127.0.0.1:48826
> 2011-10-18 08:27:25,109 INFO org.apache.zookeeper.ClientCnxn: Socket
> connection established to localhost/127.0.0.1:2182, initiating session
> 2011-10-18 08:27:25,109 INFO org.apache.zookeeper.server.NIOServerCnxn:
> Client attempting to establish new session at /127.0.0.1:48826
> 2011-10-18 08:27:25,113 INFO org.apache.zookeeper.server.NIOServerCnxn:
> Established session 0x1331700150e0002 with negotiated timeout 40000 for
> client /127.0.0.1:48826
> 2011-10-18 08:27:25,117 INFO org.apache.zookeeper.ClientCnxn: Session
> establishment complete on server localhost/127.0.0.1:2182, sessionid =
> 0x1331700150e0002, negotiated timeout = 40000
> 2011-10-18 08:27:26,071 INFO org.apache.zookeeper.ZooKeeper: Initiating
> client connection, connectString=localhost:2182 sessionTimeout=180000
> watcher=hconnection
> 2011-10-18 08:27:26,072 INFO org.apache.zookeeper.ClientCnxn: Opening
> socket connection to server localhost/127.0.0.1:2182
> 2011-10-18 08:27:26,072 INFO org.apache.zookeeper.server.NIOServerCnxn:
> Accepted socket connection from /127.0.0.1:48827
> 2011-10-18 08:27:26,072 INFO org.apache.zookeeper.ClientCnxn: Socket
> connection established to localhost/127.0.0.1:2182, initiating session
> 2011-10-18 08:27:26,073 INFO org.apache.zookeeper.server.NIOServerCnxn:
> Client attempting to establish new session at /127.0.0.1:48827
> 2011-10-18 08:27:26,078 INFO org.apache.zookeeper.server.NIOServerCnxn:
> Established session 0x1331700150e0003 with negotiated timeout 40000 for
> client /127.0.0.1:48827
> 2011-10-18 08:27:26,080 INFO org.apache.zookeeper.ClientCnxn: Session
> establishment complete on server localhost/127.0.0.1:2182, sessionid =
> 0x1331700150e0003, negotiated timeout = 40000
> 2011-10-18 08:27:26,148 DEBUG
> org.apache.hadoop.hbase.catalog.CatalogTracker: Starting catalog tracker
> org.apache.hadoop.hbase.catalog.CatalogTracker@7f5d3388
> 2011-10-18 08:27:26,212 DEBUG
> org.apache.hadoop.hbase.catalog.CatalogTracker: Starting catalog tracker
> org.apache.hadoop.hbase.catalog.CatalogTracker@342798e7
> 2011-10-18 08:27:26,217 INFO
> org.apache.hadoop.hbase.regionserver.MemStoreFlusher:
> globalMemStoreLimit=399.2m, globalMemStoreLimitLowMark=349.3m,
> maxHeap=997.9m
> 2011-10-18 08:27:26,219 DEBUG
> org.apache.hadoop.hbase.regionserver.PriorityCompactionQueue: Create
> PriorityCompactionQueue
> 2011-10-18 08:27:26,219 INFO
> org.apache.hadoop.hbase.regionserver.HRegionServer: Runs every 10000000ms
> 2011-10-18 08:27:26,294 INFO
> org.apache.hadoop.hbase.regionserver.HRegionServer: Attempting connect to
> Master server at localhost.localdomain:49977
> 2011-10-18 08:27:26,344 INFO
> org.apache.hadoop.hbase.regionserver.HRegionServer: Master isn't available
> yet, retrying
> 2011-10-18 08:27:26,348 INFO org.apache.hadoop.hbase.master.HMaster: Server
> active/primary master; localhost.localdomain:49977,
> sessionid=0x1331700150e0000, cluster-up flag was=false
> 2011-10-18 08:27:26,349 DEBUG
> org.apache.hadoop.hbase.executor.ExecutorService: Starting executor service
> name=MASTER_OPEN_REGION-localhost.localdomain:49977, corePoolSize=5,
> maxPoolSize=5
> 2011-10-18 08:27:26,349 DEBUG
> org.apache.hadoop.hbase.executor.ExecutorService: Starting executor service
> name=MASTER_CLOSE_REGION-localhost.localdomain:49977, corePoolSize=5,
> maxPoolSize=5
> 2011-10-18 08:27:26,349 DEBUG
> org.apache.hadoop.hbase.executor.ExecutorService: Starting executor service
> name=MASTER_SERVER_OPERATIONS-localhost.localdomain:49977, corePoolSize=3,
> maxPoolSize=3
> 2011-10-18 08:27:26,349 DEBUG
> org.apache.hadoop.hbase.executor.ExecutorService: Starting executor service
> name=MASTER_META_SERVER_OPERATIONS-localhost.localdomain:49977,
> corePoolSize=5, maxPoolSize=5
> 2011-10-18 08:27:26,349 DEBUG
> org.apache.hadoop.hbase.executor.ExecutorService: Starting executor service
> name=MASTER_TABLE_OPERATIONS-localhost.localdomain:49977, corePoolSize=1,
> maxPoolSize=1
> 2011-10-18 08:27:26,351 DEBUG org.apache.hadoop.hbase.master.LogCleaner:
> Add log cleaner in chain:
> org.apache.hadoop.hbase.master.TimeToLiveLogCleaner
> 2011-10-18 08:27:26,739 INFO org.mortbay.log: Logging to
> org.slf4j.impl.Log4jLoggerAdapter(org.mortbay.log) via
> org.mortbay.log.Slf4jLog
> 2011-10-18 08:27:26,832 INFO org.apache.hadoop.http.HttpServer: Added
> global filtersafety
> (class=org.apache.hadoop.http.HttpServer$QuotingInputFilter)
> 2011-10-18 08:27:26,838 INFO org.apache.hadoop.http.HttpServer: Port
> returned by webServer.getConnectors()[0].getLocalPort() before open() is -1.
> Opening the listener on 60010
> 2011-10-18 08:27:26,838 INFO org.apache.hadoop.http.HttpServer:
> listener.getLocalPort() returned 60010
> webServer.getConnectors()[0].getLocalPort() returned 60010
> 2011-10-18 08:27:26,838 INFO org.apache.hadoop.http.HttpServer: Jetty bound
> to port 60010
> 2011-10-18 08:27:26,838 INFO org.mortbay.log: jetty-6.1.26
> 2011-10-18 08:27:27,019 WARN org.mortbay.log: Can't reuse
> /tmp/Jetty_0_0_0_0_60010_master____q3nwom, using
> /tmp/Jetty_0_0_0_0_60010_master____q3nwom_3288413844900815841
> 2011-10-18 08:27:27,877 INFO org.mortbay.log: Started
> SelectChannelConnector@0.0.0.0:60010
> 2011-10-18 08:27:27,877 DEBUG org.apache.hadoop.hbase.master.HMaster:
> Started service threads
> 2011-10-18 08:27:29,348 INFO
> org.apache.hadoop.hbase.regionserver.HRegionServer: Attempting connect to
> Master server at localhost.localdomain:49977
> 2011-10-18 08:27:29,356 INFO
> org.apache.hadoop.hbase.regionserver.HRegionServer: Connected to master at
> localhost.localdomain:49977
> 2011-10-18 08:27:29,359 INFO
> org.apache.hadoop.hbase.regionserver.HRegionServer: Telling master at
> localhost.localdomain:49977 that we are up
> 2011-10-18 08:27:29,364 INFO org.apache.hadoop.hbase.master.ServerManager:
> Registering server=localhost.localdomain,57754,1318940844922, regionCount=0,
> userLoad=false
> 2011-10-18 08:27:29,373 INFO
> org.apache.hadoop.hbase.regionserver.HRegionServer: Master passed us address
> to use. Was=localhost.localdomain:57754, Now=localhost.localdomain:57754
> 2011-10-18 08:27:29,373 DEBUG
> org.apache.hadoop.hbase.regionserver.HRegionServer: Config from master:
> fs.default.name=file:///
> 2011-10-18 08:27:29,373 DEBUG
> org.apache.hadoop.hbase.regionserver.HRegionServer: Config from master:
> hbase.rootdir=file:///tmp/hbase-hbase/hbase
> 2011-10-18 08:27:29,376 DEBUG
> org.apache.hadoop.hbase.regionserver.HRegionServer:
> logdir=file:/tmp/hbase-hbase/hbase/.logs/localhost.localdomain,57754,1318940844922
> 2011-10-18 08:27:29,380 INFO org.apache.hadoop.hbase.master.ServerManager:
> Waiting on regionserver(s) count to settle; currently=1
> 2011-10-18 08:27:29,399 INFO org.apache.hadoop.hbase.regionserver.wal.HLog:
> HLog configuration: blocksize=32 MB, rollsize=30.4 MB, enabled=true,
> flushlogentries=1, optionallogflushinternal=1000ms
> 2011-10-18 08:27:29,450 WARN org.apache.hadoop.util.NativeCodeLoader:
> Unable to load native-hadoop library for your platform... using builtin-java
> classes where applicable
> 2011-10-18 08:27:29,496 INFO
> org.apache.hadoop.hbase.regionserver.wal.SequenceFileLogWriter: syncFs --
> HDFS-200 -- not available, dfs.support.append=false
> 2011-10-18 08:27:29,497 INFO org.apache.hadoop.hbase.regionserver.wal.HLog:
> New hlog
> /tmp/hbase-hbase/hbase/.logs/localhost.localdomain,57754,1318940844922/localhost.localdomain%3A57754.1318940849409
> 2011-10-18 08:27:29,497 INFO org.apache.hadoop.hbase.regionserver.wal.HLog:
> getNumCurrentReplicas--HDFS-826 not available;
> hdfs_out=org.apache.hadoop.fs.ChecksumFileSystem$ChecksumFSOutputSummer@381eb0c6,
> exception=org.apache.hadoop.fs.ChecksumFileSystem$ChecksumFSOutputSummer.getNumCurrentReplicas()
> 2011-10-18 08:27:29,506 INFO org.apache.hadoop.metrics.jvm.JvmMetrics:
> Cannot initialize JVM Metrics with processName=RegionServer,
> sessionId=RegionServer:0;localhost.localdomain,57754,1318940844922 - already
> initialized
> 2011-10-18 08:27:29,509 INFO org.apache.hadoop.hbase.metrics: new MBeanInfo
> 2011-10-18 08:27:29,510 INFO
> org.apache.hadoop.hbase.regionserver.metrics.RegionServerMetrics:
> Initialized
> 2011-10-18 08:27:29,511 DEBUG
> org.apache.hadoop.hbase.executor.ExecutorService: Starting executor service
> name=RS_OPEN_REGION-localhost.localdomain,57754,1318940844922,
> corePoolSize=3, maxPoolSize=3
> 2011-10-18 08:27:29,512 DEBUG
> org.apache.hadoop.hbase.executor.ExecutorService: Starting executor service
> name=RS_OPEN_ROOT-localhost.localdomain,57754,1318940844922, corePoolSize=1,
> maxPoolSize=1
> 2011-10-18 08:27:29,512 DEBUG
> org.apache.hadoop.hbase.executor.ExecutorService: Starting executor service
> name=RS_OPEN_META-localhost.localdomain,57754,1318940844922, corePoolSize=1,
> maxPoolSize=1
> 2011-10-18 08:27:29,512 DEBUG
> org.apache.hadoop.hbase.executor.ExecutorService: Starting executor service
> name=RS_CLOSE_REGION-localhost.localdomain,57754,1318940844922,
> corePoolSize=3, maxPoolSize=3
> 2011-10-18 08:27:29,512 DEBUG
> org.apache.hadoop.hbase.executor.ExecutorService: Starting executor service
> name=RS_CLOSE_ROOT-localhost.localdomain,57754,1318940844922,
> corePoolSize=1, maxPoolSize=1
> 2011-10-18 08:27:29,512 DEBUG
> org.apache.hadoop.hbase.executor.ExecutorService: Starting executor service
> name=RS_CLOSE_META-localhost.localdomain,57754,1318940844922,
> corePoolSize=1, maxPoolSize=1
> 2011-10-18 08:27:29,699 INFO org.apache.hadoop.http.HttpServer: Added
> global filtersafety
> (class=org.apache.hadoop.http.HttpServer$QuotingInputFilter)
> 2011-10-18 08:27:29,700 INFO org.apache.hadoop.http.HttpServer: Port
> returned by webServer.getConnectors()[0].getLocalPort() before open() is -1.
> Opening the listener on 60030
> 2011-10-18 08:27:29,700 INFO org.apache.hadoop.http.HttpServer:
> listener.getLocalPort() returned 60030
> webServer.getConnectors()[0].getLocalPort() returned 60030
> 2011-10-18 08:27:29,700 INFO org.apache.hadoop.http.HttpServer: Jetty bound
> to port 60030
> 2011-10-18 08:27:29,700 INFO org.mortbay.log: jetty-6.1.26
> 2011-10-18 08:27:29,715 WARN org.mortbay.log: Can't reuse
> /tmp/Jetty_0_0_0_0_60030_regionserver____.h599vl, using
> /tmp/Jetty_0_0_0_0_60030_regionserver____.h599vl_2500151639767017676
> 2011-10-18 08:27:30,234 INFO org.mortbay.log: Started
> SelectChannelConnector@0.0.0.0:60030
> 2011-10-18 08:27:30,236 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server
> Responder: starting
> 2011-10-18 08:27:30,236 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server
> listener on 57754: starting
> 2011-10-18 08:27:30,236 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server
> handler 0 on 57754: starting
> 2011-10-18 08:27:30,236 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server
> handler 1 on 57754: starting
> 2011-10-18 08:27:30,236 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server
> handler 2 on 57754: starting
> 2011-10-18 08:27:30,258 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server
> handler 4 on 57754: starting
> 2011-10-18 08:27:30,258 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server
> handler 5 on 57754: starting
> 2011-10-18 08:27:30,261 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server
> handler 3 on 57754: starting
> 2011-10-18 08:27:30,283 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server
> handler 7 on 57754: starting
> 2011-10-18 08:27:30,284 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server
> handler 8 on 57754: starting
> 2011-10-18 08:27:30,284 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server
> handler 6 on 57754: starting
> 2011-10-18 08:27:30,284 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server
> handler 9 on 57754: starting
> 2011-10-18 08:27:30,284 INFO org.apache.hadoop.ipc.HBaseServer: PRI IPC
> Server handler 0 on 57754: starting
> 2011-10-18 08:27:30,298 INFO org.apache.hadoop.ipc.HBaseServer: PRI IPC
> Server handler 1 on 57754: starting
> 2011-10-18 08:27:30,298 INFO org.apache.hadoop.ipc.HBaseServer: PRI IPC
> Server handler 2 on 57754: starting
> 2011-10-18 08:27:30,299 INFO org.apache.hadoop.ipc.HBaseServer: PRI IPC
> Server handler 3 on 57754: starting
> 2011-10-18 08:27:30,322 INFO org.apache.hadoop.ipc.HBaseServer: PRI IPC
> Server handler 4 on 57754: starting
> 2011-10-18 08:27:30,369 INFO org.apache.hadoop.ipc.HBaseServer: PRI IPC
> Server handler 5 on 57754: starting
> 2011-10-18 08:27:30,370 INFO org.apache.hadoop.ipc.HBaseServer: PRI IPC
> Server handler 6 on 57754: starting
> 2011-10-18 08:27:30,371 INFO org.apache.hadoop.ipc.HBaseServer: PRI IPC
> Server handler 7 on 57754: starting
> 2011-10-18 08:27:30,371 INFO org.apache.hadoop.ipc.HBaseServer: PRI IPC
> Server handler 8 on 57754: starting
> 2011-10-18 08:27:30,371 INFO
> org.apache.hadoop.hbase.regionserver.HRegionServer: Serving as
> localhost.localdomain,57754,1318940844922, RPC listening on /
> 127.0.0.1:57754, sessionid=0x1331700150e0002
> 2011-10-18 08:27:30,372 INFO org.apache.hadoop.ipc.HBaseServer: PRI IPC
> Server handler 9 on 57754: starting
> 2011-10-18 08:27:30,524 INFO
> org.apache.hadoop.hbase.regionserver.StoreFile: Allocating LruBlockCache
> with maximum size 199.6m
> 2011-10-18 08:27:30,883 INFO org.apache.hadoop.hbase.master.ServerManager:
> Waiting on regionserver(s) count to settle; currently=1
> 2011-10-18 08:27:32,385 INFO org.apache.hadoop.hbase.master.ServerManager:
> Finished waiting for regionserver count to settle; count=1, sleptFor=4500
> 2011-10-18 08:27:32,385 INFO org.apache.hadoop.hbase.master.ServerManager:
> Exiting wait on regionserver(s) to checkin; count=1, stopped=false, count of
> regions out on cluster=0
> 2011-10-18 08:27:32,388 INFO
> org.apache.hadoop.hbase.master.MasterFileSystem: Log folder
> file:/tmp/hbase-hbase/hbase/.logs/localhost.localdomain,57754,1318940844922
> belongs to an existing region server
> 2011-10-18 08:27:32,388 INFO
> org.apache.hadoop.hbase.master.MasterFileSystem: Log folder
> file:/tmp/hbase-hbase/hbase/.logs/localhost.localdomain,50781,1318937790362
> doesn't belong to a known region server, splitting
> 2011-10-18 08:27:32,428 INFO
> org.apache.hadoop.hbase.regionserver.wal.HLogSplitter: Splitting 1 hlog(s)
> in
> file:/tmp/hbase-hbase/hbase/.logs/localhost.localdomain,50781,1318937790362
> 2011-10-18 08:27:32,429 DEBUG
> org.apache.hadoop.hbase.regionserver.wal.HLogSplitter: Writer thread
> Thread[WriterThread-0,5,main]: starting
> 2011-10-18 08:27:32,434 DEBUG
> org.apache.hadoop.hbase.regionserver.wal.HLogSplitter: Splitting hlog 1 of
> 1:
> file:/tmp/hbase-hbase/hbase/.logs/localhost.localdomain,50781,1318937790362/localhost.localdomain%3A50781.1318937795015,
> length=307
> 2011-10-18 08:27:32,435 WARN org.apache.hadoop.hbase.util.FSUtils: Running
> on HDFS without append enabled may result in data loss
> 2011-10-18 08:27:32,440 DEBUG
> org.apache.hadoop.hbase.regionserver.wal.HLogSplitter: Writer thread
> Thread[WriterThread-2,5,main]: starting
> 2011-10-18 08:27:32,443 DEBUG
> org.apache.hadoop.hbase.regionserver.wal.HLogSplitter: Writer thread
> Thread[WriterThread-1,5,main]: starting
> 2011-10-18 08:27:32,454 WARN
> org.apache.hadoop.hbase.regionserver.wal.SequenceFileLogReader: Error while
> trying to get accurate file length. Truncation / data loss may occur if
> RegionServers die.
> java.lang.NoSuchMethodException:
> org.apache.hadoop.fs.ChecksumFileSystem$ChecksumFSInputChecker.getFileLength()
> at java.lang.Class.getMethod(Class.java:1605)
> at
> org.apache.hadoop.hbase.regionserver.wal.SequenceFileLogReader$WALReader$WALReaderFSDataInputStream.getPos(SequenceFileLogReader.java:107)
> at org.apache.hadoop.io.SequenceFile$Reader.<init>(SequenceFile.java:1436)
> at org.apache.hadoop.io.SequenceFile$Reader.<init>(SequenceFile.java:1424)
> at org.apache.hadoop.io.SequenceFile$Reader.<init>(SequenceFile.java:1419)
> at
> org.apache.hadoop.hbase.regionserver.wal.SequenceFileLogReader$WALReader.<init>(SequenceFileLogReader.java:57)
> at
> org.apache.hadoop.hbase.regionserver.wal.SequenceFileLogReader.init(SequenceFileLogReader.java:158)
> at org.apache.hadoop.hbase.regionserver.wal.HLog.getReader(HLog.java:575)
> at
> org.apache.hadoop.hbase.regionserver.wal.HLogSplitter.getReader(HLogSplitter.java:477)
> at
> org.apache.hadoop.hbase.regionserver.wal.HLogSplitter.parseHLog(HLogSplitter.java:414)
> at
> org.apache.hadoop.hbase.regionserver.wal.HLogSplitter.splitLog(HLogSplitter.java:262)
> at
> org.apache.hadoop.hbase.regionserver.wal.HLogSplitter.splitLog(HLogSplitter.java:188)
> at
> org.apache.hadoop.hbase.master.MasterFileSystem.splitLog(MasterFileSystem.java:197)
> at
> org.apache.hadoop.hbase.master.MasterFileSystem.splitLogAfterStartup(MasterFileSystem.java:181)
> at
> org.apache.hadoop.hbase.master.HMaster.finishInitialization(HMaster.java:385)
> at org.apache.hadoop.hbase.master.HMaster.run(HMaster.java:283)
> at
> org.apache.hadoop.hbase.master.HMasterCommandLine$LocalHMaster.run(HMasterCommandLine.java:193)
> at java.lang.Thread.run(Thread.java:619)
> 2011-10-18 08:27:33,063 DEBUG
> org.apache.hadoop.hbase.regionserver.wal.HLogSplitter: Pushed=1 entries from
> file:/tmp/hbase-hbase/hbase/.logs/localhost.localdomain,50781,1318937790362/localhost.localdomain%3A50781.1318937795015
> 2011-10-18 08:27:33,069 INFO
> org.apache.hadoop.hbase.regionserver.wal.HLogSplitter: Archived processed
> log
> file:/tmp/hbase-hbase/hbase/.logs/localhost.localdomain,50781,1318937790362/localhost.localdomain%3A50781.1318937795015
> to
> file:/tmp/hbase-hbase/hbase/.oldlogs/localhost.localdomain%3A50781.1318937795015
> 2011-10-18 08:27:33,069 INFO
> org.apache.hadoop.hbase.regionserver.wal.HLogSplitter: Waiting for split
> writer threads to finish
> 2011-10-18 08:27:33,078 INFO
> org.apache.hadoop.hbase.regionserver.wal.SequenceFileLogWriter: syncFs --
> HDFS-200 -- not available, dfs.support.append=false
> 2011-10-18 08:27:33,079 DEBUG
> org.apache.hadoop.hbase.regionserver.wal.HLogSplitter: Creating writer
> path=file:/tmp/hbase-hbase/hbase/-ROOT-/70236052/recovered.edits/0000000000000000007
> region=70236052
> 2011-10-18 08:27:33,079 INFO
> org.apache.hadoop.hbase.regionserver.wal.HLogSplitter: Split writers
> finished
> 2011-10-18 08:27:33,080 INFO
> org.apache.hadoop.hbase.regionserver.wal.HLogSplitter: Closed path
> file:/tmp/hbase-hbase/hbase/-ROOT-/70236052/recovered.edits/0000000000000000007
> (wrote 1 edits in 17ms)
> 2011-10-18 08:27:33,080 INFO
> org.apache.hadoop.hbase.regionserver.wal.HLogSplitter: hlog file splitting
> completed in 657 ms for
> file:/tmp/hbase-hbase/hbase/.logs/localhost.localdomain,50781,1318937790362
> 2011-10-18 08:27:34,087 INFO
> org.apache.hadoop.hbase.catalog.RootLocationEditor: Unsetting ROOT region
> location in ZooKeeper
> 2011-10-18 08:27:34,089 INFO
> org.apache.zookeeper.server.PrepRequestProcessor: Got user-level
> KeeperException when processing sessionid:0x1331700150e0000 type:delete
> cxid:0x15 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error
> Path:/hbase/root-region-server Error:KeeperErrorCode = NoNode for
> /hbase/root-region-server
> 2011-10-18 08:27:34,092 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign:
> master:49977-0x1331700150e0000 Creating (or updating) unassigned node for
> 70236052 with OFFLINE state
> 2011-10-18 08:27:34,098 DEBUG
> org.apache.hadoop.hbase.master.AssignmentManager: No previous transition
> plan was found (or we are ignoring an existing plan) for -ROOT-,,0.70236052
> so generated a random one; hri=-ROOT-,,0.70236052, src=,
> dest=localhost.localdomain,57754,1318940844922; 1 (online=1, exclude=null)
> available servers
> 2011-10-18 08:27:34,098 DEBUG
> org.apache.hadoop.hbase.master.AssignmentManager: Assigning region
> -ROOT-,,0.70236052 to localhost.localdomain,57754,1318940844922
> 2011-10-18 08:27:34,098 DEBUG org.apache.hadoop.hbase.master.ServerManager:
> New connection to localhost.localdomain,57754,1318940844922
> 2011-10-18 08:27:34,131 INFO
> org.apache.hadoop.hbase.regionserver.HRegionServer: Received request to open
> region: -ROOT-,,0.70236052
> 2011-10-18 08:27:34,145 DEBUG
> org.apache.hadoop.hbase.regionserver.handler.OpenRegionHandler: Processing
> open of -ROOT-,,0.70236052
> 2011-10-18 08:27:34,146 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign:
> regionserver:57754-0x1331700150e0002 Attempting to transition node
> 70236052/-ROOT- from M_ZK_REGION_OFFLINE to RS_ZK_REGION_OPENING
> 2011-10-18 08:27:34,153 DEBUG
> org.apache.hadoop.hbase.master.AssignmentManager: Handling
> transition=RS_ZK_REGION_OPENING,
> server=localhost.localdomain,57754,1318940844922, region=70236052/-ROOT-
> 2011-10-18 08:27:34,154 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign:
> regionserver:57754-0x1331700150e0002 Successfully transitioned node 70236052
> from M_ZK_REGION_OFFLINE to RS_ZK_REGION_OPENING
> 2011-10-18 08:27:34,155 DEBUG org.apache.hadoop.hbase.regionserver.HRegion:
> Opening region: REGION => {NAME => '-ROOT-,,0', STARTKEY => '', ENDKEY =>
> '', ENCODED => 70236052, TABLE => {{NAME => '-ROOT-', IS_ROOT => 'true',
> IS_META => 'true', FAMILIES => [{NAME => 'info', BLOOMFILTER => 'NONE',
> REPLICATION_SCOPE => '0', VERSIONS => '10', COMPRESSION => 'NONE', TTL =>
> '2147483647', BLOCKSIZE => '8192', IN_MEMORY => 'true', BLOCKCACHE =>
> 'true'}]}}
> 2011-10-18 08:27:34,156 DEBUG org.apache.hadoop.hbase.regionserver.HRegion:
> Instantiated -ROOT-,,0.70236052
> 2011-10-18 08:27:34,269 DEBUG org.apache.hadoop.hbase.regionserver.Store:
> loaded file:/tmp/hbase-hbase/hbase/-ROOT-/70236052/info/2226863419614596666,
> isReference=false, isBulkLoadResult=false, seqid=2, majorCompaction=false
> 2011-10-18 08:27:34,285 DEBUG org.apache.hadoop.hbase.regionserver.Store:
> loaded file:/tmp/hbase-hbase/hbase/-ROOT-/70236052/info/8233054724424930581,
> isReference=false, isBulkLoadResult=false, seqid=5, majorCompaction=false
> 2011-10-18 08:27:34,325 INFO org.apache.hadoop.hbase.regionserver.HRegion:
> Replaying edits from
> file:/tmp/hbase-hbase/hbase/-ROOT-/70236052/recovered.edits/0000000000000000007;
> minSequenceid=5
> 2011-10-18 08:27:34,327 WARN
> org.apache.hadoop.hbase.regionserver.wal.SequenceFileLogReader: Error while
> trying to get accurate file length. Truncation / data loss may occur if
> RegionServers die.
> java.lang.NoSuchMethodException:
> org.apache.hadoop.fs.ChecksumFileSystem$ChecksumFSInputChecker.getFileLength()
> at java.lang.Class.getMethod(Class.java:1605)
> at
> org.apache.hadoop.hbase.regionserver.wal.SequenceFileLogReader$WALReader$WALReaderFSDataInputStream.getPos(SequenceFileLogReader.java:107)
> at org.apache.hadoop.io.SequenceFile$Reader.<init>(SequenceFile.java:1436)
> at org.apache.hadoop.io.SequenceFile$Reader.<init>(SequenceFile.java:1424)
> at org.apache.hadoop.io.SequenceFile$Reader.<init>(SequenceFile.java:1419)
> at
> org.apache.hadoop.hbase.regionserver.wal.SequenceFileLogReader$WALReader.<init>(SequenceFileLogReader.java:57)
> at
> org.apache.hadoop.hbase.regionserver.wal.SequenceFileLogReader.init(SequenceFileLogReader.java:158)
> at org.apache.hadoop.hbase.regionserver.wal.HLog.getReader(HLog.java:575)
> at
> org.apache.hadoop.hbase.regionserver.HRegion.replayRecoveredEdits(HRegion.java:1875)
> at
> org.apache.hadoop.hbase.regionserver.HRegion.replayRecoveredEditsIfAny(HRegion.java:1835)
> at
> org.apache.hadoop.hbase.regionserver.HRegion.initialize(HRegion.java:354)
> at
> org.apache.hadoop.hbase.regionserver.HRegion.openHRegion(HRegion.java:2553)
> at
> org.apache.hadoop.hbase.regionserver.HRegion.openHRegion(HRegion.java:2539)
> at
> org.apache.hadoop.hbase.regionserver.handler.OpenRegionHandler.openRegion(OpenRegionHandler.java:272)
> at
> org.apache.hadoop.hbase.regionserver.handler.OpenRegionHandler.process(OpenRegionHandler.java:99)
> at org.apache.hadoop.hbase.executor.EventHandler.run(EventHandler.java:156)
> at
> java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
> at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
> at java.lang.Thread.run(Thread.java:619)
> 2011-10-18 08:27:34,329 DEBUG org.apache.hadoop.hbase.regionserver.HRegion:
> Applied 2, skipped 0, firstSequenceidInLog=7, maxSequenceidInLog=7
> 2011-10-18 08:27:34,329 DEBUG org.apache.hadoop.hbase.regionserver.HRegion:
> Started memstore flush for -ROOT-,,0.70236052, current region memstore size
> 480.0; wal is null, using passed sequenceid=7
> 2011-10-18 08:27:34,329 DEBUG org.apache.hadoop.hbase.regionserver.HRegion:
> Finished snapshotting, commencing flushing stores
> 2011-10-18 08:27:34,417 INFO org.apache.hadoop.hbase.regionserver.Store:
> Renaming flushed file at
> file:/tmp/hbase-hbase/hbase/-ROOT-/70236052/.tmp/7507925448071592382 to
> file:/tmp/hbase-hbase/hbase/-ROOT-/70236052/info/6152135076013786807
> 2011-10-18 08:27:34,419 INFO org.apache.hadoop.hbase.regionserver.Store:
> Added file:/tmp/hbase-hbase/hbase/-ROOT-/70236052/info/6152135076013786807,
> entries=2, sequenceid=7, memsize=480.0, filesize=514.0
> 2011-10-18 08:27:34,419 INFO org.apache.hadoop.hbase.regionserver.HRegion:
> Finished memstore flush of ~480.0 for region -ROOT-,,0.70236052 in 90ms,
> sequenceid=7, compaction requested=true; wal=null
> 2011-10-18 08:27:34,443 DEBUG org.apache.hadoop.hbase.regionserver.HRegion:
> Deleted recovered.edits
> file=file:/tmp/hbase-hbase/hbase/-ROOT-/70236052/recovered.edits/0000000000000000007
> 2011-10-18 08:27:34,444 INFO org.apache.hadoop.hbase.regionserver.HRegion:
> Onlined -ROOT-,,0.70236052; next sequenceid=8
> 2011-10-18 08:27:34,444 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign:
> regionserver:57754-0x1331700150e0002 Attempting to transition node
> 70236052/-ROOT- from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENING
> 2011-10-18 08:27:34,449 DEBUG
> org.apache.hadoop.hbase.master.AssignmentManager: Handling
> transition=RS_ZK_REGION_OPENING,
> server=localhost.localdomain,57754,1318940844922, region=70236052/-ROOT-
> 2011-10-18 08:27:34,449 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign:
> regionserver:57754-0x1331700150e0002 Successfully transitioned node 70236052
> from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENING
> 2011-10-18 08:27:34,450 INFO
> org.apache.hadoop.hbase.catalog.RootLocationEditor: Setting ROOT region
> location in ZooKeeper as localhost.localdomain:57754
> 2011-10-18 08:27:34,456 INFO org.apache.hadoop.hbase.master.HMaster: -ROOT-
> assigned=1, rit=false, location=localhost.localdomain:57754
> 2011-10-18 08:27:34,473 INFO org.apache.hadoop.ipc.HbaseRPC: Server at
> localhost.localdomain/127.0.0.1:50781 could not be reached after 1 tries,
> giving up.
> 2011-10-18 08:27:34,473 INFO
> org.apache.hadoop.hbase.catalog.CatalogTracker: Passed metaserver is null
> 2011-10-18 08:27:34,473 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign:
> master:49977-0x1331700150e0000 Creating (or updating) unassigned node for
> 1028785192 with OFFLINE state
> 2011-10-18 08:27:34,477 DEBUG
> org.apache.hadoop.hbase.master.AssignmentManager: Handling
> transition=M_ZK_REGION_OFFLINE, server=localhost.localdomain:49977,
> region=1028785192/.META.
> 2011-10-18 08:27:34,478 DEBUG
> org.apache.hadoop.hbase.master.AssignmentManager: No previous transition
> plan was found (or we are ignoring an existing plan) for
> .META.,,1.1028785192 so generated a random one; hri=.META.,,1.1028785192,
> src=, dest=localhost.localdomain,57754,1318940844922; 1 (online=1,
> exclude=null) available servers
> 2011-10-18 08:27:34,478 DEBUG
> org.apache.hadoop.hbase.master.AssignmentManager: Assigning region
> .META.,,1.1028785192 to localhost.localdomain,57754,1318940844922
> 2011-10-18 08:27:34,479 INFO
> org.apache.hadoop.hbase.regionserver.HRegionServer: Received request to open
> region: .META.,,1.1028785192
> 2011-10-18 08:27:34,645 DEBUG
> org.apache.hadoop.hbase.regionserver.handler.OpenRegionHandler: Processing
> open of .META.,,1.1028785192
> 2011-10-18 08:27:34,645 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign:
> regionserver:57754-0x1331700150e0002 Attempting to transition node
> 1028785192/.META. from M_ZK_REGION_OFFLINE to RS_ZK_REGION_OPENING
> 2011-10-18 08:27:34,647 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign:
> regionserver:57754-0x1331700150e0002 Attempting to transition node
> 70236052/-ROOT- from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENED
> 2011-10-18 08:27:34,655 DEBUG
> org.apache.hadoop.hbase.master.AssignmentManager: Handling
> transition=RS_ZK_REGION_OPENING,
> server=localhost.localdomain,57754,1318940844922, region=1028785192/.META.
> 2011-10-18 08:27:34,656 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign:
> regionserver:57754-0x1331700150e0002 Successfully transitioned node
> 1028785192 from M_ZK_REGION_OFFLINE to RS_ZK_REGION_OPENING
> 2011-10-18 08:27:34,656 DEBUG org.apache.hadoop.hbase.regionserver.HRegion:
> Opening region: REGION => {NAME => '.META.,,1', STARTKEY => '', ENDKEY =>
> '', ENCODED => 1028785192, TABLE => {{NAME => '.META.', IS_META => 'true',
> FAMILIES => [{NAME => 'info', BLOOMFILTER => 'NONE', REPLICATION_SCOPE =>
> '0', VERSIONS => '10', COMPRESSION => 'NONE', TTL => '2147483647', BLOCKSIZE
> => '8192', IN_MEMORY => 'true', BLOCKCACHE => 'true'}]}}
> 2011-10-18 08:27:34,657 DEBUG org.apache.hadoop.hbase.regionserver.HRegion:
> Instantiated .META.,,1.1028785192
> 2011-10-18 08:27:34,696 INFO org.apache.hadoop.hbase.regionserver.HRegion:
> Onlined .META.,,1.1028785192; next sequenceid=1
> 2011-10-18 08:27:34,697 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign:
> regionserver:57754-0x1331700150e0002 Attempting to transition node
> 1028785192/.META. from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENING
> 2011-10-18 08:27:34,726 DEBUG
> org.apache.hadoop.hbase.master.AssignmentManager: Handling
> transition=RS_ZK_REGION_OPENED,
> server=localhost.localdomain,57754,1318940844922, region=70236052/-ROOT-
> 2011-10-18 08:27:34,727 DEBUG
> org.apache.hadoop.hbase.master.handler.OpenedRegionHandler: Handling OPENED
> event for 70236052; deleting unassigned node
> 2011-10-18 08:27:34,727 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign:
> master:49977-0x1331700150e0000 Deleting existing unassigned node for
> 70236052 that is in expected state RS_ZK_REGION_OPENED
> 2011-10-18 08:27:34,729 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign:
> regionserver:57754-0x1331700150e0002 Successfully transitioned node 70236052
> from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENED
> 2011-10-18 08:27:34,729 DEBUG
> org.apache.hadoop.hbase.regionserver.handler.OpenRegionHandler: Opened
> -ROOT-,,0.70236052
> 2011-10-18 08:27:34,735 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign:
> master:49977-0x1331700150e0000 Successfully deleted unassigned node for
> region 70236052 in expected state RS_ZK_REGION_OPENED
> 2011-10-18 08:27:34,735 DEBUG
> org.apache.hadoop.hbase.master.handler.OpenedRegionHandler: Opened region
> -ROOT-,,0.70236052 on localhost.localdomain,57754,1318940844922
> 2011-10-18 08:27:34,737 DEBUG
> org.apache.hadoop.hbase.master.AssignmentManager: Handling
> transition=RS_ZK_REGION_OPENING,
> server=localhost.localdomain,57754,1318940844922, region=1028785192/.META.
> 2011-10-18 08:27:34,738 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign:
> regionserver:57754-0x1331700150e0002 Successfully transitioned node
> 1028785192 from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENING
> 2011-10-18 08:27:34,742 INFO org.apache.hadoop.hbase.catalog.MetaEditor:
> Updated row .META.,,1.1028785192 in region -ROOT-,,0 with
> server=localhost.localdomain:57754, startcode=1318940844922
> 2011-10-18 08:27:34,742 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign:
> regionserver:57754-0x1331700150e0002 Attempting to transition node
> 1028785192/.META. from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENED
> 2011-10-18 08:27:34,745 DEBUG
> org.apache.hadoop.hbase.master.AssignmentManager: Handling
> transition=RS_ZK_REGION_OPENED,
> server=localhost.localdomain,57754,1318940844922, region=1028785192/.META.
> 2011-10-18 08:27:34,746 DEBUG
> org.apache.hadoop.hbase.master.handler.OpenedRegionHandler: Handling OPENED
> event for 1028785192; deleting unassigned node
> 2011-10-18 08:27:34,746 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign:
> master:49977-0x1331700150e0000 Deleting existing unassigned node for
> 1028785192 that is in expected state RS_ZK_REGION_OPENED
> 2011-10-18 08:27:34,748 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign:
> regionserver:57754-0x1331700150e0002 Successfully transitioned node
> 1028785192 from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENED
> 2011-10-18 08:27:34,748 DEBUG
> org.apache.hadoop.hbase.regionserver.handler.OpenRegionHandler: Opened
> .META.,,1.1028785192
> 2011-10-18 08:27:34,749 INFO
> org.apache.hadoop.hbase.zookeeper.MetaNodeTracker: Detected completed
> assignment of META, notifying catalog tracker
> 2011-10-18 08:27:34,750 INFO
> org.apache.hadoop.hbase.zookeeper.MetaNodeTracker: Detected completed
> assignment of META, notifying catalog tracker
> 2011-10-18 08:27:34,751 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign:
> master:49977-0x1331700150e0000 Successfully deleted unassigned node for
> region 1028785192 in expected state RS_ZK_REGION_OPENED
> 2011-10-18 08:27:34,751 DEBUG
> org.apache.hadoop.hbase.master.handler.OpenedRegionHandler: Opened region
> .META.,,1.1028785192 on localhost.localdomain,57754,1318940844922
> 2011-10-18 08:27:34,755 INFO org.apache.hadoop.hbase.master.HMaster: .META.
> assigned=2, rit=false, location=localhost.localdomain:57754
> 2011-10-18 08:27:34,755 INFO org.apache.hadoop.hbase.master.HMaster: Master
> startup proceeding: cluster startup
> 2011-10-18 08:27:34,755 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign:
> master:49977-0x1331700150e0000 Deleting any existing unassigned nodes
> 2011-10-18 08:27:35,035 INFO org.apache.hadoop.hbase.master.HMaster: Master
> has completed initialization
> 2011-10-18 08:27:35,038 DEBUG
> org.apache.hadoop.hbase.master.CatalogJanitor: Scanned 0 catalog row(s) and
> gc'd 0 unreferenced parent region(s)
> 2011-10-18 08:28:06,767 INFO org.apache.zookeeper.ZooKeeper: Initiating
> client connection, connectString=localhost:2182 sessionTimeout=180000
> watcher=hconnection
> 2011-10-18 08:28:06,768 INFO org.apache.zookeeper.ClientCnxn: Opening
> socket connection to server localhost/127.0.0.1:2182
> 2011-10-18 08:28:06,768 INFO org.apache.zookeeper.server.NIOServerCnxn:
> Accepted socket connection from /127.0.0.1:48880
> 2011-10-18 08:28:06,769 INFO org.apache.zookeeper.ClientCnxn: Socket
> connection established to localhost/127.0.0.1:2182, initiating session
> 2011-10-18 08:28:06,769 INFO org.apache.zookeeper.server.NIOServerCnxn:
> Client attempting to establish new session at /127.0.0.1:48880
> 2011-10-18 08:28:06,780 INFO org.apache.zookeeper.server.NIOServerCnxn:
> Established session 0x1331700150e0004 with negotiated timeout 40000 for
> client /127.0.0.1:48880
> 2011-10-18 08:28:06,782 INFO org.apache.zookeeper.ClientCnxn: Session
> establishment complete on server localhost/127.0.0.1:2182, sessionid =
> 0x1331700150e0004, negotiated timeout = 40000
> 2011-10-18 08:28:06,800 DEBUG org.apache.hadoop.hbase.client.MetaScanner:
> Scanning .META. starting at row= for max=2147483647 rows
> 2011-10-18 08:28:06,801 DEBUG
> org.apache.hadoop.hbase.client.HConnectionManager$HConnectionImplementation:
> Lookedup root region location,
> connection=org.apache.hadoop.hbase.client.HConnectionManager$HConnectionImplementation@1b4b74a7;
> hsa=localhost.localdomain:57754
> 2011-10-18 08:28:06,822 DEBUG
> org.apache.hadoop.hbase.client.HConnectionManager$HConnectionImplementation:
> Cached location for .META.,,1.1028785192 is localhost.localdomain:57754
> 2011-10-18 08:28:06,824 INFO
> org.apache.hadoop.hbase.client.HConnectionManager$HConnectionImplementation:
> Closed zookeeper sessionid=0x1331700150e0004
> 2011-10-18 08:28:06,824 INFO
> org.apache.zookeeper.server.PrepRequestProcessor: Processed session
> termination for sessionid: 0x1331700150e0004
> 2011-10-18 08:28:06,828 INFO org.apache.zookeeper.server.NIOServerCnxn:
> Closed socket connection for client /127.0.0.1:48880 which had sessionid
> 0x1331700150e0004
> 2011-10-18 08:28:06,829 INFO org.apache.zookeeper.ZooKeeper: Session:
> 0x1331700150e0004 closed
> 2011-10-18 08:28:06,837 INFO org.apache.zookeeper.ClientCnxn: EventThread
> shut down
>
Re: HMaster issues
Posted by Jean-Daniel Cryans <jd...@apache.org>.
This line:
java.lang.NoSuchMethodException:
org.apache.hadoop.fs.ChecksumFileSystem$ChecksumFSInputChecker.getFileLength()
Is because it's using the local filesystem and not HDFS (so it's expected).
As far as I can tell the master starts ok, maybe the client is trying to use
the ZK port 2181? Start the shell with -d and it should show you where it's
connecting.
J-D
On Tue, Oct 18, 2011 at 7:19 AM, Ben West <bw...@yahoo.com> wrote:
> Hey All,
>
> I'm having an issue I can't debug. The shell gives me a
> MasterNotRunningException, but I can connect to the master via the web
> interface. I'm using the Cloudera demo VM, which has a standalone instance
> of HBase.
>
> I'm attaching the HBase-master log file. The only thing I can see is a
> warning that getting a checksum failed, but from the warning that doesn't
> sound very serious.
>
> The only thing in my config file is to change the Zookeeper port since
> there seemed to be a conflict with the default.
>
> Any help would be appreciated,
> -Ben
>
>
> Tue Oct 18 08:27:17 EDT 2011 Starting master on localhost.localdomain
> ulimit -n 1024
> 2011-10-18 08:27:20,631 INFO org.apache.zookeeper.server.ZooKeeperServer:
> Server environment:zookeeper.version=3.3.3-cdh3u1--1, built on 07/30/2011
> 01:29 GMT
> 2011-10-18 08:27:20,631 INFO org.apache.zookeeper.server.ZooKeeperServer:
> Server environment:host.name=localhost.localdomain
> 2011-10-18 08:27:20,631 INFO org.apache.zookeeper.server.ZooKeeperServer:
> Server environment:java.version=1.6.0_21
> 2011-10-18 08:27:20,631 INFO org.apache.zookeeper.server.ZooKeeperServer:
> Server environment:java.vendor=Sun Microsystems Inc.
> 2011-10-18 08:27:20,631 INFO org.apache.zookeeper.server.ZooKeeperServer:
> Server environment:java.home=/usr/java/jdk1.6.0_21/jre
> 2011-10-18 08:27:20,631 INFO org.apache.zookeeper.server.ZooKeeperServer:
> Server
>
> environment:java.class.path=/usr/lib/hbase/bin/../conf:/usr/java/jdk1.6.0_21/lib/tools.jar:/usr/lib/hbase/bin/..:/usr/lib/hbase/bin/../hbase-0.90.3-cdh3u1.jar:/usr/lib/hbase/bin/../hbase-0.90.3-cdh3u1-tests.jar:/usr/lib/hbase/bin/../lib/activation-1.1.jar:/usr/lib/hbase/bin/../lib/asm-3.1.jar:/usr/lib/hbase/bin/../lib/avro-1.3.3.jar:/usr/lib/hbase/bin/../lib/commons-cli-1.2.jar:/usr/lib/hbase/bin/../lib/commons-codec-1.4.jar:/usr/lib/hbase/bin/../lib/commons-el-1.0.jar:/usr/lib/hbase/bin/../lib/commons-httpclient-3.1.jar:/usr/lib/hbase/bin/../lib/commons-lang-2.5.jar:/usr/lib/hbase/bin/../lib/commons-logging-1.1.1.jar:/usr/lib/hbase/bin/../lib/commons-net-1.4.1.jar:/usr/lib/hbase/bin/../lib/core-3.1.1.jar:/usr/lib/hbase/bin/../lib/guava-r06.jar:/usr/lib/hbase/bin/../lib/hadoop-core.jar:/usr/lib/hbase/bin/../lib/jackson-core-asl-1.5.2.jar:/usr/lib/hbase/bin/../lib/jackson-jaxrs-1.5.5.jar:/usr/lib/hbase/bin/../lib/jackson-mapper-asl-1.5.2.jar:/usr/lib/hb
>
> ase/bin/../lib/jackson-xc-1.5.5.jar:/usr/lib/hbase/bin/../lib/jasper-compiler-5.5.23.jar:/usr/lib/hbase/bin/../lib/jasper-runtime-5.5.23.jar:/usr/lib/hbase/bin/../lib/jaxb-api-2.1.jar:/usr/lib/hbase/bin/../lib/jaxb-impl-2.1.12.jar:/usr/lib/hbase/bin/../lib/jersey-core-1.4.jar:/usr/lib/hbase/bin/../lib/jersey-json-1.4.jar:/usr/lib/hbase/bin/../lib/jersey-server-1.4.jar:/usr/lib/hbase/bin/../lib/jettison-1.1.jar:/usr/lib/hbase/bin/../lib/jetty-6.1.26.jar:/usr/lib/hbase/bin/../lib/jetty-util-6.1.26.jar:/usr/lib/hbase/bin/../lib/jruby-complete-1.6.0.jar:/usr/lib/hbase/bin/../lib/jsp-2.1-6.1.14.jar:/usr/lib/hbase/bin/../lib/jsp-api-2.1-6.1.14.jar:/usr/lib/hbase/bin/../lib/jsp-api-2.1.jar:/usr/lib/hbase/bin/../lib/jsr311-api-1.1.1.jar:/usr/lib/hbase/bin/../lib/log4j-1.2.16.jar:/usr/lib/hbase/bin/../lib/protobuf-java-2.3.0.jar:/usr/lib/hbase/bin/../lib/servlet-api-2.5-6.1.14.jar:/usr/lib/hbase/bin/../lib/servlet-api-2.5.jar:/usr/lib/hbase/bin/../lib/slf4j-api-
>
> 1.5.8.jar:/usr/lib/hbase/bin/../lib/slf4j-log4j12-1.5.8.jar:/usr/lib/hbase/bin/../lib/stax-api-1.0.1.jar:/usr/lib/hbase/bin/../lib/thrift-0.2.0.jar:/usr/lib/hbase/bin/../lib/xmlenc-0.52.jar:/usr/lib/hbase/bin/../lib/zookeeper.jar
> 2011-10-18 08:27:20,631 INFO org.apache.zookeeper.server.ZooKeeperServer:
> Server
> environment:java.library.path=/usr/lib/hbase/bin/../lib/native/Linux-amd64-64
> 2011-10-18 08:27:20,631 INFO org.apache.zookeeper.server.ZooKeeperServer:
> Server environment:java.io.tmpdir=/tmp
> 2011-10-18 08:27:20,631 INFO org.apache.zookeeper.server.ZooKeeperServer:
> Server environment:java.compiler=<NA>
> 2011-10-18 08:27:20,631 INFO org.apache.zookeeper.server.ZooKeeperServer:
> Server environment:os.name=Linux
> 2011-10-18 08:27:20,631 INFO org.apache.zookeeper.server.ZooKeeperServer:
> Server environment:os.arch=amd64
> 2011-10-18 08:27:20,631 INFO org.apache.zookeeper.server.ZooKeeperServer:
> Server environment:os.version=2.6.18-238.19.1.el5
> 2011-10-18 08:27:20,631 INFO org.apache.zookeeper.server.ZooKeeperServer:
> Server environment:user.name=hbase
> 2011-10-18 08:27:20,631 INFO org.apache.zookeeper.server.ZooKeeperServer:
> Server environment:user.home=/var/run/hbase
> 2011-10-18 08:27:20,631 INFO org.apache.zookeeper.server.ZooKeeperServer:
> Server environment:user.dir=/
> 2011-10-18 08:27:20,837 INFO org.apache.zookeeper.server.ZooKeeperServer:
> Created server with tickTime 2000 minSessionTimeout 4000 maxSessionTimeout
> 40000 datadir /tmp/hbase-hbase/zookeeper/zookeeper/version-2 snapdir
> /tmp/hbase-hbase/zookeeper/zookeeper/version-2
> 2011-10-18 08:27:21,189 INFO org.apache.zookeeper.server.NIOServerCnxn:
> binding to port 0.0.0.0/0.0.0.0:2182
> 2011-10-18 08:27:21,220 INFO
> org.apache.zookeeper.server.persistence.FileTxnSnapLog: Snapshotting: 0
> 2011-10-18 08:27:21,463 INFO org.apache.zookeeper.server.NIOServerCnxn:
> Accepted socket connection from /127.0.0.1:48821
> 2011-10-18 08:27:21,485 INFO org.apache.zookeeper.server.NIOServerCnxn:
> Processing stat command from /127.0.0.1:48821
> 2011-10-18 08:27:21,488 INFO org.apache.zookeeper.server.NIOServerCnxn:
> Stat command output
> 2011-10-18 08:27:21,488 INFO org.apache.zookeeper.server.NIOServerCnxn:
> Closed socket connection for client /127.0.0.1:48821 (no session
> established for client)
> 2011-10-18 08:27:21,489 INFO
> org.apache.hadoop.hbase.zookeeper.MiniZooKeeperCluster: Started MiniZK
> Server on client port: 2182
> 2011-10-18 08:27:21,939 INFO org.apache.hadoop.hbase.ipc.HBaseRpcMetrics:
> Initializing RPC Metrics with hostName=HMasterCommandLine$LocalHMaster,
> port=49977
> 2011-10-18 08:27:23,849 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server
> Responder: starting
> 2011-10-18 08:27:23,870 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server
> listener on 49977: starting
> 2011-10-18 08:27:23,884 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server
> handler 0 on 49977: starting
> 2011-10-18 08:27:23,885 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server
> handler 1 on 49977: starting
> 2011-10-18 08:27:23,909 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server
> handler 3 on 49977: starting
> 2011-10-18 08:27:23,909 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server
> handler 2 on 49977: starting
> 2011-10-18 08:27:23,910 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server
> handler 4 on 49977: starting
> 2011-10-18 08:27:23,910 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server
> handler 5 on 49977: starting
> 2011-10-18 08:27:23,910 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server
> handler 6 on 49977: starting
> 2011-10-18 08:27:23,911 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server
> handler 7 on 49977: starting
> 2011-10-18 08:27:23,911 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server
> handler 8 on 49977: starting
> 2011-10-18 08:27:23,911 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server
> handler 9 on 49977: starting
> 2011-10-18 08:27:23,951 INFO org.apache.zookeeper.ZooKeeper: Client
> environment:zookeeper.version=3.3.3-cdh3u1--1, built on 07/30/2011 01:29 GMT
> 2011-10-18 08:27:23,951 INFO org.apache.zookeeper.ZooKeeper: Client
> environment:host.name=localhost.localdomain
> 2011-10-18 08:27:23,951 INFO org.apache.zookeeper.ZooKeeper: Client
> environment:java.version=1.6.0_21
> 2011-10-18 08:27:23,951 INFO org.apache.zookeeper.ZooKeeper: Client
> environment:java.vendor=Sun Microsystems Inc.
> 2011-10-18 08:27:23,951 INFO org.apache.zookeeper.ZooKeeper: Client
> environment:java.home=/usr/java/jdk1.6.0_21/jre
> 2011-10-18 08:27:23,951 INFO org.apache.zookeeper.ZooKeeper: Client
>
> environment:java.class.path=/usr/lib/hbase/bin/../conf:/usr/java/jdk1.6.0_21/lib/tools.jar:/usr/lib/hbase/bin/..:/usr/lib/hbase/bin/../hbase-0.90.3-cdh3u1.jar:/usr/lib/hbase/bin/../hbase-0.90.3-cdh3u1-tests.jar:/usr/lib/hbase/bin/../lib/activation-1.1.jar:/usr/lib/hbase/bin/../lib/asm-3.1.jar:/usr/lib/hbase/bin/../lib/avro-1.3.3.jar:/usr/lib/hbase/bin/../lib/commons-cli-1.2.jar:/usr/lib/hbase/bin/../lib/commons-codec-1.4.jar:/usr/lib/hbase/bin/../lib/commons-el-1.0.jar:/usr/lib/hbase/bin/../lib/commons-httpclient-3.1.jar:/usr/lib/hbase/bin/../lib/commons-lang-2.5.jar:/usr/lib/hbase/bin/../lib/commons-logging-1.1.1.jar:/usr/lib/hbase/bin/../lib/commons-net-1.4.1.jar:/usr/lib/hbase/bin/../lib/core-3.1.1.jar:/usr/lib/hbase/bin/../lib/guava-r06.jar:/usr/lib/hbase/bin/../lib/hadoop-core.jar:/usr/lib/hbase/bin/../lib/jackson-core-asl-1.5.2.jar:/usr/lib/hbase/bin/../lib/jackson-jaxrs-1.5.5.jar:/usr/lib/hbase/bin/../lib/jackson-mapper-asl-1.5.2.jar:/usr/lib/hb
>
> ase/bin/../lib/jackson-xc-1.5.5.jar:/usr/lib/hbase/bin/../lib/jasper-compiler-5.5.23.jar:/usr/lib/hbase/bin/../lib/jasper-runtime-5.5.23.jar:/usr/lib/hbase/bin/../lib/jaxb-api-2.1.jar:/usr/lib/hbase/bin/../lib/jaxb-impl-2.1.12.jar:/usr/lib/hbase/bin/../lib/jersey-core-1.4.jar:/usr/lib/hbase/bin/../lib/jersey-json-1.4.jar:/usr/lib/hbase/bin/../lib/jersey-server-1.4.jar:/usr/lib/hbase/bin/../lib/jettison-1.1.jar:/usr/lib/hbase/bin/../lib/jetty-6.1.26.jar:/usr/lib/hbase/bin/../lib/jetty-util-6.1.26.jar:/usr/lib/hbase/bin/../lib/jruby-complete-1.6.0.jar:/usr/lib/hbase/bin/../lib/jsp-2.1-6.1.14.jar:/usr/lib/hbase/bin/../lib/jsp-api-2.1-6.1.14.jar:/usr/lib/hbase/bin/../lib/jsp-api-2.1.jar:/usr/lib/hbase/bin/../lib/jsr311-api-1.1.1.jar:/usr/lib/hbase/bin/../lib/log4j-1.2.16.jar:/usr/lib/hbase/bin/../lib/protobuf-java-2.3.0.jar:/usr/lib/hbase/bin/../lib/servlet-api-2.5-6.1.14.jar:/usr/lib/hbase/bin/../lib/servlet-api-2.5.jar:/usr/lib/hbase/bin/../lib/slf4j-api-
>
> 1.5.8.jar:/usr/lib/hbase/bin/../lib/slf4j-log4j12-1.5.8.jar:/usr/lib/hbase/bin/../lib/stax-api-1.0.1.jar:/usr/lib/hbase/bin/../lib/thrift-0.2.0.jar:/usr/lib/hbase/bin/../lib/xmlenc-0.52.jar:/usr/lib/hbase/bin/../lib/zookeeper.jar
> 2011-10-18 08:27:23,951 INFO org.apache.zookeeper.ZooKeeper: Client
> environment:java.library.path=/usr/lib/hbase/bin/../lib/native/Linux-amd64-64
> 2011-10-18 08:27:23,951 INFO org.apache.zookeeper.ZooKeeper: Client
> environment:java.io.tmpdir=/tmp
> 2011-10-18 08:27:23,951 INFO org.apache.zookeeper.ZooKeeper: Client
> environment:java.compiler=<NA>
> 2011-10-18 08:27:23,951 INFO org.apache.zookeeper.ZooKeeper: Client
> environment:os.name=Linux
> 2011-10-18 08:27:23,951 INFO org.apache.zookeeper.ZooKeeper: Client
> environment:os.arch=amd64
> 2011-10-18 08:27:23,951 INFO org.apache.zookeeper.ZooKeeper: Client
> environment:os.version=2.6.18-238.19.1.el5
> 2011-10-18 08:27:23,951 INFO org.apache.zookeeper.ZooKeeper: Client
> environment:user.name=hbase
> 2011-10-18 08:27:23,951 INFO org.apache.zookeeper.ZooKeeper: Client
> environment:user.home=/var/run/hbase
> 2011-10-18 08:27:23,951 INFO org.apache.zookeeper.ZooKeeper: Client
> environment:user.dir=/
> 2011-10-18 08:27:23,952 INFO org.apache.zookeeper.ZooKeeper: Initiating
> client connection, connectString=localhost:2182 sessionTimeout=180000
> watcher=master:49977
> 2011-10-18 08:27:24,009 INFO org.apache.zookeeper.ClientCnxn: Opening
> socket connection to server localhost/127.0.0.1:2182
> 2011-10-18 08:27:24,047 INFO org.apache.zookeeper.server.NIOServerCnxn:
> Accepted socket connection from /127.0.0.1:48824
> 2011-10-18 08:27:24,047 INFO org.apache.zookeeper.ClientCnxn: Socket
> connection established to localhost/127.0.0.1:2182, initiating session
> 2011-10-18 08:27:24,064 INFO org.apache.zookeeper.server.NIOServerCnxn:
> Client attempting to establish new session at /127.0.0.1:48824
> 2011-10-18 08:27:24,066 INFO
> org.apache.zookeeper.server.persistence.FileTxnLog: Creating new log file:
> log.1
> 2011-10-18 08:27:24,092 INFO org.apache.zookeeper.server.NIOServerCnxn:
> Established session 0x1331700150e0000 with negotiated timeout 40000 for
> client /127.0.0.1:48824
> 2011-10-18 08:27:24,097 INFO org.apache.zookeeper.ClientCnxn: Session
> establishment complete on server localhost/127.0.0.1:2182, sessionid =
> 0x1331700150e0000, negotiated timeout = 40000
> 2011-10-18 08:27:24,111 INFO org.apache.hadoop.metrics.jvm.JvmMetrics:
> Initializing JVM Metrics with processName=Master,
> sessionId=localhost.localdomain:49977
> 2011-10-18 08:27:24,131 INFO org.apache.hadoop.hbase.metrics: MetricsString
> added: revision
> 2011-10-18 08:27:24,131 INFO org.apache.hadoop.hbase.metrics: MetricsString
> added: hdfsUser
> 2011-10-18 08:27:24,131 INFO org.apache.hadoop.hbase.metrics: MetricsString
> added: hdfsDate
> 2011-10-18 08:27:24,131 INFO org.apache.hadoop.hbase.metrics: MetricsString
> added: hdfsUrl
> 2011-10-18 08:27:24,131 INFO org.apache.hadoop.hbase.metrics: MetricsString
> added: date
> 2011-10-18 08:27:24,131 INFO org.apache.hadoop.hbase.metrics: MetricsString
> added: hdfsRevision
> 2011-10-18 08:27:24,131 INFO org.apache.hadoop.hbase.metrics: MetricsString
> added: user
> 2011-10-18 08:27:24,131 INFO org.apache.hadoop.hbase.metrics: MetricsString
> added: hdfsVersion
> 2011-10-18 08:27:24,131 INFO org.apache.hadoop.hbase.metrics: MetricsString
> added: url
> 2011-10-18 08:27:24,131 INFO org.apache.hadoop.hbase.metrics: MetricsString
> added: version
> 2011-10-18 08:27:24,131 INFO org.apache.hadoop.hbase.metrics: new MBeanInfo
> 2011-10-18 08:27:24,131 INFO org.apache.hadoop.hbase.metrics: new MBeanInfo
> 2011-10-18 08:27:24,132 INFO
> org.apache.hadoop.hbase.master.metrics.MasterMetrics: Initialized
> 2011-10-18 08:27:24,508 INFO org.apache.zookeeper.ZooKeeper: Initiating
> client connection, connectString=localhost:2182 sessionTimeout=180000
> watcher=hconnection
> 2011-10-18 08:27:24,508 INFO org.apache.zookeeper.ClientCnxn: Opening
> socket connection to server localhost/127.0.0.1:2182
> 2011-10-18 08:27:24,527 INFO org.apache.zookeeper.server.NIOServerCnxn:
> Accepted socket connection from /127.0.0.1:48825
> 2011-10-18 08:27:24,528 INFO org.apache.zookeeper.ClientCnxn: Socket
> connection established to localhost/127.0.0.1:2182, initiating session
> 2011-10-18 08:27:24,528 INFO org.apache.zookeeper.server.NIOServerCnxn:
> Client attempting to establish new session at /127.0.0.1:48825
> 2011-10-18 08:27:24,537 INFO org.apache.zookeeper.server.NIOServerCnxn:
> Established session 0x1331700150e0001 with negotiated timeout 40000 for
> client /127.0.0.1:48825
> 2011-10-18 08:27:24,539 INFO org.apache.zookeeper.ClientCnxn: Session
> establishment complete on server localhost/127.0.0.1:2182, sessionid =
> 0x1331700150e0001, negotiated timeout = 40000
> 2011-10-18 08:27:24,727 INFO org.apache.hadoop.hbase.ipc.HBaseRpcMetrics:
> Initializing RPC Metrics with hostName=HRegionServer, port=57754
> 2011-10-18 08:27:25,093 INFO org.apache.zookeeper.ZooKeeper: Initiating
> client connection, connectString=localhost:2182 sessionTimeout=180000
> watcher=regionserver:57754
> 2011-10-18 08:27:25,093 INFO
> org.apache.hadoop.hbase.master.ActiveMasterManager:
> Master=localhost.localdomain:49977
> 2011-10-18 08:27:25,107 INFO org.apache.zookeeper.ClientCnxn: Opening
> socket connection to server localhost/127.0.0.1:2182
> 2011-10-18 08:27:25,107 INFO org.apache.zookeeper.server.NIOServerCnxn:
> Accepted socket connection from /127.0.0.1:48826
> 2011-10-18 08:27:25,109 INFO org.apache.zookeeper.ClientCnxn: Socket
> connection established to localhost/127.0.0.1:2182, initiating session
> 2011-10-18 08:27:25,109 INFO org.apache.zookeeper.server.NIOServerCnxn:
> Client attempting to establish new session at /127.0.0.1:48826
> 2011-10-18 08:27:25,113 INFO org.apache.zookeeper.server.NIOServerCnxn:
> Established session 0x1331700150e0002 with negotiated timeout 40000 for
> client /127.0.0.1:48826
> 2011-10-18 08:27:25,117 INFO org.apache.zookeeper.ClientCnxn: Session
> establishment complete on server localhost/127.0.0.1:2182, sessionid =
> 0x1331700150e0002, negotiated timeout = 40000
> 2011-10-18 08:27:26,071 INFO org.apache.zookeeper.ZooKeeper: Initiating
> client connection, connectString=localhost:2182 sessionTimeout=180000
> watcher=hconnection
> 2011-10-18 08:27:26,072 INFO org.apache.zookeeper.ClientCnxn: Opening
> socket connection to server localhost/127.0.0.1:2182
> 2011-10-18 08:27:26,072 INFO org.apache.zookeeper.server.NIOServerCnxn:
> Accepted socket connection from /127.0.0.1:48827
> 2011-10-18 08:27:26,072 INFO org.apache.zookeeper.ClientCnxn: Socket
> connection established to localhost/127.0.0.1:2182, initiating session
> 2011-10-18 08:27:26,073 INFO org.apache.zookeeper.server.NIOServerCnxn:
> Client attempting to establish new session at /127.0.0.1:48827
> 2011-10-18 08:27:26,078 INFO org.apache.zookeeper.server.NIOServerCnxn:
> Established session 0x1331700150e0003 with negotiated timeout 40000 for
> client /127.0.0.1:48827
> 2011-10-18 08:27:26,080 INFO org.apache.zookeeper.ClientCnxn: Session
> establishment complete on server localhost/127.0.0.1:2182, sessionid =
> 0x1331700150e0003, negotiated timeout = 40000
> 2011-10-18 08:27:26,148 DEBUG
> org.apache.hadoop.hbase.catalog.CatalogTracker: Starting catalog tracker
> org.apache.hadoop.hbase.catalog.CatalogTracker@7f5d3388
> 2011-10-18 08:27:26,212 DEBUG
> org.apache.hadoop.hbase.catalog.CatalogTracker: Starting catalog tracker
> org.apache.hadoop.hbase.catalog.CatalogTracker@342798e7
> 2011-10-18 08:27:26,217 INFO
> org.apache.hadoop.hbase.regionserver.MemStoreFlusher:
> globalMemStoreLimit=399.2m, globalMemStoreLimitLowMark=349.3m,
> maxHeap=997.9m
> 2011-10-18 08:27:26,219 DEBUG
> org.apache.hadoop.hbase.regionserver.PriorityCompactionQueue: Create
> PriorityCompactionQueue
> 2011-10-18 08:27:26,219 INFO
> org.apache.hadoop.hbase.regionserver.HRegionServer: Runs every 10000000ms
> 2011-10-18 08:27:26,294 INFO
> org.apache.hadoop.hbase.regionserver.HRegionServer: Attempting connect to
> Master server at localhost.localdomain:49977
> 2011-10-18 08:27:26,344 INFO
> org.apache.hadoop.hbase.regionserver.HRegionServer: Master isn't available
> yet, retrying
> 2011-10-18 08:27:26,348 INFO org.apache.hadoop.hbase.master.HMaster: Server
> active/primary master; localhost.localdomain:49977,
> sessionid=0x1331700150e0000, cluster-up flag was=false
> 2011-10-18 08:27:26,349 DEBUG
> org.apache.hadoop.hbase.executor.ExecutorService: Starting executor service
> name=MASTER_OPEN_REGION-localhost.localdomain:49977, corePoolSize=5,
> maxPoolSize=5
> 2011-10-18 08:27:26,349 DEBUG
> org.apache.hadoop.hbase.executor.ExecutorService: Starting executor service
> name=MASTER_CLOSE_REGION-localhost.localdomain:49977, corePoolSize=5,
> maxPoolSize=5
> 2011-10-18 08:27:26,349 DEBUG
> org.apache.hadoop.hbase.executor.ExecutorService: Starting executor service
> name=MASTER_SERVER_OPERATIONS-localhost.localdomain:49977, corePoolSize=3,
> maxPoolSize=3
> 2011-10-18 08:27:26,349 DEBUG
> org.apache.hadoop.hbase.executor.ExecutorService: Starting executor service
> name=MASTER_META_SERVER_OPERATIONS-localhost.localdomain:49977,
> corePoolSize=5, maxPoolSize=5
> 2011-10-18 08:27:26,349 DEBUG
> org.apache.hadoop.hbase.executor.ExecutorService: Starting executor service
> name=MASTER_TABLE_OPERATIONS-localhost.localdomain:49977, corePoolSize=1,
> maxPoolSize=1
> 2011-10-18 08:27:26,351 DEBUG org.apache.hadoop.hbase.master.LogCleaner:
> Add log cleaner in chain:
> org.apache.hadoop.hbase.master.TimeToLiveLogCleaner
> 2011-10-18 08:27:26,739 INFO org.mortbay.log: Logging to
> org.slf4j.impl.Log4jLoggerAdapter(org.mortbay.log) via
> org.mortbay.log.Slf4jLog
> 2011-10-18 08:27:26,832 INFO org.apache.hadoop.http.HttpServer: Added
> global filtersafety
> (class=org.apache.hadoop.http.HttpServer$QuotingInputFilter)
> 2011-10-18 08:27:26,838 INFO org.apache.hadoop.http.HttpServer: Port
> returned by webServer.getConnectors()[0].getLocalPort() before open() is -1.
> Opening the listener on 60010
> 2011-10-18 08:27:26,838 INFO org.apache.hadoop.http.HttpServer:
> listener.getLocalPort() returned 60010
> webServer.getConnectors()[0].getLocalPort() returned 60010
> 2011-10-18 08:27:26,838 INFO org.apache.hadoop.http.HttpServer: Jetty bound
> to port 60010
> 2011-10-18 08:27:26,838 INFO org.mortbay.log: jetty-6.1.26
> 2011-10-18 08:27:27,019 WARN org.mortbay.log: Can't reuse
> /tmp/Jetty_0_0_0_0_60010_master____q3nwom, using
> /tmp/Jetty_0_0_0_0_60010_master____q3nwom_3288413844900815841
> 2011-10-18 08:27:27,877 INFO org.mortbay.log: Started
> SelectChannelConnector@0.0.0.0:60010
> 2011-10-18 08:27:27,877 DEBUG org.apache.hadoop.hbase.master.HMaster:
> Started service threads
> 2011-10-18 08:27:29,348 INFO
> org.apache.hadoop.hbase.regionserver.HRegionServer: Attempting connect to
> Master server at localhost.localdomain:49977
> 2011-10-18 08:27:29,356 INFO
> org.apache.hadoop.hbase.regionserver.HRegionServer: Connected to master at
> localhost.localdomain:49977
> 2011-10-18 08:27:29,359 INFO
> org.apache.hadoop.hbase.regionserver.HRegionServer: Telling master at
> localhost.localdomain:49977 that we are up
> 2011-10-18 08:27:29,364 INFO org.apache.hadoop.hbase.master.ServerManager:
> Registering server=localhost.localdomain,57754,1318940844922, regionCount=0,
> userLoad=false
> 2011-10-18 08:27:29,373 INFO
> org.apache.hadoop.hbase.regionserver.HRegionServer: Master passed us address
> to use. Was=localhost.localdomain:57754, Now=localhost.localdomain:57754
> 2011-10-18 08:27:29,373 DEBUG
> org.apache.hadoop.hbase.regionserver.HRegionServer: Config from master:
> fs.default.name=file:///
> 2011-10-18 08:27:29,373 DEBUG
> org.apache.hadoop.hbase.regionserver.HRegionServer: Config from master:
> hbase.rootdir=file:///tmp/hbase-hbase/hbase
> 2011-10-18 08:27:29,376 DEBUG
> org.apache.hadoop.hbase.regionserver.HRegionServer:
> logdir=file:/tmp/hbase-hbase/hbase/.logs/localhost.localdomain,57754,1318940844922
> 2011-10-18 08:27:29,380 INFO org.apache.hadoop.hbase.master.ServerManager:
> Waiting on regionserver(s) count to settle; currently=1
> 2011-10-18 08:27:29,399 INFO org.apache.hadoop.hbase.regionserver.wal.HLog:
> HLog configuration: blocksize=32 MB, rollsize=30.4 MB, enabled=true,
> flushlogentries=1, optionallogflushinternal=1000ms
> 2011-10-18 08:27:29,450 WARN org.apache.hadoop.util.NativeCodeLoader:
> Unable to load native-hadoop library for your platform... using builtin-java
> classes where applicable
> 2011-10-18 08:27:29,496 INFO
> org.apache.hadoop.hbase.regionserver.wal.SequenceFileLogWriter: syncFs --
> HDFS-200 -- not available, dfs.support.append=false
> 2011-10-18 08:27:29,497 INFO org.apache.hadoop.hbase.regionserver.wal.HLog:
> New hlog
> /tmp/hbase-hbase/hbase/.logs/localhost.localdomain,57754,1318940844922/localhost.localdomain%3A57754.1318940849409
> 2011-10-18 08:27:29,497 INFO org.apache.hadoop.hbase.regionserver.wal.HLog:
> getNumCurrentReplicas--HDFS-826 not available;
> hdfs_out=org.apache.hadoop.fs.ChecksumFileSystem$ChecksumFSOutputSummer@381eb0c6,
> exception=org.apache.hadoop.fs.ChecksumFileSystem$ChecksumFSOutputSummer.getNumCurrentReplicas()
> 2011-10-18 08:27:29,506 INFO org.apache.hadoop.metrics.jvm.JvmMetrics:
> Cannot initialize JVM Metrics with processName=RegionServer,
> sessionId=RegionServer:0;localhost.localdomain,57754,1318940844922 - already
> initialized
> 2011-10-18 08:27:29,509 INFO org.apache.hadoop.hbase.metrics: new MBeanInfo
> 2011-10-18 08:27:29,510 INFO
> org.apache.hadoop.hbase.regionserver.metrics.RegionServerMetrics:
> Initialized
> 2011-10-18 08:27:29,511 DEBUG
> org.apache.hadoop.hbase.executor.ExecutorService: Starting executor service
> name=RS_OPEN_REGION-localhost.localdomain,57754,1318940844922,
> corePoolSize=3, maxPoolSize=3
> 2011-10-18 08:27:29,512 DEBUG
> org.apache.hadoop.hbase.executor.ExecutorService: Starting executor service
> name=RS_OPEN_ROOT-localhost.localdomain,57754,1318940844922, corePoolSize=1,
> maxPoolSize=1
> 2011-10-18 08:27:29,512 DEBUG
> org.apache.hadoop.hbase.executor.ExecutorService: Starting executor service
> name=RS_OPEN_META-localhost.localdomain,57754,1318940844922, corePoolSize=1,
> maxPoolSize=1
> 2011-10-18 08:27:29,512 DEBUG
> org.apache.hadoop.hbase.executor.ExecutorService: Starting executor service
> name=RS_CLOSE_REGION-localhost.localdomain,57754,1318940844922,
> corePoolSize=3, maxPoolSize=3
> 2011-10-18 08:27:29,512 DEBUG
> org.apache.hadoop.hbase.executor.ExecutorService: Starting executor service
> name=RS_CLOSE_ROOT-localhost.localdomain,57754,1318940844922,
> corePoolSize=1, maxPoolSize=1
> 2011-10-18 08:27:29,512 DEBUG
> org.apache.hadoop.hbase.executor.ExecutorService: Starting executor service
> name=RS_CLOSE_META-localhost.localdomain,57754,1318940844922,
> corePoolSize=1, maxPoolSize=1
> 2011-10-18 08:27:29,699 INFO org.apache.hadoop.http.HttpServer: Added
> global filtersafety
> (class=org.apache.hadoop.http.HttpServer$QuotingInputFilter)
> 2011-10-18 08:27:29,700 INFO org.apache.hadoop.http.HttpServer: Port
> returned by webServer.getConnectors()[0].getLocalPort() before open() is -1.
> Opening the listener on 60030
> 2011-10-18 08:27:29,700 INFO org.apache.hadoop.http.HttpServer:
> listener.getLocalPort() returned 60030
> webServer.getConnectors()[0].getLocalPort() returned 60030
> 2011-10-18 08:27:29,700 INFO org.apache.hadoop.http.HttpServer: Jetty bound
> to port 60030
> 2011-10-18 08:27:29,700 INFO org.mortbay.log: jetty-6.1.26
> 2011-10-18 08:27:29,715 WARN org.mortbay.log: Can't reuse
> /tmp/Jetty_0_0_0_0_60030_regionserver____.h599vl, using
> /tmp/Jetty_0_0_0_0_60030_regionserver____.h599vl_2500151639767017676
> 2011-10-18 08:27:30,234 INFO org.mortbay.log: Started
> SelectChannelConnector@0.0.0.0:60030
> 2011-10-18 08:27:30,236 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server
> Responder: starting
> 2011-10-18 08:27:30,236 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server
> listener on 57754: starting
> 2011-10-18 08:27:30,236 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server
> handler 0 on 57754: starting
> 2011-10-18 08:27:30,236 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server
> handler 1 on 57754: starting
> 2011-10-18 08:27:30,236 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server
> handler 2 on 57754: starting
> 2011-10-18 08:27:30,258 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server
> handler 4 on 57754: starting
> 2011-10-18 08:27:30,258 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server
> handler 5 on 57754: starting
> 2011-10-18 08:27:30,261 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server
> handler 3 on 57754: starting
> 2011-10-18 08:27:30,283 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server
> handler 7 on 57754: starting
> 2011-10-18 08:27:30,284 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server
> handler 8 on 57754: starting
> 2011-10-18 08:27:30,284 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server
> handler 6 on 57754: starting
> 2011-10-18 08:27:30,284 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server
> handler 9 on 57754: starting
> 2011-10-18 08:27:30,284 INFO org.apache.hadoop.ipc.HBaseServer: PRI IPC
> Server handler 0 on 57754: starting
> 2011-10-18 08:27:30,298 INFO org.apache.hadoop.ipc.HBaseServer: PRI IPC
> Server handler 1 on 57754: starting
> 2011-10-18 08:27:30,298 INFO org.apache.hadoop.ipc.HBaseServer: PRI IPC
> Server handler 2 on 57754: starting
> 2011-10-18 08:27:30,299 INFO org.apache.hadoop.ipc.HBaseServer: PRI IPC
> Server handler 3 on 57754: starting
> 2011-10-18 08:27:30,322 INFO org.apache.hadoop.ipc.HBaseServer: PRI IPC
> Server handler 4 on 57754: starting
> 2011-10-18 08:27:30,369 INFO org.apache.hadoop.ipc.HBaseServer: PRI IPC
> Server handler 5 on 57754: starting
> 2011-10-18 08:27:30,370 INFO org.apache.hadoop.ipc.HBaseServer: PRI IPC
> Server handler 6 on 57754: starting
> 2011-10-18 08:27:30,371 INFO org.apache.hadoop.ipc.HBaseServer: PRI IPC
> Server handler 7 on 57754: starting
> 2011-10-18 08:27:30,371 INFO org.apache.hadoop.ipc.HBaseServer: PRI IPC
> Server handler 8 on 57754: starting
> 2011-10-18 08:27:30,371 INFO
> org.apache.hadoop.hbase.regionserver.HRegionServer: Serving as
> localhost.localdomain,57754,1318940844922, RPC listening on /
> 127.0.0.1:57754, sessionid=0x1331700150e0002
> 2011-10-18 08:27:30,372 INFO org.apache.hadoop.ipc.HBaseServer: PRI IPC
> Server handler 9 on 57754: starting
> 2011-10-18 08:27:30,524 INFO
> org.apache.hadoop.hbase.regionserver.StoreFile: Allocating LruBlockCache
> with maximum size 199.6m
> 2011-10-18 08:27:30,883 INFO org.apache.hadoop.hbase.master.ServerManager:
> Waiting on regionserver(s) count to settle; currently=1
> 2011-10-18 08:27:32,385 INFO org.apache.hadoop.hbase.master.ServerManager:
> Finished waiting for regionserver count to settle; count=1, sleptFor=4500
> 2011-10-18 08:27:32,385 INFO org.apache.hadoop.hbase.master.ServerManager:
> Exiting wait on regionserver(s) to checkin; count=1, stopped=false, count of
> regions out on cluster=0
> 2011-10-18 08:27:32,388 INFO
> org.apache.hadoop.hbase.master.MasterFileSystem: Log folder
> file:/tmp/hbase-hbase/hbase/.logs/localhost.localdomain,57754,1318940844922
> belongs to an existing region server
> 2011-10-18 08:27:32,388 INFO
> org.apache.hadoop.hbase.master.MasterFileSystem: Log folder
> file:/tmp/hbase-hbase/hbase/.logs/localhost.localdomain,50781,1318937790362
> doesn't belong to a known region server, splitting
> 2011-10-18 08:27:32,428 INFO
> org.apache.hadoop.hbase.regionserver.wal.HLogSplitter: Splitting 1 hlog(s)
> in
> file:/tmp/hbase-hbase/hbase/.logs/localhost.localdomain,50781,1318937790362
> 2011-10-18 08:27:32,429 DEBUG
> org.apache.hadoop.hbase.regionserver.wal.HLogSplitter: Writer thread
> Thread[WriterThread-0,5,main]: starting
> 2011-10-18 08:27:32,434 DEBUG
> org.apache.hadoop.hbase.regionserver.wal.HLogSplitter: Splitting hlog 1 of
> 1:
> file:/tmp/hbase-hbase/hbase/.logs/localhost.localdomain,50781,1318937790362/localhost.localdomain%3A50781.1318937795015,
> length=307
> 2011-10-18 08:27:32,435 WARN org.apache.hadoop.hbase.util.FSUtils: Running
> on HDFS without append enabled may result in data loss
> 2011-10-18 08:27:32,440 DEBUG
> org.apache.hadoop.hbase.regionserver.wal.HLogSplitter: Writer thread
> Thread[WriterThread-2,5,main]: starting
> 2011-10-18 08:27:32,443 DEBUG
> org.apache.hadoop.hbase.regionserver.wal.HLogSplitter: Writer thread
> Thread[WriterThread-1,5,main]: starting
> 2011-10-18 08:27:32,454 WARN
> org.apache.hadoop.hbase.regionserver.wal.SequenceFileLogReader: Error while
> trying to get accurate file length. Truncation / data loss may occur if
> RegionServers die.
> java.lang.NoSuchMethodException:
> org.apache.hadoop.fs.ChecksumFileSystem$ChecksumFSInputChecker.getFileLength()
> at java.lang.Class.getMethod(Class.java:1605)
> at
> org.apache.hadoop.hbase.regionserver.wal.SequenceFileLogReader$WALReader$WALReaderFSDataInputStream.getPos(SequenceFileLogReader.java:107)
> at org.apache.hadoop.io.SequenceFile$Reader.<init>(SequenceFile.java:1436)
> at org.apache.hadoop.io.SequenceFile$Reader.<init>(SequenceFile.java:1424)
> at org.apache.hadoop.io.SequenceFile$Reader.<init>(SequenceFile.java:1419)
> at
> org.apache.hadoop.hbase.regionserver.wal.SequenceFileLogReader$WALReader.<init>(SequenceFileLogReader.java:57)
> at
> org.apache.hadoop.hbase.regionserver.wal.SequenceFileLogReader.init(SequenceFileLogReader.java:158)
> at org.apache.hadoop.hbase.regionserver.wal.HLog.getReader(HLog.java:575)
> at
> org.apache.hadoop.hbase.regionserver.wal.HLogSplitter.getReader(HLogSplitter.java:477)
> at
> org.apache.hadoop.hbase.regionserver.wal.HLogSplitter.parseHLog(HLogSplitter.java:414)
> at
> org.apache.hadoop.hbase.regionserver.wal.HLogSplitter.splitLog(HLogSplitter.java:262)
> at
> org.apache.hadoop.hbase.regionserver.wal.HLogSplitter.splitLog(HLogSplitter.java:188)
> at
> org.apache.hadoop.hbase.master.MasterFileSystem.splitLog(MasterFileSystem.java:197)
> at
> org.apache.hadoop.hbase.master.MasterFileSystem.splitLogAfterStartup(MasterFileSystem.java:181)
> at
> org.apache.hadoop.hbase.master.HMaster.finishInitialization(HMaster.java:385)
> at org.apache.hadoop.hbase.master.HMaster.run(HMaster.java:283)
> at
> org.apache.hadoop.hbase.master.HMasterCommandLine$LocalHMaster.run(HMasterCommandLine.java:193)
> at java.lang.Thread.run(Thread.java:619)
> 2011-10-18 08:27:33,063 DEBUG
> org.apache.hadoop.hbase.regionserver.wal.HLogSplitter: Pushed=1 entries from
> file:/tmp/hbase-hbase/hbase/.logs/localhost.localdomain,50781,1318937790362/localhost.localdomain%3A50781.1318937795015
> 2011-10-18 08:27:33,069 INFO
> org.apache.hadoop.hbase.regionserver.wal.HLogSplitter: Archived processed
> log
> file:/tmp/hbase-hbase/hbase/.logs/localhost.localdomain,50781,1318937790362/localhost.localdomain%3A50781.1318937795015
> to
> file:/tmp/hbase-hbase/hbase/.oldlogs/localhost.localdomain%3A50781.1318937795015
> 2011-10-18 08:27:33,069 INFO
> org.apache.hadoop.hbase.regionserver.wal.HLogSplitter: Waiting for split
> writer threads to finish
> 2011-10-18 08:27:33,078 INFO
> org.apache.hadoop.hbase.regionserver.wal.SequenceFileLogWriter: syncFs --
> HDFS-200 -- not available, dfs.support.append=false
> 2011-10-18 08:27:33,079 DEBUG
> org.apache.hadoop.hbase.regionserver.wal.HLogSplitter: Creating writer
> path=file:/tmp/hbase-hbase/hbase/-ROOT-/70236052/recovered.edits/0000000000000000007
> region=70236052
> 2011-10-18 08:27:33,079 INFO
> org.apache.hadoop.hbase.regionserver.wal.HLogSplitter: Split writers
> finished
> 2011-10-18 08:27:33,080 INFO
> org.apache.hadoop.hbase.regionserver.wal.HLogSplitter: Closed path
> file:/tmp/hbase-hbase/hbase/-ROOT-/70236052/recovered.edits/0000000000000000007
> (wrote 1 edits in 17ms)
> 2011-10-18 08:27:33,080 INFO
> org.apache.hadoop.hbase.regionserver.wal.HLogSplitter: hlog file splitting
> completed in 657 ms for
> file:/tmp/hbase-hbase/hbase/.logs/localhost.localdomain,50781,1318937790362
> 2011-10-18 08:27:34,087 INFO
> org.apache.hadoop.hbase.catalog.RootLocationEditor: Unsetting ROOT region
> location in ZooKeeper
> 2011-10-18 08:27:34,089 INFO
> org.apache.zookeeper.server.PrepRequestProcessor: Got user-level
> KeeperException when processing sessionid:0x1331700150e0000 type:delete
> cxid:0x15 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error
> Path:/hbase/root-region-server Error:KeeperErrorCode = NoNode for
> /hbase/root-region-server
> 2011-10-18 08:27:34,092 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign:
> master:49977-0x1331700150e0000 Creating (or updating) unassigned node for
> 70236052 with OFFLINE state
> 2011-10-18 08:27:34,098 DEBUG
> org.apache.hadoop.hbase.master.AssignmentManager: No previous transition
> plan was found (or we are ignoring an existing plan) for -ROOT-,,0.70236052
> so generated a random one; hri=-ROOT-,,0.70236052, src=,
> dest=localhost.localdomain,57754,1318940844922; 1 (online=1, exclude=null)
> available servers
> 2011-10-18 08:27:34,098 DEBUG
> org.apache.hadoop.hbase.master.AssignmentManager: Assigning region
> -ROOT-,,0.70236052 to localhost.localdomain,57754,1318940844922
> 2011-10-18 08:27:34,098 DEBUG org.apache.hadoop.hbase.master.ServerManager:
> New connection to localhost.localdomain,57754,1318940844922
> 2011-10-18 08:27:34,131 INFO
> org.apache.hadoop.hbase.regionserver.HRegionServer: Received request to open
> region: -ROOT-,,0.70236052
> 2011-10-18 08:27:34,145 DEBUG
> org.apache.hadoop.hbase.regionserver.handler.OpenRegionHandler: Processing
> open of -ROOT-,,0.70236052
> 2011-10-18 08:27:34,146 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign:
> regionserver:57754-0x1331700150e0002 Attempting to transition node
> 70236052/-ROOT- from M_ZK_REGION_OFFLINE to RS_ZK_REGION_OPENING
> 2011-10-18 08:27:34,153 DEBUG
> org.apache.hadoop.hbase.master.AssignmentManager: Handling
> transition=RS_ZK_REGION_OPENING,
> server=localhost.localdomain,57754,1318940844922, region=70236052/-ROOT-
> 2011-10-18 08:27:34,154 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign:
> regionserver:57754-0x1331700150e0002 Successfully transitioned node 70236052
> from M_ZK_REGION_OFFLINE to RS_ZK_REGION_OPENING
> 2011-10-18 08:27:34,155 DEBUG org.apache.hadoop.hbase.regionserver.HRegion:
> Opening region: REGION => {NAME => '-ROOT-,,0', STARTKEY => '', ENDKEY =>
> '', ENCODED => 70236052, TABLE => {{NAME => '-ROOT-', IS_ROOT => 'true',
> IS_META => 'true', FAMILIES => [{NAME => 'info', BLOOMFILTER => 'NONE',
> REPLICATION_SCOPE => '0', VERSIONS => '10', COMPRESSION => 'NONE', TTL =>
> '2147483647', BLOCKSIZE => '8192', IN_MEMORY => 'true', BLOCKCACHE =>
> 'true'}]}}
> 2011-10-18 08:27:34,156 DEBUG org.apache.hadoop.hbase.regionserver.HRegion:
> Instantiated -ROOT-,,0.70236052
> 2011-10-18 08:27:34,269 DEBUG org.apache.hadoop.hbase.regionserver.Store:
> loaded file:/tmp/hbase-hbase/hbase/-ROOT-/70236052/info/2226863419614596666,
> isReference=false, isBulkLoadResult=false, seqid=2, majorCompaction=false
> 2011-10-18 08:27:34,285 DEBUG org.apache.hadoop.hbase.regionserver.Store:
> loaded file:/tmp/hbase-hbase/hbase/-ROOT-/70236052/info/8233054724424930581,
> isReference=false, isBulkLoadResult=false, seqid=5, majorCompaction=false
> 2011-10-18 08:27:34,325 INFO org.apache.hadoop.hbase.regionserver.HRegion:
> Replaying edits from
> file:/tmp/hbase-hbase/hbase/-ROOT-/70236052/recovered.edits/0000000000000000007;
> minSequenceid=5
> 2011-10-18 08:27:34,327 WARN
> org.apache.hadoop.hbase.regionserver.wal.SequenceFileLogReader: Error while
> trying to get accurate file length. Truncation / data loss may occur if
> RegionServers die.
> java.lang.NoSuchMethodException:
> org.apache.hadoop.fs.ChecksumFileSystem$ChecksumFSInputChecker.getFileLength()
> at java.lang.Class.getMethod(Class.java:1605)
> at
> org.apache.hadoop.hbase.regionserver.wal.SequenceFileLogReader$WALReader$WALReaderFSDataInputStream.getPos(SequenceFileLogReader.java:107)
> at org.apache.hadoop.io.SequenceFile$Reader.<init>(SequenceFile.java:1436)
> at org.apache.hadoop.io.SequenceFile$Reader.<init>(SequenceFile.java:1424)
> at org.apache.hadoop.io.SequenceFile$Reader.<init>(SequenceFile.java:1419)
> at
> org.apache.hadoop.hbase.regionserver.wal.SequenceFileLogReader$WALReader.<init>(SequenceFileLogReader.java:57)
> at
> org.apache.hadoop.hbase.regionserver.wal.SequenceFileLogReader.init(SequenceFileLogReader.java:158)
> at org.apache.hadoop.hbase.regionserver.wal.HLog.getReader(HLog.java:575)
> at
> org.apache.hadoop.hbase.regionserver.HRegion.replayRecoveredEdits(HRegion.java:1875)
> at
> org.apache.hadoop.hbase.regionserver.HRegion.replayRecoveredEditsIfAny(HRegion.java:1835)
> at
> org.apache.hadoop.hbase.regionserver.HRegion.initialize(HRegion.java:354)
> at
> org.apache.hadoop.hbase.regionserver.HRegion.openHRegion(HRegion.java:2553)
> at
> org.apache.hadoop.hbase.regionserver.HRegion.openHRegion(HRegion.java:2539)
> at
> org.apache.hadoop.hbase.regionserver.handler.OpenRegionHandler.openRegion(OpenRegionHandler.java:272)
> at
> org.apache.hadoop.hbase.regionserver.handler.OpenRegionHandler.process(OpenRegionHandler.java:99)
> at org.apache.hadoop.hbase.executor.EventHandler.run(EventHandler.java:156)
> at
> java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
> at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
> at java.lang.Thread.run(Thread.java:619)
> 2011-10-18 08:27:34,329 DEBUG org.apache.hadoop.hbase.regionserver.HRegion:
> Applied 2, skipped 0, firstSequenceidInLog=7, maxSequenceidInLog=7
> 2011-10-18 08:27:34,329 DEBUG org.apache.hadoop.hbase.regionserver.HRegion:
> Started memstore flush for -ROOT-,,0.70236052, current region memstore size
> 480.0; wal is null, using passed sequenceid=7
> 2011-10-18 08:27:34,329 DEBUG org.apache.hadoop.hbase.regionserver.HRegion:
> Finished snapshotting, commencing flushing stores
> 2011-10-18 08:27:34,417 INFO org.apache.hadoop.hbase.regionserver.Store:
> Renaming flushed file at
> file:/tmp/hbase-hbase/hbase/-ROOT-/70236052/.tmp/7507925448071592382 to
> file:/tmp/hbase-hbase/hbase/-ROOT-/70236052/info/6152135076013786807
> 2011-10-18 08:27:34,419 INFO org.apache.hadoop.hbase.regionserver.Store:
> Added file:/tmp/hbase-hbase/hbase/-ROOT-/70236052/info/6152135076013786807,
> entries=2, sequenceid=7, memsize=480.0, filesize=514.0
> 2011-10-18 08:27:34,419 INFO org.apache.hadoop.hbase.regionserver.HRegion:
> Finished memstore flush of ~480.0 for region -ROOT-,,0.70236052 in 90ms,
> sequenceid=7, compaction requested=true; wal=null
> 2011-10-18 08:27:34,443 DEBUG org.apache.hadoop.hbase.regionserver.HRegion:
> Deleted recovered.edits
> file=file:/tmp/hbase-hbase/hbase/-ROOT-/70236052/recovered.edits/0000000000000000007
> 2011-10-18 08:27:34,444 INFO org.apache.hadoop.hbase.regionserver.HRegion:
> Onlined -ROOT-,,0.70236052; next sequenceid=8
> 2011-10-18 08:27:34,444 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign:
> regionserver:57754-0x1331700150e0002 Attempting to transition node
> 70236052/-ROOT- from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENING
> 2011-10-18 08:27:34,449 DEBUG
> org.apache.hadoop.hbase.master.AssignmentManager: Handling
> transition=RS_ZK_REGION_OPENING,
> server=localhost.localdomain,57754,1318940844922, region=70236052/-ROOT-
> 2011-10-18 08:27:34,449 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign:
> regionserver:57754-0x1331700150e0002 Successfully transitioned node 70236052
> from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENING
> 2011-10-18 08:27:34,450 INFO
> org.apache.hadoop.hbase.catalog.RootLocationEditor: Setting ROOT region
> location in ZooKeeper as localhost.localdomain:57754
> 2011-10-18 08:27:34,456 INFO org.apache.hadoop.hbase.master.HMaster: -ROOT-
> assigned=1, rit=false, location=localhost.localdomain:57754
> 2011-10-18 08:27:34,473 INFO org.apache.hadoop.ipc.HbaseRPC: Server at
> localhost.localdomain/127.0.0.1:50781 could not be reached after 1 tries,
> giving up.
> 2011-10-18 08:27:34,473 INFO
> org.apache.hadoop.hbase.catalog.CatalogTracker: Passed metaserver is null
> 2011-10-18 08:27:34,473 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign:
> master:49977-0x1331700150e0000 Creating (or updating) unassigned node for
> 1028785192 with OFFLINE state
> 2011-10-18 08:27:34,477 DEBUG
> org.apache.hadoop.hbase.master.AssignmentManager: Handling
> transition=M_ZK_REGION_OFFLINE, server=localhost.localdomain:49977,
> region=1028785192/.META.
> 2011-10-18 08:27:34,478 DEBUG
> org.apache.hadoop.hbase.master.AssignmentManager: No previous transition
> plan was found (or we are ignoring an existing plan) for
> .META.,,1.1028785192 so generated a random one; hri=.META.,,1.1028785192,
> src=, dest=localhost.localdomain,57754,1318940844922; 1 (online=1,
> exclude=null) available servers
> 2011-10-18 08:27:34,478 DEBUG
> org.apache.hadoop.hbase.master.AssignmentManager: Assigning region
> .META.,,1.1028785192 to localhost.localdomain,57754,1318940844922
> 2011-10-18 08:27:34,479 INFO
> org.apache.hadoop.hbase.regionserver.HRegionServer: Received request to open
> region: .META.,,1.1028785192
> 2011-10-18 08:27:34,645 DEBUG
> org.apache.hadoop.hbase.regionserver.handler.OpenRegionHandler: Processing
> open of .META.,,1.1028785192
> 2011-10-18 08:27:34,645 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign:
> regionserver:57754-0x1331700150e0002 Attempting to transition node
> 1028785192/.META. from M_ZK_REGION_OFFLINE to RS_ZK_REGION_OPENING
> 2011-10-18 08:27:34,647 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign:
> regionserver:57754-0x1331700150e0002 Attempting to transition node
> 70236052/-ROOT- from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENED
> 2011-10-18 08:27:34,655 DEBUG
> org.apache.hadoop.hbase.master.AssignmentManager: Handling
> transition=RS_ZK_REGION_OPENING,
> server=localhost.localdomain,57754,1318940844922, region=1028785192/.META.
> 2011-10-18 08:27:34,656 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign:
> regionserver:57754-0x1331700150e0002 Successfully transitioned node
> 1028785192 from M_ZK_REGION_OFFLINE to RS_ZK_REGION_OPENING
> 2011-10-18 08:27:34,656 DEBUG org.apache.hadoop.hbase.regionserver.HRegion:
> Opening region: REGION => {NAME => '.META.,,1', STARTKEY => '', ENDKEY =>
> '', ENCODED => 1028785192, TABLE => {{NAME => '.META.', IS_META => 'true',
> FAMILIES => [{NAME => 'info', BLOOMFILTER => 'NONE', REPLICATION_SCOPE =>
> '0', VERSIONS => '10', COMPRESSION => 'NONE', TTL => '2147483647', BLOCKSIZE
> => '8192', IN_MEMORY => 'true', BLOCKCACHE => 'true'}]}}
> 2011-10-18 08:27:34,657 DEBUG org.apache.hadoop.hbase.regionserver.HRegion:
> Instantiated .META.,,1.1028785192
> 2011-10-18 08:27:34,696 INFO org.apache.hadoop.hbase.regionserver.HRegion:
> Onlined .META.,,1.1028785192; next sequenceid=1
> 2011-10-18 08:27:34,697 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign:
> regionserver:57754-0x1331700150e0002 Attempting to transition node
> 1028785192/.META. from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENING
> 2011-10-18 08:27:34,726 DEBUG
> org.apache.hadoop.hbase.master.AssignmentManager: Handling
> transition=RS_ZK_REGION_OPENED,
> server=localhost.localdomain,57754,1318940844922, region=70236052/-ROOT-
> 2011-10-18 08:27:34,727 DEBUG
> org.apache.hadoop.hbase.master.handler.OpenedRegionHandler: Handling OPENED
> event for 70236052; deleting unassigned node
> 2011-10-18 08:27:34,727 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign:
> master:49977-0x1331700150e0000 Deleting existing unassigned node for
> 70236052 that is in expected state RS_ZK_REGION_OPENED
> 2011-10-18 08:27:34,729 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign:
> regionserver:57754-0x1331700150e0002 Successfully transitioned node 70236052
> from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENED
> 2011-10-18 08:27:34,729 DEBUG
> org.apache.hadoop.hbase.regionserver.handler.OpenRegionHandler: Opened
> -ROOT-,,0.70236052
> 2011-10-18 08:27:34,735 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign:
> master:49977-0x1331700150e0000 Successfully deleted unassigned node for
> region 70236052 in expected state RS_ZK_REGION_OPENED
> 2011-10-18 08:27:34,735 DEBUG
> org.apache.hadoop.hbase.master.handler.OpenedRegionHandler: Opened region
> -ROOT-,,0.70236052 on localhost.localdomain,57754,1318940844922
> 2011-10-18 08:27:34,737 DEBUG
> org.apache.hadoop.hbase.master.AssignmentManager: Handling
> transition=RS_ZK_REGION_OPENING,
> server=localhost.localdomain,57754,1318940844922, region=1028785192/.META.
> 2011-10-18 08:27:34,738 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign:
> regionserver:57754-0x1331700150e0002 Successfully transitioned node
> 1028785192 from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENING
> 2011-10-18 08:27:34,742 INFO org.apache.hadoop.hbase.catalog.MetaEditor:
> Updated row .META.,,1.1028785192 in region -ROOT-,,0 with
> server=localhost.localdomain:57754, startcode=1318940844922
> 2011-10-18 08:27:34,742 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign:
> regionserver:57754-0x1331700150e0002 Attempting to transition node
> 1028785192/.META. from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENED
> 2011-10-18 08:27:34,745 DEBUG
> org.apache.hadoop.hbase.master.AssignmentManager: Handling
> transition=RS_ZK_REGION_OPENED,
> server=localhost.localdomain,57754,1318940844922, region=1028785192/.META.
> 2011-10-18 08:27:34,746 DEBUG
> org.apache.hadoop.hbase.master.handler.OpenedRegionHandler: Handling OPENED
> event for 1028785192; deleting unassigned node
> 2011-10-18 08:27:34,746 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign:
> master:49977-0x1331700150e0000 Deleting existing unassigned node for
> 1028785192 that is in expected state RS_ZK_REGION_OPENED
> 2011-10-18 08:27:34,748 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign:
> regionserver:57754-0x1331700150e0002 Successfully transitioned node
> 1028785192 from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENED
> 2011-10-18 08:27:34,748 DEBUG
> org.apache.hadoop.hbase.regionserver.handler.OpenRegionHandler: Opened
> .META.,,1.1028785192
> 2011-10-18 08:27:34,749 INFO
> org.apache.hadoop.hbase.zookeeper.MetaNodeTracker: Detected completed
> assignment of META, notifying catalog tracker
> 2011-10-18 08:27:34,750 INFO
> org.apache.hadoop.hbase.zookeeper.MetaNodeTracker: Detected completed
> assignment of META, notifying catalog tracker
> 2011-10-18 08:27:34,751 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign:
> master:49977-0x1331700150e0000 Successfully deleted unassigned node for
> region 1028785192 in expected state RS_ZK_REGION_OPENED
> 2011-10-18 08:27:34,751 DEBUG
> org.apache.hadoop.hbase.master.handler.OpenedRegionHandler: Opened region
> .META.,,1.1028785192 on localhost.localdomain,57754,1318940844922
> 2011-10-18 08:27:34,755 INFO org.apache.hadoop.hbase.master.HMaster: .META.
> assigned=2, rit=false, location=localhost.localdomain:57754
> 2011-10-18 08:27:34,755 INFO org.apache.hadoop.hbase.master.HMaster: Master
> startup proceeding: cluster startup
> 2011-10-18 08:27:34,755 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign:
> master:49977-0x1331700150e0000 Deleting any existing unassigned nodes
> 2011-10-18 08:27:35,035 INFO org.apache.hadoop.hbase.master.HMaster: Master
> has completed initialization
> 2011-10-18 08:27:35,038 DEBUG
> org.apache.hadoop.hbase.master.CatalogJanitor: Scanned 0 catalog row(s) and
> gc'd 0 unreferenced parent region(s)
> 2011-10-18 08:28:06,767 INFO org.apache.zookeeper.ZooKeeper: Initiating
> client connection, connectString=localhost:2182 sessionTimeout=180000
> watcher=hconnection
> 2011-10-18 08:28:06,768 INFO org.apache.zookeeper.ClientCnxn: Opening
> socket connection to server localhost/127.0.0.1:2182
> 2011-10-18 08:28:06,768 INFO org.apache.zookeeper.server.NIOServerCnxn:
> Accepted socket connection from /127.0.0.1:48880
> 2011-10-18 08:28:06,769 INFO org.apache.zookeeper.ClientCnxn: Socket
> connection established to localhost/127.0.0.1:2182, initiating session
> 2011-10-18 08:28:06,769 INFO org.apache.zookeeper.server.NIOServerCnxn:
> Client attempting to establish new session at /127.0.0.1:48880
> 2011-10-18 08:28:06,780 INFO org.apache.zookeeper.server.NIOServerCnxn:
> Established session 0x1331700150e0004 with negotiated timeout 40000 for
> client /127.0.0.1:48880
> 2011-10-18 08:28:06,782 INFO org.apache.zookeeper.ClientCnxn: Session
> establishment complete on server localhost/127.0.0.1:2182, sessionid =
> 0x1331700150e0004, negotiated timeout = 40000
> 2011-10-18 08:28:06,800 DEBUG org.apache.hadoop.hbase.client.MetaScanner:
> Scanning .META. starting at row= for max=2147483647 rows
> 2011-10-18 08:28:06,801 DEBUG
> org.apache.hadoop.hbase.client.HConnectionManager$HConnectionImplementation:
> Lookedup root region location,
> connection=org.apache.hadoop.hbase.client.HConnectionManager$HConnectionImplementation@1b4b74a7;
> hsa=localhost.localdomain:57754
> 2011-10-18 08:28:06,822 DEBUG
> org.apache.hadoop.hbase.client.HConnectionManager$HConnectionImplementation:
> Cached location for .META.,,1.1028785192 is localhost.localdomain:57754
> 2011-10-18 08:28:06,824 INFO
> org.apache.hadoop.hbase.client.HConnectionManager$HConnectionImplementation:
> Closed zookeeper sessionid=0x1331700150e0004
> 2011-10-18 08:28:06,824 INFO
> org.apache.zookeeper.server.PrepRequestProcessor: Processed session
> termination for sessionid: 0x1331700150e0004
> 2011-10-18 08:28:06,828 INFO org.apache.zookeeper.server.NIOServerCnxn:
> Closed socket connection for client /127.0.0.1:48880 which had sessionid
> 0x1331700150e0004
> 2011-10-18 08:28:06,829 INFO org.apache.zookeeper.ZooKeeper: Session:
> 0x1331700150e0004 closed
> 2011-10-18 08:28:06,837 INFO org.apache.zookeeper.ClientCnxn: EventThread
> shut down
>
HMaster issues
Posted by Ben West <bw...@yahoo.com>.
Hey All,
I'm having an issue I can't debug. The shell gives me a MasterNotRunningException, but I can connect to the master via the web interface. I'm using the Cloudera demo VM, which has a standalone instance of HBase.
I'm attaching the HBase-master log file. The only thing I can see is a warning that getting a checksum failed, but from the warning that doesn't sound very serious.
The only thing in my config file is to change the Zookeeper port since there seemed to be a conflict with the default.
Any help would be appreciated,
-Ben
Tue Oct 18 08:27:17 EDT 2011 Starting master on localhost.localdomain
ulimit -n 1024
2011-10-18 08:27:20,631 INFO org.apache.zookeeper.server.ZooKeeperServer: Server environment:zookeeper.version=3.3.3-cdh3u1--1, built on 07/30/2011 01:29 GMT
2011-10-18 08:27:20,631 INFO org.apache.zookeeper.server.ZooKeeperServer: Server environment:host.name=localhost.localdomain
2011-10-18 08:27:20,631 INFO org.apache.zookeeper.server.ZooKeeperServer: Server environment:java.version=1.6.0_21
2011-10-18 08:27:20,631 INFO org.apache.zookeeper.server.ZooKeeperServer: Server environment:java.vendor=Sun Microsystems Inc.
2011-10-18 08:27:20,631 INFO org.apache.zookeeper.server.ZooKeeperServer: Server environment:java.home=/usr/java/jdk1.6.0_21/jre
2011-10-18 08:27:20,631 INFO org.apache.zookeeper.server.ZooKeeperServer: Server
environment:java.class.path=/usr/lib/hbase/bin/../conf:/usr/java/jdk1.6.0_21/lib/tools.jar:/usr/lib/hbase/bin/..:/usr/lib/hbase/bin/../hbase-0.90.3-cdh3u1.jar:/usr/lib/hbase/bin/../hbase-0.90.3-cdh3u1-tests.jar:/usr/lib/hbase/bin/../lib/activation-1.1.jar:/usr/lib/hbase/bin/../lib/asm-3.1.jar:/usr/lib/hbase/bin/../lib/avro-1.3.3.jar:/usr/lib/hbase/bin/../lib/commons-cli-1.2.jar:/usr/lib/hbase/bin/../lib/commons-codec-1.4.jar:/usr/lib/hbase/bin/../lib/commons-el-1.0.jar:/usr/lib/hbase/bin/../lib/commons-httpclient-3.1.jar:/usr/lib/hbase/bin/../lib/commons-lang-2.5.jar:/usr/lib/hbase/bin/../lib/commons-logging-1.1.1.jar:/usr/lib/hbase/bin/../lib/commons-net-1.4.1.jar:/usr/lib/hbase/bin/../lib/core-3.1.1.jar:/usr/lib/hbase/bin/../lib/guava-r06.jar:/usr/lib/hbase/bin/../lib/hadoop-core.jar:/usr/lib/hbase/bin/../lib/jackson-core-asl-1.5.2.jar:/usr/lib/hbase/bin/../lib/jackson-jaxrs-1.5.5.jar:/usr/lib/hbase/bin/../lib/jackson-mapper-asl-1.5.2.jar:/usr/lib/hb
ase/bin/../lib/jackson-xc-1.5.5.jar:/usr/lib/hbase/bin/../lib/jasper-compiler-5.5.23.jar:/usr/lib/hbase/bin/../lib/jasper-runtime-5.5.23.jar:/usr/lib/hbase/bin/../lib/jaxb-api-2.1.jar:/usr/lib/hbase/bin/../lib/jaxb-impl-2.1.12.jar:/usr/lib/hbase/bin/../lib/jersey-core-1.4.jar:/usr/lib/hbase/bin/../lib/jersey-json-1.4.jar:/usr/lib/hbase/bin/../lib/jersey-server-1.4.jar:/usr/lib/hbase/bin/../lib/jettison-1.1.jar:/usr/lib/hbase/bin/../lib/jetty-6.1.26.jar:/usr/lib/hbase/bin/../lib/jetty-util-6.1.26.jar:/usr/lib/hbase/bin/../lib/jruby-complete-1.6.0.jar:/usr/lib/hbase/bin/../lib/jsp-2.1-6.1.14.jar:/usr/lib/hbase/bin/../lib/jsp-api-2.1-6.1.14.jar:/usr/lib/hbase/bin/../lib/jsp-api-2.1.jar:/usr/lib/hbase/bin/../lib/jsr311-api-1.1.1.jar:/usr/lib/hbase/bin/../lib/log4j-1.2.16.jar:/usr/lib/hbase/bin/../lib/protobuf-java-2.3.0.jar:/usr/lib/hbase/bin/../lib/servlet-api-2.5-6.1.14.jar:/usr/lib/hbase/bin/../lib/servlet-api-2.5.jar:/usr/lib/hbase/bin/../lib/slf4j-api-
1.5.8.jar:/usr/lib/hbase/bin/../lib/slf4j-log4j12-1.5.8.jar:/usr/lib/hbase/bin/../lib/stax-api-1.0.1.jar:/usr/lib/hbase/bin/../lib/thrift-0.2.0.jar:/usr/lib/hbase/bin/../lib/xmlenc-0.52.jar:/usr/lib/hbase/bin/../lib/zookeeper.jar
2011-10-18 08:27:20,631 INFO org.apache.zookeeper.server.ZooKeeperServer: Server environment:java.library.path=/usr/lib/hbase/bin/../lib/native/Linux-amd64-64
2011-10-18 08:27:20,631 INFO org.apache.zookeeper.server.ZooKeeperServer: Server environment:java.io.tmpdir=/tmp
2011-10-18 08:27:20,631 INFO org.apache.zookeeper.server.ZooKeeperServer: Server environment:java.compiler=<NA>
2011-10-18 08:27:20,631 INFO org.apache.zookeeper.server.ZooKeeperServer: Server environment:os.name=Linux
2011-10-18 08:27:20,631 INFO org.apache.zookeeper.server.ZooKeeperServer: Server environment:os.arch=amd64
2011-10-18 08:27:20,631 INFO org.apache.zookeeper.server.ZooKeeperServer: Server environment:os.version=2.6.18-238.19.1.el5
2011-10-18 08:27:20,631 INFO org.apache.zookeeper.server.ZooKeeperServer: Server environment:user.name=hbase
2011-10-18 08:27:20,631 INFO org.apache.zookeeper.server.ZooKeeperServer: Server environment:user.home=/var/run/hbase
2011-10-18 08:27:20,631 INFO org.apache.zookeeper.server.ZooKeeperServer: Server environment:user.dir=/
2011-10-18 08:27:20,837 INFO org.apache.zookeeper.server.ZooKeeperServer: Created server with tickTime 2000 minSessionTimeout 4000 maxSessionTimeout 40000 datadir /tmp/hbase-hbase/zookeeper/zookeeper/version-2 snapdir /tmp/hbase-hbase/zookeeper/zookeeper/version-2
2011-10-18 08:27:21,189 INFO org.apache.zookeeper.server.NIOServerCnxn: binding to port 0.0.0.0/0.0.0.0:2182
2011-10-18 08:27:21,220 INFO org.apache.zookeeper.server.persistence.FileTxnSnapLog: Snapshotting: 0
2011-10-18 08:27:21,463 INFO org.apache.zookeeper.server.NIOServerCnxn: Accepted socket connection from /127.0.0.1:48821
2011-10-18 08:27:21,485 INFO org.apache.zookeeper.server.NIOServerCnxn: Processing stat command from /127.0.0.1:48821
2011-10-18 08:27:21,488 INFO org.apache.zookeeper.server.NIOServerCnxn: Stat command output
2011-10-18 08:27:21,488 INFO org.apache.zookeeper.server.NIOServerCnxn: Closed socket connection for client /127.0.0.1:48821 (no session established for client)
2011-10-18 08:27:21,489 INFO org.apache.hadoop.hbase.zookeeper.MiniZooKeeperCluster: Started MiniZK Server on client port: 2182
2011-10-18 08:27:21,939 INFO org.apache.hadoop.hbase.ipc.HBaseRpcMetrics: Initializing RPC Metrics with hostName=HMasterCommandLine$LocalHMaster, port=49977
2011-10-18 08:27:23,849 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server Responder: starting
2011-10-18 08:27:23,870 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server listener on 49977: starting
2011-10-18 08:27:23,884 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server handler 0 on 49977: starting
2011-10-18 08:27:23,885 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server handler 1 on 49977: starting
2011-10-18 08:27:23,909 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server handler 3 on 49977: starting
2011-10-18 08:27:23,909 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server handler 2 on 49977: starting
2011-10-18 08:27:23,910 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server handler 4 on 49977: starting
2011-10-18 08:27:23,910 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server handler 5 on 49977: starting
2011-10-18 08:27:23,910 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server handler 6 on 49977: starting
2011-10-18 08:27:23,911 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server handler 7 on 49977: starting
2011-10-18 08:27:23,911 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server handler 8 on 49977: starting
2011-10-18 08:27:23,911 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server handler 9 on 49977: starting
2011-10-18 08:27:23,951 INFO org.apache.zookeeper.ZooKeeper: Client environment:zookeeper.version=3.3.3-cdh3u1--1, built on 07/30/2011 01:29 GMT
2011-10-18 08:27:23,951 INFO org.apache.zookeeper.ZooKeeper: Client environment:host.name=localhost.localdomain
2011-10-18 08:27:23,951 INFO org.apache.zookeeper.ZooKeeper: Client environment:java.version=1.6.0_21
2011-10-18 08:27:23,951 INFO org.apache.zookeeper.ZooKeeper: Client environment:java.vendor=Sun Microsystems Inc.
2011-10-18 08:27:23,951 INFO org.apache.zookeeper.ZooKeeper: Client environment:java.home=/usr/java/jdk1.6.0_21/jre
2011-10-18 08:27:23,951 INFO org.apache.zookeeper.ZooKeeper: Client
environment:java.class.path=/usr/lib/hbase/bin/../conf:/usr/java/jdk1.6.0_21/lib/tools.jar:/usr/lib/hbase/bin/..:/usr/lib/hbase/bin/../hbase-0.90.3-cdh3u1.jar:/usr/lib/hbase/bin/../hbase-0.90.3-cdh3u1-tests.jar:/usr/lib/hbase/bin/../lib/activation-1.1.jar:/usr/lib/hbase/bin/../lib/asm-3.1.jar:/usr/lib/hbase/bin/../lib/avro-1.3.3.jar:/usr/lib/hbase/bin/../lib/commons-cli-1.2.jar:/usr/lib/hbase/bin/../lib/commons-codec-1.4.jar:/usr/lib/hbase/bin/../lib/commons-el-1.0.jar:/usr/lib/hbase/bin/../lib/commons-httpclient-3.1.jar:/usr/lib/hbase/bin/../lib/commons-lang-2.5.jar:/usr/lib/hbase/bin/../lib/commons-logging-1.1.1.jar:/usr/lib/hbase/bin/../lib/commons-net-1.4.1.jar:/usr/lib/hbase/bin/../lib/core-3.1.1.jar:/usr/lib/hbase/bin/../lib/guava-r06.jar:/usr/lib/hbase/bin/../lib/hadoop-core.jar:/usr/lib/hbase/bin/../lib/jackson-core-asl-1.5.2.jar:/usr/lib/hbase/bin/../lib/jackson-jaxrs-1.5.5.jar:/usr/lib/hbase/bin/../lib/jackson-mapper-asl-1.5.2.jar:/usr/lib/hb
ase/bin/../lib/jackson-xc-1.5.5.jar:/usr/lib/hbase/bin/../lib/jasper-compiler-5.5.23.jar:/usr/lib/hbase/bin/../lib/jasper-runtime-5.5.23.jar:/usr/lib/hbase/bin/../lib/jaxb-api-2.1.jar:/usr/lib/hbase/bin/../lib/jaxb-impl-2.1.12.jar:/usr/lib/hbase/bin/../lib/jersey-core-1.4.jar:/usr/lib/hbase/bin/../lib/jersey-json-1.4.jar:/usr/lib/hbase/bin/../lib/jersey-server-1.4.jar:/usr/lib/hbase/bin/../lib/jettison-1.1.jar:/usr/lib/hbase/bin/../lib/jetty-6.1.26.jar:/usr/lib/hbase/bin/../lib/jetty-util-6.1.26.jar:/usr/lib/hbase/bin/../lib/jruby-complete-1.6.0.jar:/usr/lib/hbase/bin/../lib/jsp-2.1-6.1.14.jar:/usr/lib/hbase/bin/../lib/jsp-api-2.1-6.1.14.jar:/usr/lib/hbase/bin/../lib/jsp-api-2.1.jar:/usr/lib/hbase/bin/../lib/jsr311-api-1.1.1.jar:/usr/lib/hbase/bin/../lib/log4j-1.2.16.jar:/usr/lib/hbase/bin/../lib/protobuf-java-2.3.0.jar:/usr/lib/hbase/bin/../lib/servlet-api-2.5-6.1.14.jar:/usr/lib/hbase/bin/../lib/servlet-api-2.5.jar:/usr/lib/hbase/bin/../lib/slf4j-api-
1.5.8.jar:/usr/lib/hbase/bin/../lib/slf4j-log4j12-1.5.8.jar:/usr/lib/hbase/bin/../lib/stax-api-1.0.1.jar:/usr/lib/hbase/bin/../lib/thrift-0.2.0.jar:/usr/lib/hbase/bin/../lib/xmlenc-0.52.jar:/usr/lib/hbase/bin/../lib/zookeeper.jar
2011-10-18 08:27:23,951 INFO org.apache.zookeeper.ZooKeeper: Client environment:java.library.path=/usr/lib/hbase/bin/../lib/native/Linux-amd64-64
2011-10-18 08:27:23,951 INFO org.apache.zookeeper.ZooKeeper: Client environment:java.io.tmpdir=/tmp
2011-10-18 08:27:23,951 INFO org.apache.zookeeper.ZooKeeper: Client environment:java.compiler=<NA>
2011-10-18 08:27:23,951 INFO org.apache.zookeeper.ZooKeeper: Client environment:os.name=Linux
2011-10-18 08:27:23,951 INFO org.apache.zookeeper.ZooKeeper: Client environment:os.arch=amd64
2011-10-18 08:27:23,951 INFO org.apache.zookeeper.ZooKeeper: Client environment:os.version=2.6.18-238.19.1.el5
2011-10-18 08:27:23,951 INFO org.apache.zookeeper.ZooKeeper: Client environment:user.name=hbase
2011-10-18 08:27:23,951 INFO org.apache.zookeeper.ZooKeeper: Client environment:user.home=/var/run/hbase
2011-10-18 08:27:23,951 INFO org.apache.zookeeper.ZooKeeper: Client environment:user.dir=/
2011-10-18 08:27:23,952 INFO org.apache.zookeeper.ZooKeeper: Initiating client connection, connectString=localhost:2182 sessionTimeout=180000 watcher=master:49977
2011-10-18 08:27:24,009 INFO org.apache.zookeeper.ClientCnxn: Opening socket connection to server localhost/127.0.0.1:2182
2011-10-18 08:27:24,047 INFO org.apache.zookeeper.server.NIOServerCnxn: Accepted socket connection from /127.0.0.1:48824
2011-10-18 08:27:24,047 INFO org.apache.zookeeper.ClientCnxn: Socket connection established to localhost/127.0.0.1:2182, initiating session
2011-10-18 08:27:24,064 INFO org.apache.zookeeper.server.NIOServerCnxn: Client attempting to establish new session at /127.0.0.1:48824
2011-10-18 08:27:24,066 INFO org.apache.zookeeper.server.persistence.FileTxnLog: Creating new log file: log.1
2011-10-18 08:27:24,092 INFO org.apache.zookeeper.server.NIOServerCnxn: Established session 0x1331700150e0000 with negotiated timeout 40000 for client /127.0.0.1:48824
2011-10-18 08:27:24,097 INFO org.apache.zookeeper.ClientCnxn: Session establishment complete on server localhost/127.0.0.1:2182, sessionid = 0x1331700150e0000, negotiated timeout = 40000
2011-10-18 08:27:24,111 INFO org.apache.hadoop.metrics.jvm.JvmMetrics: Initializing JVM Metrics with processName=Master, sessionId=localhost.localdomain:49977
2011-10-18 08:27:24,131 INFO org.apache.hadoop.hbase.metrics: MetricsString added: revision
2011-10-18 08:27:24,131 INFO org.apache.hadoop.hbase.metrics: MetricsString added: hdfsUser
2011-10-18 08:27:24,131 INFO org.apache.hadoop.hbase.metrics: MetricsString added: hdfsDate
2011-10-18 08:27:24,131 INFO org.apache.hadoop.hbase.metrics: MetricsString added: hdfsUrl
2011-10-18 08:27:24,131 INFO org.apache.hadoop.hbase.metrics: MetricsString added: date
2011-10-18 08:27:24,131 INFO org.apache.hadoop.hbase.metrics: MetricsString added: hdfsRevision
2011-10-18 08:27:24,131 INFO org.apache.hadoop.hbase.metrics: MetricsString added: user
2011-10-18 08:27:24,131 INFO org.apache.hadoop.hbase.metrics: MetricsString added: hdfsVersion
2011-10-18 08:27:24,131 INFO org.apache.hadoop.hbase.metrics: MetricsString added: url
2011-10-18 08:27:24,131 INFO org.apache.hadoop.hbase.metrics: MetricsString added: version
2011-10-18 08:27:24,131 INFO org.apache.hadoop.hbase.metrics: new MBeanInfo
2011-10-18 08:27:24,131 INFO org.apache.hadoop.hbase.metrics: new MBeanInfo
2011-10-18 08:27:24,132 INFO org.apache.hadoop.hbase.master.metrics.MasterMetrics: Initialized
2011-10-18 08:27:24,508 INFO org.apache.zookeeper.ZooKeeper: Initiating client connection, connectString=localhost:2182 sessionTimeout=180000 watcher=hconnection
2011-10-18 08:27:24,508 INFO org.apache.zookeeper.ClientCnxn: Opening socket connection to server localhost/127.0.0.1:2182
2011-10-18 08:27:24,527 INFO org.apache.zookeeper.server.NIOServerCnxn: Accepted socket connection from /127.0.0.1:48825
2011-10-18 08:27:24,528 INFO org.apache.zookeeper.ClientCnxn: Socket connection established to localhost/127.0.0.1:2182, initiating session
2011-10-18 08:27:24,528 INFO org.apache.zookeeper.server.NIOServerCnxn: Client attempting to establish new session at /127.0.0.1:48825
2011-10-18 08:27:24,537 INFO org.apache.zookeeper.server.NIOServerCnxn: Established session 0x1331700150e0001 with negotiated timeout 40000 for client /127.0.0.1:48825
2011-10-18 08:27:24,539 INFO org.apache.zookeeper.ClientCnxn: Session establishment complete on server localhost/127.0.0.1:2182, sessionid = 0x1331700150e0001, negotiated timeout = 40000
2011-10-18 08:27:24,727 INFO org.apache.hadoop.hbase.ipc.HBaseRpcMetrics: Initializing RPC Metrics with hostName=HRegionServer, port=57754
2011-10-18 08:27:25,093 INFO org.apache.zookeeper.ZooKeeper: Initiating client connection, connectString=localhost:2182 sessionTimeout=180000 watcher=regionserver:57754
2011-10-18 08:27:25,093 INFO org.apache.hadoop.hbase.master.ActiveMasterManager: Master=localhost.localdomain:49977
2011-10-18 08:27:25,107 INFO org.apache.zookeeper.ClientCnxn: Opening socket connection to server localhost/127.0.0.1:2182
2011-10-18 08:27:25,107 INFO org.apache.zookeeper.server.NIOServerCnxn: Accepted socket connection from /127.0.0.1:48826
2011-10-18 08:27:25,109 INFO org.apache.zookeeper.ClientCnxn: Socket connection established to localhost/127.0.0.1:2182, initiating session
2011-10-18 08:27:25,109 INFO org.apache.zookeeper.server.NIOServerCnxn: Client attempting to establish new session at /127.0.0.1:48826
2011-10-18 08:27:25,113 INFO org.apache.zookeeper.server.NIOServerCnxn: Established session 0x1331700150e0002 with negotiated timeout 40000 for client /127.0.0.1:48826
2011-10-18 08:27:25,117 INFO org.apache.zookeeper.ClientCnxn: Session establishment complete on server localhost/127.0.0.1:2182, sessionid = 0x1331700150e0002, negotiated timeout = 40000
2011-10-18 08:27:26,071 INFO org.apache.zookeeper.ZooKeeper: Initiating client connection, connectString=localhost:2182 sessionTimeout=180000 watcher=hconnection
2011-10-18 08:27:26,072 INFO org.apache.zookeeper.ClientCnxn: Opening socket connection to server localhost/127.0.0.1:2182
2011-10-18 08:27:26,072 INFO org.apache.zookeeper.server.NIOServerCnxn: Accepted socket connection from /127.0.0.1:48827
2011-10-18 08:27:26,072 INFO org.apache.zookeeper.ClientCnxn: Socket connection established to localhost/127.0.0.1:2182, initiating session
2011-10-18 08:27:26,073 INFO org.apache.zookeeper.server.NIOServerCnxn: Client attempting to establish new session at /127.0.0.1:48827
2011-10-18 08:27:26,078 INFO org.apache.zookeeper.server.NIOServerCnxn: Established session 0x1331700150e0003 with negotiated timeout 40000 for client /127.0.0.1:48827
2011-10-18 08:27:26,080 INFO org.apache.zookeeper.ClientCnxn: Session establishment complete on server localhost/127.0.0.1:2182, sessionid = 0x1331700150e0003, negotiated timeout = 40000
2011-10-18 08:27:26,148 DEBUG org.apache.hadoop.hbase.catalog.CatalogTracker: Starting catalog tracker org.apache.hadoop.hbase.catalog.CatalogTracker@7f5d3388
2011-10-18 08:27:26,212 DEBUG org.apache.hadoop.hbase.catalog.CatalogTracker: Starting catalog tracker org.apache.hadoop.hbase.catalog.CatalogTracker@342798e7
2011-10-18 08:27:26,217 INFO org.apache.hadoop.hbase.regionserver.MemStoreFlusher: globalMemStoreLimit=399.2m, globalMemStoreLimitLowMark=349.3m, maxHeap=997.9m
2011-10-18 08:27:26,219 DEBUG org.apache.hadoop.hbase.regionserver.PriorityCompactionQueue: Create PriorityCompactionQueue
2011-10-18 08:27:26,219 INFO org.apache.hadoop.hbase.regionserver.HRegionServer: Runs every 10000000ms
2011-10-18 08:27:26,294 INFO org.apache.hadoop.hbase.regionserver.HRegionServer: Attempting connect to Master server at localhost.localdomain:49977
2011-10-18 08:27:26,344 INFO org.apache.hadoop.hbase.regionserver.HRegionServer: Master isn't available yet, retrying
2011-10-18 08:27:26,348 INFO org.apache.hadoop.hbase.master.HMaster: Server active/primary master; localhost.localdomain:49977, sessionid=0x1331700150e0000, cluster-up flag was=false
2011-10-18 08:27:26,349 DEBUG org.apache.hadoop.hbase.executor.ExecutorService: Starting executor service name=MASTER_OPEN_REGION-localhost.localdomain:49977, corePoolSize=5, maxPoolSize=5
2011-10-18 08:27:26,349 DEBUG org.apache.hadoop.hbase.executor.ExecutorService: Starting executor service name=MASTER_CLOSE_REGION-localhost.localdomain:49977, corePoolSize=5, maxPoolSize=5
2011-10-18 08:27:26,349 DEBUG org.apache.hadoop.hbase.executor.ExecutorService: Starting executor service name=MASTER_SERVER_OPERATIONS-localhost.localdomain:49977, corePoolSize=3, maxPoolSize=3
2011-10-18 08:27:26,349 DEBUG org.apache.hadoop.hbase.executor.ExecutorService: Starting executor service name=MASTER_META_SERVER_OPERATIONS-localhost.localdomain:49977, corePoolSize=5, maxPoolSize=5
2011-10-18 08:27:26,349 DEBUG org.apache.hadoop.hbase.executor.ExecutorService: Starting executor service name=MASTER_TABLE_OPERATIONS-localhost.localdomain:49977, corePoolSize=1, maxPoolSize=1
2011-10-18 08:27:26,351 DEBUG org.apache.hadoop.hbase.master.LogCleaner: Add log cleaner in chain: org.apache.hadoop.hbase.master.TimeToLiveLogCleaner
2011-10-18 08:27:26,739 INFO org.mortbay.log: Logging to org.slf4j.impl.Log4jLoggerAdapter(org.mortbay.log) via org.mortbay.log.Slf4jLog
2011-10-18 08:27:26,832 INFO org.apache.hadoop.http.HttpServer: Added global filtersafety (class=org.apache.hadoop.http.HttpServer$QuotingInputFilter)
2011-10-18 08:27:26,838 INFO org.apache.hadoop.http.HttpServer: Port returned by webServer.getConnectors()[0].getLocalPort() before open() is -1. Opening the listener on 60010
2011-10-18 08:27:26,838 INFO org.apache.hadoop.http.HttpServer: listener.getLocalPort() returned 60010 webServer.getConnectors()[0].getLocalPort() returned 60010
2011-10-18 08:27:26,838 INFO org.apache.hadoop.http.HttpServer: Jetty bound to port 60010
2011-10-18 08:27:26,838 INFO org.mortbay.log: jetty-6.1.26
2011-10-18 08:27:27,019 WARN org.mortbay.log: Can't reuse /tmp/Jetty_0_0_0_0_60010_master____q3nwom, using /tmp/Jetty_0_0_0_0_60010_master____q3nwom_3288413844900815841
2011-10-18 08:27:27,877 INFO org.mortbay.log: Started SelectChannelConnector@0.0.0.0:60010
2011-10-18 08:27:27,877 DEBUG org.apache.hadoop.hbase.master.HMaster: Started service threads
2011-10-18 08:27:29,348 INFO org.apache.hadoop.hbase.regionserver.HRegionServer: Attempting connect to Master server at localhost.localdomain:49977
2011-10-18 08:27:29,356 INFO org.apache.hadoop.hbase.regionserver.HRegionServer: Connected to master at localhost.localdomain:49977
2011-10-18 08:27:29,359 INFO org.apache.hadoop.hbase.regionserver.HRegionServer: Telling master at localhost.localdomain:49977 that we are up
2011-10-18 08:27:29,364 INFO org.apache.hadoop.hbase.master.ServerManager: Registering server=localhost.localdomain,57754,1318940844922, regionCount=0, userLoad=false
2011-10-18 08:27:29,373 INFO org.apache.hadoop.hbase.regionserver.HRegionServer: Master passed us address to use. Was=localhost.localdomain:57754, Now=localhost.localdomain:57754
2011-10-18 08:27:29,373 DEBUG org.apache.hadoop.hbase.regionserver.HRegionServer: Config from master: fs.default.name=file:///
2011-10-18 08:27:29,373 DEBUG org.apache.hadoop.hbase.regionserver.HRegionServer: Config from master: hbase.rootdir=file:///tmp/hbase-hbase/hbase
2011-10-18 08:27:29,376 DEBUG org.apache.hadoop.hbase.regionserver.HRegionServer: logdir=file:/tmp/hbase-hbase/hbase/.logs/localhost.localdomain,57754,1318940844922
2011-10-18 08:27:29,380 INFO org.apache.hadoop.hbase.master.ServerManager: Waiting on regionserver(s) count to settle; currently=1
2011-10-18 08:27:29,399 INFO org.apache.hadoop.hbase.regionserver.wal.HLog: HLog configuration: blocksize=32 MB, rollsize=30.4 MB, enabled=true, flushlogentries=1, optionallogflushinternal=1000ms
2011-10-18 08:27:29,450 WARN org.apache.hadoop.util.NativeCodeLoader: Unable to load native-hadoop library for your platform... using builtin-java classes where applicable
2011-10-18 08:27:29,496 INFO org.apache.hadoop.hbase.regionserver.wal.SequenceFileLogWriter: syncFs -- HDFS-200 -- not available, dfs.support.append=false
2011-10-18 08:27:29,497 INFO org.apache.hadoop.hbase.regionserver.wal.HLog: New hlog /tmp/hbase-hbase/hbase/.logs/localhost.localdomain,57754,1318940844922/localhost.localdomain%3A57754.1318940849409
2011-10-18 08:27:29,497 INFO org.apache.hadoop.hbase.regionserver.wal.HLog: getNumCurrentReplicas--HDFS-826 not available; hdfs_out=org.apache.hadoop.fs.ChecksumFileSystem$ChecksumFSOutputSummer@381eb0c6, exception=org.apache.hadoop.fs.ChecksumFileSystem$ChecksumFSOutputSummer.getNumCurrentReplicas()
2011-10-18 08:27:29,506 INFO org.apache.hadoop.metrics.jvm.JvmMetrics: Cannot initialize JVM Metrics with processName=RegionServer, sessionId=RegionServer:0;localhost.localdomain,57754,1318940844922 - already initialized
2011-10-18 08:27:29,509 INFO org.apache.hadoop.hbase.metrics: new MBeanInfo
2011-10-18 08:27:29,510 INFO org.apache.hadoop.hbase.regionserver.metrics.RegionServerMetrics: Initialized
2011-10-18 08:27:29,511 DEBUG org.apache.hadoop.hbase.executor.ExecutorService: Starting executor service name=RS_OPEN_REGION-localhost.localdomain,57754,1318940844922, corePoolSize=3, maxPoolSize=3
2011-10-18 08:27:29,512 DEBUG org.apache.hadoop.hbase.executor.ExecutorService: Starting executor service name=RS_OPEN_ROOT-localhost.localdomain,57754,1318940844922, corePoolSize=1, maxPoolSize=1
2011-10-18 08:27:29,512 DEBUG org.apache.hadoop.hbase.executor.ExecutorService: Starting executor service name=RS_OPEN_META-localhost.localdomain,57754,1318940844922, corePoolSize=1, maxPoolSize=1
2011-10-18 08:27:29,512 DEBUG org.apache.hadoop.hbase.executor.ExecutorService: Starting executor service name=RS_CLOSE_REGION-localhost.localdomain,57754,1318940844922, corePoolSize=3, maxPoolSize=3
2011-10-18 08:27:29,512 DEBUG org.apache.hadoop.hbase.executor.ExecutorService: Starting executor service name=RS_CLOSE_ROOT-localhost.localdomain,57754,1318940844922, corePoolSize=1, maxPoolSize=1
2011-10-18 08:27:29,512 DEBUG org.apache.hadoop.hbase.executor.ExecutorService: Starting executor service name=RS_CLOSE_META-localhost.localdomain,57754,1318940844922, corePoolSize=1, maxPoolSize=1
2011-10-18 08:27:29,699 INFO org.apache.hadoop.http.HttpServer: Added global filtersafety (class=org.apache.hadoop.http.HttpServer$QuotingInputFilter)
2011-10-18 08:27:29,700 INFO org.apache.hadoop.http.HttpServer: Port returned by webServer.getConnectors()[0].getLocalPort() before open() is -1. Opening the listener on 60030
2011-10-18 08:27:29,700 INFO org.apache.hadoop.http.HttpServer: listener.getLocalPort() returned 60030 webServer.getConnectors()[0].getLocalPort() returned 60030
2011-10-18 08:27:29,700 INFO org.apache.hadoop.http.HttpServer: Jetty bound to port 60030
2011-10-18 08:27:29,700 INFO org.mortbay.log: jetty-6.1.26
2011-10-18 08:27:29,715 WARN org.mortbay.log: Can't reuse /tmp/Jetty_0_0_0_0_60030_regionserver____.h599vl, using /tmp/Jetty_0_0_0_0_60030_regionserver____.h599vl_2500151639767017676
2011-10-18 08:27:30,234 INFO org.mortbay.log: Started SelectChannelConnector@0.0.0.0:60030
2011-10-18 08:27:30,236 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server Responder: starting
2011-10-18 08:27:30,236 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server listener on 57754: starting
2011-10-18 08:27:30,236 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server handler 0 on 57754: starting
2011-10-18 08:27:30,236 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server handler 1 on 57754: starting
2011-10-18 08:27:30,236 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server handler 2 on 57754: starting
2011-10-18 08:27:30,258 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server handler 4 on 57754: starting
2011-10-18 08:27:30,258 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server handler 5 on 57754: starting
2011-10-18 08:27:30,261 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server handler 3 on 57754: starting
2011-10-18 08:27:30,283 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server handler 7 on 57754: starting
2011-10-18 08:27:30,284 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server handler 8 on 57754: starting
2011-10-18 08:27:30,284 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server handler 6 on 57754: starting
2011-10-18 08:27:30,284 INFO org.apache.hadoop.ipc.HBaseServer: IPC Server handler 9 on 57754: starting
2011-10-18 08:27:30,284 INFO org.apache.hadoop.ipc.HBaseServer: PRI IPC Server handler 0 on 57754: starting
2011-10-18 08:27:30,298 INFO org.apache.hadoop.ipc.HBaseServer: PRI IPC Server handler 1 on 57754: starting
2011-10-18 08:27:30,298 INFO org.apache.hadoop.ipc.HBaseServer: PRI IPC Server handler 2 on 57754: starting
2011-10-18 08:27:30,299 INFO org.apache.hadoop.ipc.HBaseServer: PRI IPC Server handler 3 on 57754: starting
2011-10-18 08:27:30,322 INFO org.apache.hadoop.ipc.HBaseServer: PRI IPC Server handler 4 on 57754: starting
2011-10-18 08:27:30,369 INFO org.apache.hadoop.ipc.HBaseServer: PRI IPC Server handler 5 on 57754: starting
2011-10-18 08:27:30,370 INFO org.apache.hadoop.ipc.HBaseServer: PRI IPC Server handler 6 on 57754: starting
2011-10-18 08:27:30,371 INFO org.apache.hadoop.ipc.HBaseServer: PRI IPC Server handler 7 on 57754: starting
2011-10-18 08:27:30,371 INFO org.apache.hadoop.ipc.HBaseServer: PRI IPC Server handler 8 on 57754: starting
2011-10-18 08:27:30,371 INFO org.apache.hadoop.hbase.regionserver.HRegionServer: Serving as localhost.localdomain,57754,1318940844922, RPC listening on /127.0.0.1:57754, sessionid=0x1331700150e0002
2011-10-18 08:27:30,372 INFO org.apache.hadoop.ipc.HBaseServer: PRI IPC Server handler 9 on 57754: starting
2011-10-18 08:27:30,524 INFO org.apache.hadoop.hbase.regionserver.StoreFile: Allocating LruBlockCache with maximum size 199.6m
2011-10-18 08:27:30,883 INFO org.apache.hadoop.hbase.master.ServerManager: Waiting on regionserver(s) count to settle; currently=1
2011-10-18 08:27:32,385 INFO org.apache.hadoop.hbase.master.ServerManager: Finished waiting for regionserver count to settle; count=1, sleptFor=4500
2011-10-18 08:27:32,385 INFO org.apache.hadoop.hbase.master.ServerManager: Exiting wait on regionserver(s) to checkin; count=1, stopped=false, count of regions out on cluster=0
2011-10-18 08:27:32,388 INFO org.apache.hadoop.hbase.master.MasterFileSystem: Log folder file:/tmp/hbase-hbase/hbase/.logs/localhost.localdomain,57754,1318940844922 belongs to an existing region server
2011-10-18 08:27:32,388 INFO org.apache.hadoop.hbase.master.MasterFileSystem: Log folder file:/tmp/hbase-hbase/hbase/.logs/localhost.localdomain,50781,1318937790362 doesn't belong to a known region server, splitting
2011-10-18 08:27:32,428 INFO org.apache.hadoop.hbase.regionserver.wal.HLogSplitter: Splitting 1 hlog(s) in file:/tmp/hbase-hbase/hbase/.logs/localhost.localdomain,50781,1318937790362
2011-10-18 08:27:32,429 DEBUG org.apache.hadoop.hbase.regionserver.wal.HLogSplitter: Writer thread Thread[WriterThread-0,5,main]: starting
2011-10-18 08:27:32,434 DEBUG org.apache.hadoop.hbase.regionserver.wal.HLogSplitter: Splitting hlog 1 of 1: file:/tmp/hbase-hbase/hbase/.logs/localhost.localdomain,50781,1318937790362/localhost.localdomain%3A50781.1318937795015, length=307
2011-10-18 08:27:32,435 WARN org.apache.hadoop.hbase.util.FSUtils: Running on HDFS without append enabled may result in data loss
2011-10-18 08:27:32,440 DEBUG org.apache.hadoop.hbase.regionserver.wal.HLogSplitter: Writer thread Thread[WriterThread-2,5,main]: starting
2011-10-18 08:27:32,443 DEBUG org.apache.hadoop.hbase.regionserver.wal.HLogSplitter: Writer thread Thread[WriterThread-1,5,main]: starting
2011-10-18 08:27:32,454 WARN org.apache.hadoop.hbase.regionserver.wal.SequenceFileLogReader: Error while trying to get accurate file length. Truncation / data loss may occur if RegionServers die.
java.lang.NoSuchMethodException: org.apache.hadoop.fs.ChecksumFileSystem$ChecksumFSInputChecker.getFileLength()
at java.lang.Class.getMethod(Class.java:1605)
at org.apache.hadoop.hbase.regionserver.wal.SequenceFileLogReader$WALReader$WALReaderFSDataInputStream.getPos(SequenceFileLogReader.java:107)
at org.apache.hadoop.io.SequenceFile$Reader.<init>(SequenceFile.java:1436)
at org.apache.hadoop.io.SequenceFile$Reader.<init>(SequenceFile.java:1424)
at org.apache.hadoop.io.SequenceFile$Reader.<init>(SequenceFile.java:1419)
at org.apache.hadoop.hbase.regionserver.wal.SequenceFileLogReader$WALReader.<init>(SequenceFileLogReader.java:57)
at org.apache.hadoop.hbase.regionserver.wal.SequenceFileLogReader.init(SequenceFileLogReader.java:158)
at org.apache.hadoop.hbase.regionserver.wal.HLog.getReader(HLog.java:575)
at org.apache.hadoop.hbase.regionserver.wal.HLogSplitter.getReader(HLogSplitter.java:477)
at org.apache.hadoop.hbase.regionserver.wal.HLogSplitter.parseHLog(HLogSplitter.java:414)
at org.apache.hadoop.hbase.regionserver.wal.HLogSplitter.splitLog(HLogSplitter.java:262)
at org.apache.hadoop.hbase.regionserver.wal.HLogSplitter.splitLog(HLogSplitter.java:188)
at org.apache.hadoop.hbase.master.MasterFileSystem.splitLog(MasterFileSystem.java:197)
at org.apache.hadoop.hbase.master.MasterFileSystem.splitLogAfterStartup(MasterFileSystem.java:181)
at org.apache.hadoop.hbase.master.HMaster.finishInitialization(HMaster.java:385)
at org.apache.hadoop.hbase.master.HMaster.run(HMaster.java:283)
at org.apache.hadoop.hbase.master.HMasterCommandLine$LocalHMaster.run(HMasterCommandLine.java:193)
at java.lang.Thread.run(Thread.java:619)
2011-10-18 08:27:33,063 DEBUG org.apache.hadoop.hbase.regionserver.wal.HLogSplitter: Pushed=1 entries from file:/tmp/hbase-hbase/hbase/.logs/localhost.localdomain,50781,1318937790362/localhost.localdomain%3A50781.1318937795015
2011-10-18 08:27:33,069 INFO org.apache.hadoop.hbase.regionserver.wal.HLogSplitter: Archived processed log file:/tmp/hbase-hbase/hbase/.logs/localhost.localdomain,50781,1318937790362/localhost.localdomain%3A50781.1318937795015 to file:/tmp/hbase-hbase/hbase/.oldlogs/localhost.localdomain%3A50781.1318937795015
2011-10-18 08:27:33,069 INFO org.apache.hadoop.hbase.regionserver.wal.HLogSplitter: Waiting for split writer threads to finish
2011-10-18 08:27:33,078 INFO org.apache.hadoop.hbase.regionserver.wal.SequenceFileLogWriter: syncFs -- HDFS-200 -- not available, dfs.support.append=false
2011-10-18 08:27:33,079 DEBUG org.apache.hadoop.hbase.regionserver.wal.HLogSplitter: Creating writer path=file:/tmp/hbase-hbase/hbase/-ROOT-/70236052/recovered.edits/0000000000000000007 region=70236052
2011-10-18 08:27:33,079 INFO org.apache.hadoop.hbase.regionserver.wal.HLogSplitter: Split writers finished
2011-10-18 08:27:33,080 INFO org.apache.hadoop.hbase.regionserver.wal.HLogSplitter: Closed path file:/tmp/hbase-hbase/hbase/-ROOT-/70236052/recovered.edits/0000000000000000007 (wrote 1 edits in 17ms)
2011-10-18 08:27:33,080 INFO org.apache.hadoop.hbase.regionserver.wal.HLogSplitter: hlog file splitting completed in 657 ms for file:/tmp/hbase-hbase/hbase/.logs/localhost.localdomain,50781,1318937790362
2011-10-18 08:27:34,087 INFO org.apache.hadoop.hbase.catalog.RootLocationEditor: Unsetting ROOT region location in ZooKeeper
2011-10-18 08:27:34,089 INFO org.apache.zookeeper.server.PrepRequestProcessor: Got user-level KeeperException when processing sessionid:0x1331700150e0000 type:delete cxid:0x15 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/hbase/root-region-server Error:KeeperErrorCode = NoNode for /hbase/root-region-server
2011-10-18 08:27:34,092 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: master:49977-0x1331700150e0000 Creating (or updating) unassigned node for 70236052 with OFFLINE state
2011-10-18 08:27:34,098 DEBUG org.apache.hadoop.hbase.master.AssignmentManager: No previous transition plan was found (or we are ignoring an existing plan) for -ROOT-,,0.70236052 so generated a random one; hri=-ROOT-,,0.70236052, src=, dest=localhost.localdomain,57754,1318940844922; 1 (online=1, exclude=null) available servers
2011-10-18 08:27:34,098 DEBUG org.apache.hadoop.hbase.master.AssignmentManager: Assigning region -ROOT-,,0.70236052 to localhost.localdomain,57754,1318940844922
2011-10-18 08:27:34,098 DEBUG org.apache.hadoop.hbase.master.ServerManager: New connection to localhost.localdomain,57754,1318940844922
2011-10-18 08:27:34,131 INFO org.apache.hadoop.hbase.regionserver.HRegionServer: Received request to open region: -ROOT-,,0.70236052
2011-10-18 08:27:34,145 DEBUG org.apache.hadoop.hbase.regionserver.handler.OpenRegionHandler: Processing open of -ROOT-,,0.70236052
2011-10-18 08:27:34,146 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: regionserver:57754-0x1331700150e0002 Attempting to transition node 70236052/-ROOT- from M_ZK_REGION_OFFLINE to RS_ZK_REGION_OPENING
2011-10-18 08:27:34,153 DEBUG org.apache.hadoop.hbase.master.AssignmentManager: Handling transition=RS_ZK_REGION_OPENING, server=localhost.localdomain,57754,1318940844922, region=70236052/-ROOT-
2011-10-18 08:27:34,154 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: regionserver:57754-0x1331700150e0002 Successfully transitioned node 70236052 from M_ZK_REGION_OFFLINE to RS_ZK_REGION_OPENING
2011-10-18 08:27:34,155 DEBUG org.apache.hadoop.hbase.regionserver.HRegion: Opening region: REGION => {NAME => '-ROOT-,,0', STARTKEY => '', ENDKEY => '', ENCODED => 70236052, TABLE => {{NAME => '-ROOT-', IS_ROOT => 'true', IS_META => 'true', FAMILIES => [{NAME => 'info', BLOOMFILTER => 'NONE', REPLICATION_SCOPE => '0', VERSIONS => '10', COMPRESSION => 'NONE', TTL => '2147483647', BLOCKSIZE => '8192', IN_MEMORY => 'true', BLOCKCACHE => 'true'}]}}
2011-10-18 08:27:34,156 DEBUG org.apache.hadoop.hbase.regionserver.HRegion: Instantiated -ROOT-,,0.70236052
2011-10-18 08:27:34,269 DEBUG org.apache.hadoop.hbase.regionserver.Store: loaded file:/tmp/hbase-hbase/hbase/-ROOT-/70236052/info/2226863419614596666, isReference=false, isBulkLoadResult=false, seqid=2, majorCompaction=false
2011-10-18 08:27:34,285 DEBUG org.apache.hadoop.hbase.regionserver.Store: loaded file:/tmp/hbase-hbase/hbase/-ROOT-/70236052/info/8233054724424930581, isReference=false, isBulkLoadResult=false, seqid=5, majorCompaction=false
2011-10-18 08:27:34,325 INFO org.apache.hadoop.hbase.regionserver.HRegion: Replaying edits from file:/tmp/hbase-hbase/hbase/-ROOT-/70236052/recovered.edits/0000000000000000007; minSequenceid=5
2011-10-18 08:27:34,327 WARN org.apache.hadoop.hbase.regionserver.wal.SequenceFileLogReader: Error while trying to get accurate file length. Truncation / data loss may occur if RegionServers die.
java.lang.NoSuchMethodException: org.apache.hadoop.fs.ChecksumFileSystem$ChecksumFSInputChecker.getFileLength()
at java.lang.Class.getMethod(Class.java:1605)
at org.apache.hadoop.hbase.regionserver.wal.SequenceFileLogReader$WALReader$WALReaderFSDataInputStream.getPos(SequenceFileLogReader.java:107)
at org.apache.hadoop.io.SequenceFile$Reader.<init>(SequenceFile.java:1436)
at org.apache.hadoop.io.SequenceFile$Reader.<init>(SequenceFile.java:1424)
at org.apache.hadoop.io.SequenceFile$Reader.<init>(SequenceFile.java:1419)
at org.apache.hadoop.hbase.regionserver.wal.SequenceFileLogReader$WALReader.<init>(SequenceFileLogReader.java:57)
at org.apache.hadoop.hbase.regionserver.wal.SequenceFileLogReader.init(SequenceFileLogReader.java:158)
at org.apache.hadoop.hbase.regionserver.wal.HLog.getReader(HLog.java:575)
at org.apache.hadoop.hbase.regionserver.HRegion.replayRecoveredEdits(HRegion.java:1875)
at org.apache.hadoop.hbase.regionserver.HRegion.replayRecoveredEditsIfAny(HRegion.java:1835)
at org.apache.hadoop.hbase.regionserver.HRegion.initialize(HRegion.java:354)
at org.apache.hadoop.hbase.regionserver.HRegion.openHRegion(HRegion.java:2553)
at org.apache.hadoop.hbase.regionserver.HRegion.openHRegion(HRegion.java:2539)
at org.apache.hadoop.hbase.regionserver.handler.OpenRegionHandler.openRegion(OpenRegionHandler.java:272)
at org.apache.hadoop.hbase.regionserver.handler.OpenRegionHandler.process(OpenRegionHandler.java:99)
at org.apache.hadoop.hbase.executor.EventHandler.run(EventHandler.java:156)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
at java.lang.Thread.run(Thread.java:619)
2011-10-18 08:27:34,329 DEBUG org.apache.hadoop.hbase.regionserver.HRegion: Applied 2, skipped 0, firstSequenceidInLog=7, maxSequenceidInLog=7
2011-10-18 08:27:34,329 DEBUG org.apache.hadoop.hbase.regionserver.HRegion: Started memstore flush for -ROOT-,,0.70236052, current region memstore size 480.0; wal is null, using passed sequenceid=7
2011-10-18 08:27:34,329 DEBUG org.apache.hadoop.hbase.regionserver.HRegion: Finished snapshotting, commencing flushing stores
2011-10-18 08:27:34,417 INFO org.apache.hadoop.hbase.regionserver.Store: Renaming flushed file at file:/tmp/hbase-hbase/hbase/-ROOT-/70236052/.tmp/7507925448071592382 to file:/tmp/hbase-hbase/hbase/-ROOT-/70236052/info/6152135076013786807
2011-10-18 08:27:34,419 INFO org.apache.hadoop.hbase.regionserver.Store: Added file:/tmp/hbase-hbase/hbase/-ROOT-/70236052/info/6152135076013786807, entries=2, sequenceid=7, memsize=480.0, filesize=514.0
2011-10-18 08:27:34,419 INFO org.apache.hadoop.hbase.regionserver.HRegion: Finished memstore flush of ~480.0 for region -ROOT-,,0.70236052 in 90ms, sequenceid=7, compaction requested=true; wal=null
2011-10-18 08:27:34,443 DEBUG org.apache.hadoop.hbase.regionserver.HRegion: Deleted recovered.edits file=file:/tmp/hbase-hbase/hbase/-ROOT-/70236052/recovered.edits/0000000000000000007
2011-10-18 08:27:34,444 INFO org.apache.hadoop.hbase.regionserver.HRegion: Onlined -ROOT-,,0.70236052; next sequenceid=8
2011-10-18 08:27:34,444 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: regionserver:57754-0x1331700150e0002 Attempting to transition node 70236052/-ROOT- from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENING
2011-10-18 08:27:34,449 DEBUG org.apache.hadoop.hbase.master.AssignmentManager: Handling transition=RS_ZK_REGION_OPENING, server=localhost.localdomain,57754,1318940844922, region=70236052/-ROOT-
2011-10-18 08:27:34,449 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: regionserver:57754-0x1331700150e0002 Successfully transitioned node 70236052 from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENING
2011-10-18 08:27:34,450 INFO org.apache.hadoop.hbase.catalog.RootLocationEditor: Setting ROOT region location in ZooKeeper as localhost.localdomain:57754
2011-10-18 08:27:34,456 INFO org.apache.hadoop.hbase.master.HMaster: -ROOT- assigned=1, rit=false, location=localhost.localdomain:57754
2011-10-18 08:27:34,473 INFO org.apache.hadoop.ipc.HbaseRPC: Server at localhost.localdomain/127.0.0.1:50781 could not be reached after 1 tries, giving up.
2011-10-18 08:27:34,473 INFO org.apache.hadoop.hbase.catalog.CatalogTracker: Passed metaserver is null
2011-10-18 08:27:34,473 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: master:49977-0x1331700150e0000 Creating (or updating) unassigned node for 1028785192 with OFFLINE state
2011-10-18 08:27:34,477 DEBUG org.apache.hadoop.hbase.master.AssignmentManager: Handling transition=M_ZK_REGION_OFFLINE, server=localhost.localdomain:49977, region=1028785192/.META.
2011-10-18 08:27:34,478 DEBUG org.apache.hadoop.hbase.master.AssignmentManager: No previous transition plan was found (or we are ignoring an existing plan) for .META.,,1.1028785192 so generated a random one; hri=.META.,,1.1028785192, src=, dest=localhost.localdomain,57754,1318940844922; 1 (online=1, exclude=null) available servers
2011-10-18 08:27:34,478 DEBUG org.apache.hadoop.hbase.master.AssignmentManager: Assigning region .META.,,1.1028785192 to localhost.localdomain,57754,1318940844922
2011-10-18 08:27:34,479 INFO org.apache.hadoop.hbase.regionserver.HRegionServer: Received request to open region: .META.,,1.1028785192
2011-10-18 08:27:34,645 DEBUG org.apache.hadoop.hbase.regionserver.handler.OpenRegionHandler: Processing open of .META.,,1.1028785192
2011-10-18 08:27:34,645 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: regionserver:57754-0x1331700150e0002 Attempting to transition node 1028785192/.META. from M_ZK_REGION_OFFLINE to RS_ZK_REGION_OPENING
2011-10-18 08:27:34,647 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: regionserver:57754-0x1331700150e0002 Attempting to transition node 70236052/-ROOT- from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENED
2011-10-18 08:27:34,655 DEBUG org.apache.hadoop.hbase.master.AssignmentManager: Handling transition=RS_ZK_REGION_OPENING, server=localhost.localdomain,57754,1318940844922, region=1028785192/.META.
2011-10-18 08:27:34,656 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: regionserver:57754-0x1331700150e0002 Successfully transitioned node 1028785192 from M_ZK_REGION_OFFLINE to RS_ZK_REGION_OPENING
2011-10-18 08:27:34,656 DEBUG org.apache.hadoop.hbase.regionserver.HRegion: Opening region: REGION => {NAME => '.META.,,1', STARTKEY => '', ENDKEY => '', ENCODED => 1028785192, TABLE => {{NAME => '.META.', IS_META => 'true', FAMILIES => [{NAME => 'info', BLOOMFILTER => 'NONE', REPLICATION_SCOPE => '0', VERSIONS => '10', COMPRESSION => 'NONE', TTL => '2147483647', BLOCKSIZE => '8192', IN_MEMORY => 'true', BLOCKCACHE => 'true'}]}}
2011-10-18 08:27:34,657 DEBUG org.apache.hadoop.hbase.regionserver.HRegion: Instantiated .META.,,1.1028785192
2011-10-18 08:27:34,696 INFO org.apache.hadoop.hbase.regionserver.HRegion: Onlined .META.,,1.1028785192; next sequenceid=1
2011-10-18 08:27:34,697 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: regionserver:57754-0x1331700150e0002 Attempting to transition node 1028785192/.META. from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENING
2011-10-18 08:27:34,726 DEBUG org.apache.hadoop.hbase.master.AssignmentManager: Handling transition=RS_ZK_REGION_OPENED, server=localhost.localdomain,57754,1318940844922, region=70236052/-ROOT-
2011-10-18 08:27:34,727 DEBUG org.apache.hadoop.hbase.master.handler.OpenedRegionHandler: Handling OPENED event for 70236052; deleting unassigned node
2011-10-18 08:27:34,727 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: master:49977-0x1331700150e0000 Deleting existing unassigned node for 70236052 that is in expected state RS_ZK_REGION_OPENED
2011-10-18 08:27:34,729 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: regionserver:57754-0x1331700150e0002 Successfully transitioned node 70236052 from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENED
2011-10-18 08:27:34,729 DEBUG org.apache.hadoop.hbase.regionserver.handler.OpenRegionHandler: Opened -ROOT-,,0.70236052
2011-10-18 08:27:34,735 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: master:49977-0x1331700150e0000 Successfully deleted unassigned node for region 70236052 in expected state RS_ZK_REGION_OPENED
2011-10-18 08:27:34,735 DEBUG org.apache.hadoop.hbase.master.handler.OpenedRegionHandler: Opened region -ROOT-,,0.70236052 on localhost.localdomain,57754,1318940844922
2011-10-18 08:27:34,737 DEBUG org.apache.hadoop.hbase.master.AssignmentManager: Handling transition=RS_ZK_REGION_OPENING, server=localhost.localdomain,57754,1318940844922, region=1028785192/.META.
2011-10-18 08:27:34,738 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: regionserver:57754-0x1331700150e0002 Successfully transitioned node 1028785192 from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENING
2011-10-18 08:27:34,742 INFO org.apache.hadoop.hbase.catalog.MetaEditor: Updated row .META.,,1.1028785192 in region -ROOT-,,0 with server=localhost.localdomain:57754, startcode=1318940844922
2011-10-18 08:27:34,742 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: regionserver:57754-0x1331700150e0002 Attempting to transition node 1028785192/.META. from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENED
2011-10-18 08:27:34,745 DEBUG org.apache.hadoop.hbase.master.AssignmentManager: Handling transition=RS_ZK_REGION_OPENED, server=localhost.localdomain,57754,1318940844922, region=1028785192/.META.
2011-10-18 08:27:34,746 DEBUG org.apache.hadoop.hbase.master.handler.OpenedRegionHandler: Handling OPENED event for 1028785192; deleting unassigned node
2011-10-18 08:27:34,746 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: master:49977-0x1331700150e0000 Deleting existing unassigned node for 1028785192 that is in expected state RS_ZK_REGION_OPENED
2011-10-18 08:27:34,748 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: regionserver:57754-0x1331700150e0002 Successfully transitioned node 1028785192 from RS_ZK_REGION_OPENING to RS_ZK_REGION_OPENED
2011-10-18 08:27:34,748 DEBUG org.apache.hadoop.hbase.regionserver.handler.OpenRegionHandler: Opened .META.,,1.1028785192
2011-10-18 08:27:34,749 INFO org.apache.hadoop.hbase.zookeeper.MetaNodeTracker: Detected completed assignment of META, notifying catalog tracker
2011-10-18 08:27:34,750 INFO org.apache.hadoop.hbase.zookeeper.MetaNodeTracker: Detected completed assignment of META, notifying catalog tracker
2011-10-18 08:27:34,751 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: master:49977-0x1331700150e0000 Successfully deleted unassigned node for region 1028785192 in expected state RS_ZK_REGION_OPENED
2011-10-18 08:27:34,751 DEBUG org.apache.hadoop.hbase.master.handler.OpenedRegionHandler: Opened region .META.,,1.1028785192 on localhost.localdomain,57754,1318940844922
2011-10-18 08:27:34,755 INFO org.apache.hadoop.hbase.master.HMaster: .META. assigned=2, rit=false, location=localhost.localdomain:57754
2011-10-18 08:27:34,755 INFO org.apache.hadoop.hbase.master.HMaster: Master startup proceeding: cluster startup
2011-10-18 08:27:34,755 DEBUG org.apache.hadoop.hbase.zookeeper.ZKAssign: master:49977-0x1331700150e0000 Deleting any existing unassigned nodes
2011-10-18 08:27:35,035 INFO org.apache.hadoop.hbase.master.HMaster: Master has completed initialization
2011-10-18 08:27:35,038 DEBUG org.apache.hadoop.hbase.master.CatalogJanitor: Scanned 0 catalog row(s) and gc'd 0 unreferenced parent region(s)
2011-10-18 08:28:06,767 INFO org.apache.zookeeper.ZooKeeper: Initiating client connection, connectString=localhost:2182 sessionTimeout=180000 watcher=hconnection
2011-10-18 08:28:06,768 INFO org.apache.zookeeper.ClientCnxn: Opening socket connection to server localhost/127.0.0.1:2182
2011-10-18 08:28:06,768 INFO org.apache.zookeeper.server.NIOServerCnxn: Accepted socket connection from /127.0.0.1:48880
2011-10-18 08:28:06,769 INFO org.apache.zookeeper.ClientCnxn: Socket connection established to localhost/127.0.0.1:2182, initiating session
2011-10-18 08:28:06,769 INFO org.apache.zookeeper.server.NIOServerCnxn: Client attempting to establish new session at /127.0.0.1:48880
2011-10-18 08:28:06,780 INFO org.apache.zookeeper.server.NIOServerCnxn: Established session 0x1331700150e0004 with negotiated timeout 40000 for client /127.0.0.1:48880
2011-10-18 08:28:06,782 INFO org.apache.zookeeper.ClientCnxn: Session establishment complete on server localhost/127.0.0.1:2182, sessionid = 0x1331700150e0004, negotiated timeout = 40000
2011-10-18 08:28:06,800 DEBUG org.apache.hadoop.hbase.client.MetaScanner: Scanning .META. starting at row= for max=2147483647 rows
2011-10-18 08:28:06,801 DEBUG org.apache.hadoop.hbase.client.HConnectionManager$HConnectionImplementation: Lookedup root region location, connection=org.apache.hadoop.hbase.client.HConnectionManager$HConnectionImplementation@1b4b74a7; hsa=localhost.localdomain:57754
2011-10-18 08:28:06,822 DEBUG org.apache.hadoop.hbase.client.HConnectionManager$HConnectionImplementation: Cached location for .META.,,1.1028785192 is localhost.localdomain:57754
2011-10-18 08:28:06,824 INFO org.apache.hadoop.hbase.client.HConnectionManager$HConnectionImplementation: Closed zookeeper sessionid=0x1331700150e0004
2011-10-18 08:28:06,824 INFO org.apache.zookeeper.server.PrepRequestProcessor: Processed session termination for sessionid: 0x1331700150e0004
2011-10-18 08:28:06,828 INFO org.apache.zookeeper.server.NIOServerCnxn: Closed socket connection for client /127.0.0.1:48880 which had sessionid 0x1331700150e0004
2011-10-18 08:28:06,829 INFO org.apache.zookeeper.ZooKeeper: Session: 0x1331700150e0004 closed
2011-10-18 08:28:06,837 INFO org.apache.zookeeper.ClientCnxn: EventThread shut down
Re: HBase Rest & Zookeeper issue
Posted by Ted Yu <yu...@gmail.com>.
For item 2 below, patch for HBASE-4508 (Backport HBASE-3777 to 0.90
branch<https://issues.apache.org/jira/browse/HBASE-4508>)
has been ready for review / verification.
Cheers
On Mon, Oct 17, 2011 at 5:44 AM, Andrew Purtell <ap...@apache.org> wrote:
> Pardon for any confusion (too late? :-) ) but this looks like a known HBase
> client bug.
>
> HBASE-3777 (https://issues.apache.org/jira/browse/HBASE-3777) has
> background.
>
> Here is what I recommend:
>
> 1) Use a build from the head of 0.90 branch, not a CDH build (I have no
> idea what revision that corresponds to)*
>
> and if that is not sufficient
>
> 2) We will need to apply HBASE-3777 to 0.90 branch.
>
> * - I reviewed the REST code on the 0.90 branch. It takes care to reuse a
> Configuration object and a common HTable pool for all table access.
>
> - Andy
>
>
> ----- Original Message -----
> > From: Ronen Itkin <ro...@taykey.com>
> > To: user@hbase.apache.org; Andrew Purtell <ap...@apache.org>
> > Cc:
> > Sent: Monday, October 17, 2011 6:12 PM
> > Subject: Re: HBase Rest & Zookeeper issue
> >
> > Hey,
> >
> > Another update, I had just stopped the Rest Service and the number of
> > zookeeper client connections from that server dropped from 513 to 3.
> >
> >
> >
> > On Mon, Oct 17, 2011 at 11:57 AM, Ronen Itkin <ro...@taykey.com> wrote:
> >
> >> Hey Andrew,
> >>
> >> Thanks for the response,
> >> Please note that the majority of zookeeper client connections are being
> >> made from the Rest service itself and not from any other Java HBase
> Client,
> >> Moreover, Rest Client address the Rest Service itself and not
> zookeepeer
> >> (while The rest Service works with zookeeper-->hbase at the
> background).
> >> So, I guess its not something in our code, but something regarding Rest
> >> and/or ZooKeeper operations.
> >>
> >> To be certain that the connections grow mainly because the Rest Service
> and
> >> not because of other HBase Java Clients, I will shut it down for 5-6
> Hours.
> >>
> >> Can you please aleborate more about using a "shared single
> > instance" ? is
> >> that something configurable for the Rest implementation?
> >> Is there any possibility that a Java HBase client is not using cache
> for
> >> zookeeper queries?
> >>
> >> Thanks,
> >>
> >>
> >> On Mon, Oct 17, 2011 at 4:39 AM, Andrew Purtell
> > <ap...@apache.org>wrote:
> >>
> >>> It may be sufficient for you to simply use the latest ASF release of
> > HBase
> >>> 0.90 instead of the CDH version. (Or use a snapshot from
> >>> nightly.cloudera.com ?) The leaking of ZooKeeper connections suggests
> a
> >>> particular problem. I went through the REST code on the head of the
> > 0.90
> >>> branch and did not find it; the code is (re)using a shared
> >>> Configuration instance.
> >>>
> >>> If you have written client HBase java code, you should also audit your
> >>> code and insure you are NOT creating a new Configuration object
> > instance
> >>> whenever you create a new HTable object, instead share a single
> > instance.
> >>> Also, insure you are not creating HTable objects without passing in a
> > shared
> >>> Configuration.
> >>>
> >>>
> >>> Another option is to patch the HBase client, to address the likely
> >>> underlying problem.See HBASE-3777 / HBASE-4508.
> >>>
> >>> https://issues.apache.org/jira/browse/HBASE-3777
> >>> https://issues.apache.org/jira/browse/HBASE-4508
> >>>
> >>> Best regards,
> >>>
> >>>
> >>> - Andy
> >>>
> >>> Problems worthy of attack prove their worth by hitting back. - Piet
> > Hein
> >>> (via Tom White)
> >>>
> >>>
> >>> ----- Original Message -----
> >>> > From: Ronen Itkin <ro...@taykey.com>
> >>> > To: user@hbase.apache.org
> >>> > Cc:
> >>> > Sent: Sunday, October 16, 2011 8:32 PM
> >>> > Subject: HBase Rest & Zookeeper issue
> >>> >
> >>> > Hey all!
> >>> >
> >>> > At first it my seem like a Zookeeper issue, but the thing is that
> > it is
> >>> very
> >>> > HBase related so I figured to send it to this mailing list as
> > well.
> >>> > I am currently using Zookeeper 3.3.3-cdh3u1, installed as a
> > distributed
> >>> > cluster with 3 nodes.
> >>> > Though I have installed Zookeeper separately, its only purpose
> > right now
> >>> is
> >>> > to serve HBase clients (hbase-0.90.3-cdh3u1).
> >>> > Seems like everything is working great for a day or two and then
> > out the
> >>> > blue, Zookeeper refuses to serve clients requests,
> >>> > alerting for the wide known issue of exceeding the defined maximum
> >>> > connections allowed for a client.
> >>> > I changed this value to 500 and it seems that it just held on for
> > more
> >>> time
> >>> > and finally reached the threshold of 500 and then stopped working.
> >>> > So, I set it to 1000 and right now I am waiting to see what will
> > happen.
> >>> >
> >>> > Meanwhile, by auditing the Zookeeper connections manually it seems
> > like
> >>> they
> >>> > keep growing in a slow - promising pace towards the threshold of
> > 1000
> >>> > connections.
> >>> > I have tried to analyze the connections and it looks like almost
> > all of
> >>> the
> >>> > connections were established from the HBase Rest service towards
> >>> zookeeper.
> >>> >
> >>> > Can someone think of a reason why it keep growing? Does someone
> > has any
> >>> > other suggestions regarding this issue?
> >>> > Are there any known issues regarding this situation, combining
> > Rest and
> >>> > Zookeeper?
> >>> >
> >>> > If it helps, this is my environment design:
> >>> >
> >>> > - Server 1 - Hadoop NameNode, JobTracker, *Hbase Master
> > (Including
> >>> Rest)*,
> >>> > *Zookeeper01*
> >>> > - Server 2 - Hadoop SecondaryMaster, HBase *Backup Master
> > (Including
> >>> > Rest)*, *Zookeeper02*
> >>> > - Server 3 - *Zookeeper03*
> >>> > - Servers 4-6 - Hadoop DataNode,TaskTracker, *HBase Region
> > Server.*
> >>> >
> >>> > The type of operations I am committing on HBase using Zookeeper
> > are:
> >>> >
> >>> > - Simple read/writes/updates using SCAN / MapReduce / Cascading
> > ..
> >>> > - Queries of the *Rest* service.
> >>> >
> >>> >
> >>> > Thanks a lot !!!
> >>> > * *Ronen Itkin
> >>> >
> >>>
> >>
> >>
> >>
> >> --
> >> *
> >> Ronen Itkin*
> >> Taykey | www.taykey.com
> >>
> >>
> >
> >
> > --
> > *
> > Ronen Itkin*
> > Taykey | www.taykey.com
> >
>
Re: HBase Rest & Zookeeper issue
Posted by Andrew Purtell <ap...@apache.org>.
Pardon for any confusion (too late? :-) ) but this looks like a known HBase client bug.
HBASE-3777 (https://issues.apache.org/jira/browse/HBASE-3777) has background.
Here is what I recommend:
1) Use a build from the head of 0.90 branch, not a CDH build (I have no idea what revision that corresponds to)*
and if that is not sufficient
2) We will need to apply HBASE-3777 to 0.90 branch.
* - I reviewed the REST code on the 0.90 branch. It takes care to reuse a Configuration object and a common HTable pool for all table access.
- Andy
----- Original Message -----
> From: Ronen Itkin <ro...@taykey.com>
> To: user@hbase.apache.org; Andrew Purtell <ap...@apache.org>
> Cc:
> Sent: Monday, October 17, 2011 6:12 PM
> Subject: Re: HBase Rest & Zookeeper issue
>
> Hey,
>
> Another update, I had just stopped the Rest Service and the number of
> zookeeper client connections from that server dropped from 513 to 3.
>
>
>
> On Mon, Oct 17, 2011 at 11:57 AM, Ronen Itkin <ro...@taykey.com> wrote:
>
>> Hey Andrew,
>>
>> Thanks for the response,
>> Please note that the majority of zookeeper client connections are being
>> made from the Rest service itself and not from any other Java HBase Client,
>> Moreover, Rest Client address the Rest Service itself and not zookeepeer
>> (while The rest Service works with zookeeper-->hbase at the background).
>> So, I guess its not something in our code, but something regarding Rest
>> and/or ZooKeeper operations.
>>
>> To be certain that the connections grow mainly because the Rest Service and
>> not because of other HBase Java Clients, I will shut it down for 5-6 Hours.
>>
>> Can you please aleborate more about using a "shared single
> instance" ? is
>> that something configurable for the Rest implementation?
>> Is there any possibility that a Java HBase client is not using cache for
>> zookeeper queries?
>>
>> Thanks,
>>
>>
>> On Mon, Oct 17, 2011 at 4:39 AM, Andrew Purtell
> <ap...@apache.org>wrote:
>>
>>> It may be sufficient for you to simply use the latest ASF release of
> HBase
>>> 0.90 instead of the CDH version. (Or use a snapshot from
>>> nightly.cloudera.com ?) The leaking of ZooKeeper connections suggests a
>>> particular problem. I went through the REST code on the head of the
> 0.90
>>> branch and did not find it; the code is (re)using a shared
>>> Configuration instance.
>>>
>>> If you have written client HBase java code, you should also audit your
>>> code and insure you are NOT creating a new Configuration object
> instance
>>> whenever you create a new HTable object, instead share a single
> instance.
>>> Also, insure you are not creating HTable objects without passing in a
> shared
>>> Configuration.
>>>
>>>
>>> Another option is to patch the HBase client, to address the likely
>>> underlying problem.See HBASE-3777 / HBASE-4508.
>>>
>>> https://issues.apache.org/jira/browse/HBASE-3777
>>> https://issues.apache.org/jira/browse/HBASE-4508
>>>
>>> Best regards,
>>>
>>>
>>> - Andy
>>>
>>> Problems worthy of attack prove their worth by hitting back. - Piet
> Hein
>>> (via Tom White)
>>>
>>>
>>> ----- Original Message -----
>>> > From: Ronen Itkin <ro...@taykey.com>
>>> > To: user@hbase.apache.org
>>> > Cc:
>>> > Sent: Sunday, October 16, 2011 8:32 PM
>>> > Subject: HBase Rest & Zookeeper issue
>>> >
>>> > Hey all!
>>> >
>>> > At first it my seem like a Zookeeper issue, but the thing is that
> it is
>>> very
>>> > HBase related so I figured to send it to this mailing list as
> well.
>>> > I am currently using Zookeeper 3.3.3-cdh3u1, installed as a
> distributed
>>> > cluster with 3 nodes.
>>> > Though I have installed Zookeeper separately, its only purpose
> right now
>>> is
>>> > to serve HBase clients (hbase-0.90.3-cdh3u1).
>>> > Seems like everything is working great for a day or two and then
> out the
>>> > blue, Zookeeper refuses to serve clients requests,
>>> > alerting for the wide known issue of exceeding the defined maximum
>>> > connections allowed for a client.
>>> > I changed this value to 500 and it seems that it just held on for
> more
>>> time
>>> > and finally reached the threshold of 500 and then stopped working.
>>> > So, I set it to 1000 and right now I am waiting to see what will
> happen.
>>> >
>>> > Meanwhile, by auditing the Zookeeper connections manually it seems
> like
>>> they
>>> > keep growing in a slow - promising pace towards the threshold of
> 1000
>>> > connections.
>>> > I have tried to analyze the connections and it looks like almost
> all of
>>> the
>>> > connections were established from the HBase Rest service towards
>>> zookeeper.
>>> >
>>> > Can someone think of a reason why it keep growing? Does someone
> has any
>>> > other suggestions regarding this issue?
>>> > Are there any known issues regarding this situation, combining
> Rest and
>>> > Zookeeper?
>>> >
>>> > If it helps, this is my environment design:
>>> >
>>> > - Server 1 - Hadoop NameNode, JobTracker, *Hbase Master
> (Including
>>> Rest)*,
>>> > *Zookeeper01*
>>> > - Server 2 - Hadoop SecondaryMaster, HBase *Backup Master
> (Including
>>> > Rest)*, *Zookeeper02*
>>> > - Server 3 - *Zookeeper03*
>>> > - Servers 4-6 - Hadoop DataNode,TaskTracker, *HBase Region
> Server.*
>>> >
>>> > The type of operations I am committing on HBase using Zookeeper
> are:
>>> >
>>> > - Simple read/writes/updates using SCAN / MapReduce / Cascading
> ..
>>> > - Queries of the *Rest* service.
>>> >
>>> >
>>> > Thanks a lot !!!
>>> > * *Ronen Itkin
>>> >
>>>
>>
>>
>>
>> --
>> *
>> Ronen Itkin*
>> Taykey | www.taykey.com
>>
>>
>
>
> --
> *
> Ronen Itkin*
> Taykey | www.taykey.com
>
Re: HBase Rest & Zookeeper issue
Posted by Ronen Itkin <ro...@taykey.com>.
Hey,
Another update, I had just stopped the Rest Service and the number of
zookeeper client connections from that server dropped from 513 to 3.
On Mon, Oct 17, 2011 at 11:57 AM, Ronen Itkin <ro...@taykey.com> wrote:
> Hey Andrew,
>
> Thanks for the response,
> Please note that the majority of zookeeper client connections are being
> made from the Rest service itself and not from any other Java HBase Client,
> Moreover, Rest Client address the Rest Service itself and not zookeepeer
> (while The rest Service works with zookeeper-->hbase at the background).
> So, I guess its not something in our code, but something regarding Rest
> and/or ZooKeeper operations.
>
> To be certain that the connections grow mainly because the Rest Service and
> not because of other HBase Java Clients, I will shut it down for 5-6 Hours.
>
> Can you please aleborate more about using a "shared single instance" ? is
> that something configurable for the Rest implementation?
> Is there any possibility that a Java HBase client is not using cache for
> zookeeper queries?
>
> Thanks,
>
>
> On Mon, Oct 17, 2011 at 4:39 AM, Andrew Purtell <ap...@apache.org>wrote:
>
>> It may be sufficient for you to simply use the latest ASF release of HBase
>> 0.90 instead of the CDH version. (Or use a snapshot from
>> nightly.cloudera.com ?) The leaking of ZooKeeper connections suggests a
>> particular problem. I went through the REST code on the head of the 0.90
>> branch and did not find it; the code is (re)using a shared
>> Configuration instance.
>>
>> If you have written client HBase java code, you should also audit your
>> code and insure you are NOT creating a new Configuration object instance
>> whenever you create a new HTable object, instead share a single instance.
>> Also, insure you are not creating HTable objects without passing in a shared
>> Configuration.
>>
>>
>> Another option is to patch the HBase client, to address the likely
>> underlying problem.See HBASE-3777 / HBASE-4508.
>>
>> https://issues.apache.org/jira/browse/HBASE-3777
>> https://issues.apache.org/jira/browse/HBASE-4508
>>
>> Best regards,
>>
>>
>> - Andy
>>
>> Problems worthy of attack prove their worth by hitting back. - Piet Hein
>> (via Tom White)
>>
>>
>> ----- Original Message -----
>> > From: Ronen Itkin <ro...@taykey.com>
>> > To: user@hbase.apache.org
>> > Cc:
>> > Sent: Sunday, October 16, 2011 8:32 PM
>> > Subject: HBase Rest & Zookeeper issue
>> >
>> > Hey all!
>> >
>> > At first it my seem like a Zookeeper issue, but the thing is that it is
>> very
>> > HBase related so I figured to send it to this mailing list as well.
>> > I am currently using Zookeeper 3.3.3-cdh3u1, installed as a distributed
>> > cluster with 3 nodes.
>> > Though I have installed Zookeeper separately, its only purpose right now
>> is
>> > to serve HBase clients (hbase-0.90.3-cdh3u1).
>> > Seems like everything is working great for a day or two and then out the
>> > blue, Zookeeper refuses to serve clients requests,
>> > alerting for the wide known issue of exceeding the defined maximum
>> > connections allowed for a client.
>> > I changed this value to 500 and it seems that it just held on for more
>> time
>> > and finally reached the threshold of 500 and then stopped working.
>> > So, I set it to 1000 and right now I am waiting to see what will happen.
>> >
>> > Meanwhile, by auditing the Zookeeper connections manually it seems like
>> they
>> > keep growing in a slow - promising pace towards the threshold of 1000
>> > connections.
>> > I have tried to analyze the connections and it looks like almost all of
>> the
>> > connections were established from the HBase Rest service towards
>> zookeeper.
>> >
>> > Can someone think of a reason why it keep growing? Does someone has any
>> > other suggestions regarding this issue?
>> > Are there any known issues regarding this situation, combining Rest and
>> > Zookeeper?
>> >
>> > If it helps, this is my environment design:
>> >
>> > - Server 1 - Hadoop NameNode, JobTracker, *Hbase Master (Including
>> Rest)*,
>> > *Zookeeper01*
>> > - Server 2 - Hadoop SecondaryMaster, HBase *Backup Master (Including
>> > Rest)*, *Zookeeper02*
>> > - Server 3 - *Zookeeper03*
>> > - Servers 4-6 - Hadoop DataNode,TaskTracker, *HBase Region Server.*
>> >
>> > The type of operations I am committing on HBase using Zookeeper are:
>> >
>> > - Simple read/writes/updates using SCAN / MapReduce / Cascading ..
>> > - Queries of the *Rest* service.
>> >
>> >
>> > Thanks a lot !!!
>> > * *Ronen Itkin
>> >
>>
>
>
>
> --
> *
> Ronen Itkin*
> Taykey | www.taykey.com
>
>
--
*
Ronen Itkin*
Taykey | www.taykey.com
Re: HBase Rest & Zookeeper issue
Posted by Ronen Itkin <ro...@taykey.com>.
Hey Andrew,
Thanks for the response,
Please note that the majority of zookeeper client connections are being made
from the Rest service itself and not from any other Java HBase Client,
Moreover, Rest Client address the Rest Service itself and not zookeepeer
(while The rest Service works with zookeeper-->hbase at the background).
So, I guess its not something in our code, but something regarding Rest
and/or ZooKeeper operations.
To be certain that the connections grow mainly because the Rest Service and
not because of other HBase Java Clients, I will shut it down for 5-6 Hours.
Can you please aleborate more about using a "shared single instance" ? is
that something configurable for the Rest implementation?
Is there any possibility that a Java HBase client is not using cache for
zookeeper queries?
Thanks,
On Mon, Oct 17, 2011 at 4:39 AM, Andrew Purtell <ap...@apache.org> wrote:
> It may be sufficient for you to simply use the latest ASF release of HBase
> 0.90 instead of the CDH version. (Or use a snapshot from
> nightly.cloudera.com ?) The leaking of ZooKeeper connections suggests a
> particular problem. I went through the REST code on the head of the 0.90
> branch and did not find it; the code is (re)using a shared
> Configuration instance.
>
> If you have written client HBase java code, you should also audit your code
> and insure you are NOT creating a new Configuration object instance whenever
> you create a new HTable object, instead share a single instance. Also,
> insure you are not creating HTable objects without passing in a shared
> Configuration.
>
>
> Another option is to patch the HBase client, to address the likely
> underlying problem.See HBASE-3777 / HBASE-4508.
>
> https://issues.apache.org/jira/browse/HBASE-3777
> https://issues.apache.org/jira/browse/HBASE-4508
>
> Best regards,
>
>
> - Andy
>
> Problems worthy of attack prove their worth by hitting back. - Piet Hein
> (via Tom White)
>
>
> ----- Original Message -----
> > From: Ronen Itkin <ro...@taykey.com>
> > To: user@hbase.apache.org
> > Cc:
> > Sent: Sunday, October 16, 2011 8:32 PM
> > Subject: HBase Rest & Zookeeper issue
> >
> > Hey all!
> >
> > At first it my seem like a Zookeeper issue, but the thing is that it is
> very
> > HBase related so I figured to send it to this mailing list as well.
> > I am currently using Zookeeper 3.3.3-cdh3u1, installed as a distributed
> > cluster with 3 nodes.
> > Though I have installed Zookeeper separately, its only purpose right now
> is
> > to serve HBase clients (hbase-0.90.3-cdh3u1).
> > Seems like everything is working great for a day or two and then out the
> > blue, Zookeeper refuses to serve clients requests,
> > alerting for the wide known issue of exceeding the defined maximum
> > connections allowed for a client.
> > I changed this value to 500 and it seems that it just held on for more
> time
> > and finally reached the threshold of 500 and then stopped working.
> > So, I set it to 1000 and right now I am waiting to see what will happen.
> >
> > Meanwhile, by auditing the Zookeeper connections manually it seems like
> they
> > keep growing in a slow - promising pace towards the threshold of 1000
> > connections.
> > I have tried to analyze the connections and it looks like almost all of
> the
> > connections were established from the HBase Rest service towards
> zookeeper.
> >
> > Can someone think of a reason why it keep growing? Does someone has any
> > other suggestions regarding this issue?
> > Are there any known issues regarding this situation, combining Rest and
> > Zookeeper?
> >
> > If it helps, this is my environment design:
> >
> > - Server 1 - Hadoop NameNode, JobTracker, *Hbase Master (Including
> Rest)*,
> > *Zookeeper01*
> > - Server 2 - Hadoop SecondaryMaster, HBase *Backup Master (Including
> > Rest)*, *Zookeeper02*
> > - Server 3 - *Zookeeper03*
> > - Servers 4-6 - Hadoop DataNode,TaskTracker, *HBase Region Server.*
> >
> > The type of operations I am committing on HBase using Zookeeper are:
> >
> > - Simple read/writes/updates using SCAN / MapReduce / Cascading ..
> > - Queries of the *Rest* service.
> >
> >
> > Thanks a lot !!!
> > * *Ronen Itkin
> >
>
--
*
Ronen Itkin*
Taykey | www.taykey.com
Re: HBase Rest & Zookeeper issue
Posted by Ted Yu <yu...@gmail.com>.
Ronen:
HBASE-4508 has been verified at rocketfuel.com for 5 months.
If you apply the patch from HBASE-4508 and build HBase 0.90(.5) yourself,
you don't need to restart Rest service nightly.
Cheers
On Tue, Oct 18, 2011 at 9:38 AM, Ronen Itkin <ro...@taykey.com> wrote:
> Andrew, Ted - Thanks a lot.
>
> I made a simple cron job that restarts the HBase Rest Service every night
> (it clears all unwanted rest-zk sessions)., and
> I am casually monitoring the number of Zookeeper clients connections using
> Nagios (analyzing netstat output on Zk servers).
> Thats good enough for now (hopping for a new release).
>
> Thanks again!
>
>
> On Tue, Oct 18, 2011 at 8:43 AM, Ronen Itkin <ro...@taykey.com> wrote:
>
>>
>> http://search-hadoop.com/m/WBann1KzrxY1&subj=Re+rest+leaking+ZooKeeper+connections
>>
>> ---------- Forwarded message ----------
>> From: Niv Mizrahi <ni...@taykey.com>
>> Date: Mon, Oct 17, 2011 at 1:38 PM
>> Subject: Re: HBase Rest & Zookeeper issue
>> To: Ronen Itkin <ro...@taykey.com>
>>
>>
>> sound like a bad news
>>
>> http://search-hadoop.com/m/WBann1KzrxY1&subj=Re+rest+leaking+ZooKeeper+connections
>>
>>
>> On Mon, Oct 17, 2011 at 11:36 AM, Niv Mizrahi <ni...@taykey.com> wrote:
>>
>>> i have read it this morining still checking it
>>> will update you on any updates.
>>>
>>>
>>> On Mon, Oct 17, 2011 at 11:08 AM, Ronen Itkin <ro...@taykey.com> wrote:
>>>
>>>> אתה יכול בבקשה להתייחס לסוגיית ה
>>>> Client HBase Code
>>>>
>>>> איך לדעתך כדאי להתקדם?
>>>>
>>>>
>>>> ---------- Forwarded message ----------
>>>> From: Andrew Purtell <ap...@apache.org>
>>>> Date: Mon, Oct 17, 2011 at 4:39 AM
>>>> Subject: Re: HBase Rest & Zookeeper issue
>>>> To: "user@hbase.apache.org" <us...@hbase.apache.org>
>>>>
>>>>
>>>> It may be sufficient for you to simply use the latest ASF release of
>>>> HBase 0.90 instead of the CDH version. (Or use a snapshot from
>>>> nightly.cloudera.com ?) The leaking of ZooKeeper connections suggests a
>>>> particular problem. I went through the REST code on the head of the 0.90
>>>> branch and did not find it; the code is (re)using a shared
>>>> Configuration instance.
>>>>
>>>> If you have written client HBase java code, you should also audit your
>>>> code and insure you are NOT creating a new Configuration object instance
>>>> whenever you create a new HTable object, instead share a single instance.
>>>> Also, insure you are not creating HTable objects without passing in a shared
>>>> Configuration.
>>>>
>>>>
>>>> Another option is to patch the HBase client, to address the likely
>>>> underlying problem.See HBASE-3777 / HBASE-4508.
>>>>
>>>> https://issues.apache.org/jira/browse/HBASE-3777
>>>> https://issues.apache.org/jira/browse/HBASE-4508
>>>>
>>>> Best regards,
>>>>
>>>>
>>>> - Andy
>>>>
>>>> Problems worthy of attack prove their worth by hitting back. - Piet Hein
>>>> (via Tom White)
>>>>
>>>>
>>>> ----- Original Message -----
>>>> > From: Ronen Itkin <ro...@taykey.com>
>>>> > To: user@hbase.apache.org
>>>> > Cc:
>>>> > Sent: Sunday, October 16, 2011 8:32 PM
>>>> > Subject: HBase Rest & Zookeeper issue
>>>> >
>>>> > Hey all!
>>>> >
>>>> > At first it my seem like a Zookeeper issue, but the thing is that it
>>>> is very
>>>> > HBase related so I figured to send it to this mailing list as well.
>>>> > I am currently using Zookeeper 3.3.3-cdh3u1, installed as a
>>>> distributed
>>>> > cluster with 3 nodes.
>>>> > Though I have installed Zookeeper separately, its only purpose right
>>>> now is
>>>> > to serve HBase clients (hbase-0.90.3-cdh3u1).
>>>> > Seems like everything is working great for a day or two and then out
>>>> the
>>>> > blue, Zookeeper refuses to serve clients requests,
>>>> > alerting for the wide known issue of exceeding the defined maximum
>>>> > connections allowed for a client.
>>>> > I changed this value to 500 and it seems that it just held on for more
>>>> time
>>>> > and finally reached the threshold of 500 and then stopped working.
>>>> > So, I set it to 1000 and right now I am waiting to see what will
>>>> happen.
>>>> >
>>>> > Meanwhile, by auditing the Zookeeper connections manually it seems
>>>> like they
>>>> > keep growing in a slow - promising pace towards the threshold of 1000
>>>> > connections.
>>>> > I have tried to analyze the connections and it looks like almost all
>>>> of the
>>>> > connections were established from the HBase Rest service towards
>>>> zookeeper.
>>>> >
>>>> > Can someone think of a reason why it keep growing? Does someone has
>>>> any
>>>> > other suggestions regarding this issue?
>>>> > Are there any known issues regarding this situation, combining Rest
>>>> and
>>>> > Zookeeper?
>>>> >
>>>> > If it helps, this is my environment design:
>>>> >
>>>> > - Server 1 - Hadoop NameNode, JobTracker, *Hbase Master (Including
>>>> Rest)*,
>>>> > *Zookeeper01*
>>>> > - Server 2 - Hadoop SecondaryMaster, HBase *Backup Master
>>>> (Including
>>>> > Rest)*, *Zookeeper02*
>>>> > - Server 3 - *Zookeeper03*
>>>> > - Servers 4-6 - Hadoop DataNode,TaskTracker, *HBase Region Server.*
>>>> >
>>>> > The type of operations I am committing on HBase using Zookeeper are:
>>>> >
>>>> > - Simple read/writes/updates using SCAN / MapReduce / Cascading ..
>>>> > - Queries of the *Rest* service.
>>>> >
>>>> >
>>>> > Thanks a lot !!!
>>>> > * *Ronen Itkin
>>>> >
>>>>
>>>>
>>>>
>>>> --
>>>> *
>>>> Ronen Itkin*
>>>> Taykey | www.taykey.com
>>>>
>>>>
>>>
>>>
>>> --
>>> *Niv Mizrahi*
>>> Taykey | www.taykey.com
>>>
>>>
>>
>>
>> --
>> *Niv Mizrahi*
>> Taykey | www.taykey.com
>>
>>
>>
>>
>> --
>> *
>> Ronen Itkin*
>> Taykey | www.taykey.com
>>
>>
>
>
> --
> *
> Ronen Itkin*
> Taykey | www.taykey.com
>
>
Re: HBase Rest & Zookeeper issue
Posted by Ronen Itkin <ro...@taykey.com>.
Andrew, Ted - Thanks a lot.
I made a simple cron job that restarts the HBase Rest Service every night
(it clears all unwanted rest-zk sessions)., and
I am casually monitoring the number of Zookeeper clients connections using
Nagios (analyzing netstat output on Zk servers).
Thats good enough for now (hopping for a new release).
Thanks again!
On Tue, Oct 18, 2011 at 8:43 AM, Ronen Itkin <ro...@taykey.com> wrote:
>
> http://search-hadoop.com/m/WBann1KzrxY1&subj=Re+rest+leaking+ZooKeeper+connections
>
> ---------- Forwarded message ----------
> From: Niv Mizrahi <ni...@taykey.com>
> Date: Mon, Oct 17, 2011 at 1:38 PM
> Subject: Re: HBase Rest & Zookeeper issue
> To: Ronen Itkin <ro...@taykey.com>
>
>
> sound like a bad news
>
> http://search-hadoop.com/m/WBann1KzrxY1&subj=Re+rest+leaking+ZooKeeper+connections
>
>
> On Mon, Oct 17, 2011 at 11:36 AM, Niv Mizrahi <ni...@taykey.com> wrote:
>
>> i have read it this morining still checking it
>> will update you on any updates.
>>
>>
>> On Mon, Oct 17, 2011 at 11:08 AM, Ronen Itkin <ro...@taykey.com> wrote:
>>
>>> אתה יכול בבקשה להתייחס לסוגיית ה
>>> Client HBase Code
>>>
>>> איך לדעתך כדאי להתקדם?
>>>
>>> ---------- Forwarded message ----------
>>> From: Andrew Purtell <ap...@apache.org>
>>> Date: Mon, Oct 17, 2011 at 4:39 AM
>>> Subject: Re: HBase Rest & Zookeeper issue
>>> To: "user@hbase.apache.org" <us...@hbase.apache.org>
>>>
>>>
>>> It may be sufficient for you to simply use the latest ASF release of
>>> HBase 0.90 instead of the CDH version. (Or use a snapshot from
>>> nightly.cloudera.com ?) The leaking of ZooKeeper connections suggests a
>>> particular problem. I went through the REST code on the head of the 0.90
>>> branch and did not find it; the code is (re)using a shared
>>> Configuration instance.
>>>
>>> If you have written client HBase java code, you should also audit your
>>> code and insure you are NOT creating a new Configuration object instance
>>> whenever you create a new HTable object, instead share a single instance.
>>> Also, insure you are not creating HTable objects without passing in a shared
>>> Configuration.
>>>
>>>
>>> Another option is to patch the HBase client, to address the likely
>>> underlying problem.See HBASE-3777 / HBASE-4508.
>>>
>>> https://issues.apache.org/jira/browse/HBASE-3777
>>> https://issues.apache.org/jira/browse/HBASE-4508
>>>
>>> Best regards,
>>>
>>>
>>> - Andy
>>>
>>> Problems worthy of attack prove their worth by hitting back. - Piet Hein
>>> (via Tom White)
>>>
>>>
>>> ----- Original Message -----
>>> > From: Ronen Itkin <ro...@taykey.com>
>>> > To: user@hbase.apache.org
>>> > Cc:
>>> > Sent: Sunday, October 16, 2011 8:32 PM
>>> > Subject: HBase Rest & Zookeeper issue
>>> >
>>> > Hey all!
>>> >
>>> > At first it my seem like a Zookeeper issue, but the thing is that it is
>>> very
>>> > HBase related so I figured to send it to this mailing list as well.
>>> > I am currently using Zookeeper 3.3.3-cdh3u1, installed as a distributed
>>> > cluster with 3 nodes.
>>> > Though I have installed Zookeeper separately, its only purpose right
>>> now is
>>> > to serve HBase clients (hbase-0.90.3-cdh3u1).
>>> > Seems like everything is working great for a day or two and then out
>>> the
>>> > blue, Zookeeper refuses to serve clients requests,
>>> > alerting for the wide known issue of exceeding the defined maximum
>>> > connections allowed for a client.
>>> > I changed this value to 500 and it seems that it just held on for more
>>> time
>>> > and finally reached the threshold of 500 and then stopped working.
>>> > So, I set it to 1000 and right now I am waiting to see what will
>>> happen.
>>> >
>>> > Meanwhile, by auditing the Zookeeper connections manually it seems like
>>> they
>>> > keep growing in a slow - promising pace towards the threshold of 1000
>>> > connections.
>>> > I have tried to analyze the connections and it looks like almost all of
>>> the
>>> > connections were established from the HBase Rest service towards
>>> zookeeper.
>>> >
>>> > Can someone think of a reason why it keep growing? Does someone has any
>>> > other suggestions regarding this issue?
>>> > Are there any known issues regarding this situation, combining Rest and
>>> > Zookeeper?
>>> >
>>> > If it helps, this is my environment design:
>>> >
>>> > - Server 1 - Hadoop NameNode, JobTracker, *Hbase Master (Including
>>> Rest)*,
>>> > *Zookeeper01*
>>> > - Server 2 - Hadoop SecondaryMaster, HBase *Backup Master (Including
>>> > Rest)*, *Zookeeper02*
>>> > - Server 3 - *Zookeeper03*
>>> > - Servers 4-6 - Hadoop DataNode,TaskTracker, *HBase Region Server.*
>>> >
>>> > The type of operations I am committing on HBase using Zookeeper are:
>>> >
>>> > - Simple read/writes/updates using SCAN / MapReduce / Cascading ..
>>> > - Queries of the *Rest* service.
>>> >
>>> >
>>> > Thanks a lot !!!
>>> > * *Ronen Itkin
>>> >
>>>
>>>
>>>
>>> --
>>> *
>>> Ronen Itkin*
>>> Taykey | www.taykey.com
>>>
>>>
>>
>>
>> --
>> *Niv Mizrahi*
>> Taykey | www.taykey.com
>>
>>
>
>
> --
> *Niv Mizrahi*
> Taykey | www.taykey.com
>
>
>
>
> --
> *
> Ronen Itkin*
> Taykey | www.taykey.com
>
>
--
*
Ronen Itkin*
Taykey | www.taykey.com
Re: HBase Rest & Zookeeper issue
Posted by Andrew Purtell <ap...@apache.org>.
It may be sufficient for you to simply use the latest ASF release of HBase 0.90 instead of the CDH version. (Or use a snapshot from nightly.cloudera.com ?) The leaking of ZooKeeper connections suggests a particular problem. I went through the REST code on the head of the 0.90 branch and did not find it; the code is (re)using a shared
Configuration instance.
If you have written client HBase java code, you should also audit your code and insure you are NOT creating a new Configuration object instance whenever you create a new HTable object, instead share a single instance. Also, insure you are not creating HTable objects without passing in a shared Configuration.
Another option is to patch the HBase client, to address the likely underlying problem.See HBASE-3777 / HBASE-4508.
https://issues.apache.org/jira/browse/HBASE-3777
https://issues.apache.org/jira/browse/HBASE-4508
Best regards,
- Andy
Problems worthy of attack prove their worth by hitting back. - Piet Hein (via Tom White)
----- Original Message -----
> From: Ronen Itkin <ro...@taykey.com>
> To: user@hbase.apache.org
> Cc:
> Sent: Sunday, October 16, 2011 8:32 PM
> Subject: HBase Rest & Zookeeper issue
>
> Hey all!
>
> At first it my seem like a Zookeeper issue, but the thing is that it is very
> HBase related so I figured to send it to this mailing list as well.
> I am currently using Zookeeper 3.3.3-cdh3u1, installed as a distributed
> cluster with 3 nodes.
> Though I have installed Zookeeper separately, its only purpose right now is
> to serve HBase clients (hbase-0.90.3-cdh3u1).
> Seems like everything is working great for a day or two and then out the
> blue, Zookeeper refuses to serve clients requests,
> alerting for the wide known issue of exceeding the defined maximum
> connections allowed for a client.
> I changed this value to 500 and it seems that it just held on for more time
> and finally reached the threshold of 500 and then stopped working.
> So, I set it to 1000 and right now I am waiting to see what will happen.
>
> Meanwhile, by auditing the Zookeeper connections manually it seems like they
> keep growing in a slow - promising pace towards the threshold of 1000
> connections.
> I have tried to analyze the connections and it looks like almost all of the
> connections were established from the HBase Rest service towards zookeeper.
>
> Can someone think of a reason why it keep growing? Does someone has any
> other suggestions regarding this issue?
> Are there any known issues regarding this situation, combining Rest and
> Zookeeper?
>
> If it helps, this is my environment design:
>
> - Server 1 - Hadoop NameNode, JobTracker, *Hbase Master (Including Rest)*,
> *Zookeeper01*
> - Server 2 - Hadoop SecondaryMaster, HBase *Backup Master (Including
> Rest)*, *Zookeeper02*
> - Server 3 - *Zookeeper03*
> - Servers 4-6 - Hadoop DataNode,TaskTracker, *HBase Region Server.*
>
> The type of operations I am committing on HBase using Zookeeper are:
>
> - Simple read/writes/updates using SCAN / MapReduce / Cascading ..
> - Queries of the *Rest* service.
>
>
> Thanks a lot !!!
> * *Ronen Itkin
>