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 [email protected]: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 [email protected]: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
