hbase-user mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Ben West <bwsithspaw...@yahoo.com>
Subject HMaster issues
Date Tue, 18 Oct 2011 14:19:07 GMT
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

Mime
View raw message