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 <bwsithspaw...@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
>
